[TOC]
gRPC的请求追踪
这是我参与更文挑战的第 1 天，活动详情查看： 更文挑战
前言
我们来回顾一下之前分享的知识点：
介绍了基本你的gRPC的使用方式，框架，交互方式等
分享了gRPC的四种认证方式中重要的2种方式，有兴趣可以点击看看哦
整理了openssl 证书的生成，关键点已经高亮标注，值得一看
gRPC生态中的中间件，主要是做统一认证工作，不必要在每一个接口中都写一次认证方式
文章中有分享gRPC的各种功能的中间件，有兴趣可以点击链接，大佬们还请不吝赐教
go tool trace
今天我们来介绍一下go的请求追踪，也就是说go Trace ，分享trace有如下几个原因：
- 学习完
trace之后，你能够自己去实践，清晰的了解整个程序的调用栈 - 可以通过追踪器捕获大量信息，如图
- 可以更快的解决我们项目中的疑难杂症
我们或许都有这样的体会，自己思考明白，设计出来的程序，可以很清晰明了的将细节解释明白，对功能的增删改也是可以做到灵活应对。
可是让我们一下子去修改别人写的功能或模块的时候，很多时候会一脸懵逼，这也不敢动，那也不敢动，在不理解的情况下，有疑问，一定要问清楚原理和逻辑，否则搞不好就是线上问题。
如上情况，最重要的一个原因就是自己对当前模块/功能的熟悉程度，以及自己的思维模型是否可迁移。
总而言之，对程序，要有敬畏之心，好奇之心，持之以恒专研下去，要有解决问题的决心。
用go tool trace具体哪些地方合适，哪些地方不合适？
不合适
- 运行缓慢的函数，或者找到大部分CPU时间花费在哪里，术业有专攻，看CPU时间花费，是有专门的工具的
go tool pprof
合适
- 找出程序在一段时间内正在做什么
-
go tool trace可以通过view trace链接提供的其他可视化功能，对于诊断争用问题帮助极大
开始写一个DEMO
GOMAXPROCS设置可以同时执行的cpu的最大数量，此处我们设置为 1 个
server.go
package main
import (
"context"
"fmt"
"os"
"runtime"
"runtime/trace"
"sync"
)
func main() {
// 使用 GOMAXPROCS设置可以同时执行的cpu的最大数量 为 1 个
runtime.GOMAXPROCS(1)
f, _ := os.Create("myTrace.dat")
defer f.Close()
//开始跟踪，在跟踪时，跟踪将被缓冲并写入 一个我们指定的文件中
_ = trace.Start(f)
defer trace.Stop()
// 咱们自定义一个任务
ctx, task := trace.NewTask(context.Background(), "customerTask")
defer task.End()
var wg sync.WaitGroup
wg.Add(10)
for i := 0; i < 10; i++ {
// 启动10个协程，模拟做任务
go func(num string) {
defer wg.Done()
// 标记 num
trace.WithRegion(ctx, num, func() {
var sum, i int64
// 模拟执行任务
for ; i < 500000000; i++ {
sum += i
}
fmt.Println(num, sum)
})
}(fmt.Sprintf("num_%02d", i))
}
wg.Wait()
}
操作步骤：
- 编译并运行会生成我们既定好的数据文件
- 通过go tool trace +
myTrace.dat - 浏览器会弹出
trace的web页面，如下
| tag | 说明 |
|---|---|
| View trace | 查看可视化的跟踪情况 |
| Goroutine analysis | 协程分析 |
| Network blocking profile (⬇) | 网络拥塞情况 |
| Synchronization blocking profile (⬇) | 同步阻塞情况 |
| Syscall blocking profile (⬇) | 系统调用阻塞情况 |
| Scheduler latency profile (⬇) | 调度延迟情况 |
| User-defined tasks | 用户自定义的任务 |
| User-defined regions | 用户自定义的区域 |
| Minimum mutator utilization | 最低 Mutator 利用率 |
View trace
可视化的web追踪页面
| tag | 说明 |
|---|---|
| 时间线 | 用于显示执行的时间单元，根据时间维度的不同可以调整区间，可以点击按钮 image
|
| 堆 | 用于显示执行期间的内存分配和释放情况 |
| 协程 | 用于显示在执行期间的每个 Goroutine 运行阶段有多少个协程在运行，其包含 GC 等待（GCWaiting）、可运行（Runnable）、运行中（Running）这三种状态。 |
| OS 线程 | 显示在执行期间有多少个线程在运行，其包含正在调用 Syscall（InSyscall）、运行中（Running)这两种状态。 |
| 虚拟处理器 | 每个虚拟处理器显示一行，虚拟处理器的数量一般默认为系统内核数。 |
| 协程和事件 | 显示在每个虚拟处理器上有什么 Goroutine 正在运行，而连线行为代表事件关联。 |
可以使用 shift + ? 唤出帮助手册
点击PROC颜色区域
可以看到该处理器此段时间再做什么事情，如图
| tag | 说明 |
|---|---|
| Start | 开始时间 |
| Wall Duration： | 持续时间 |
| Self Time | 执行时间 |
| Start Stack Trace | 开始时的堆栈信息 |
| End Stack Trace | 结束时的堆栈信息 |
| Incoming flow | 输入流 |
| Outgoing flow | 输出流 |
| Preceding events | 之前的事件 |
| Following events | 之后的事件 |
| All connected | 所有连接的事件 |
Event(s)下方的 Preceding events 点击进去可以看到每一个调用栈的执行时间
用户自定义任务如何查看？
- User-defined tasks
- 点击Count
- goroutine view
- 点击颜色区域
即可看到此段时间的调用栈，开始时间，结束时间，以及用户定义的任务开了多少个协程等等
User-defined tasks
点击Count
点击goroutine view
点击颜色区域
即可看到此段时间具体在执行什么动作，具体的信息如下
用户自定义区域如何查看呢？
与上述查看用户自定义任务的方式大同小异，如下
- User-defined regions
- 点击具体的Count
User-defined regions
点击具体的Count
即可查看到此协程的总共耗时，网络拥塞，同步阻塞，系统调用阻塞，调度等待，垃圾回收扫描，垃圾回收暂停的相关参数信息
那么某一些关键的goroutine被阻止运行时，可能会有延迟问题，大概的原因相信大家应该有些谱了吧
- 系统调用时被阻塞;
- 被共享内存阻塞（通道/互斥等）
- 调度程序没有按照我们所期望的频率运行协程
- 被runtime系统（例如GC）阻塞
正好上述原因的追踪都可以使用go tool trace 识别到 ，对于我们追踪问题，查询问题原理起了很好的助力作用
好了，本次就到这里，下一次分享 gRPC的HTTP网关，
技术是开放的，我们的心态，更应是开放的。拥抱变化，向阳而生，努力向前行。
我是小魔童哪吒，欢迎点赞关注收藏，下次见~
