gRPC的请求追踪神器 go tool trace

Golang
485
0
0
2022-04-19
标签   gRPC

[TOC]

gRPC的请求追踪

前言

我们来回顾一下之前分享的知识点:

介绍了基本你的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
  • 浏览器会弹出traceweb页面,如下

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 说明 时间线 用于显示执行的时间单元,根据时间维度的不同可以调整区间,可以点击按钮

,便可以在界面上拖拽时间线 堆 用于显示执行期间的内存分配和释放情况 协程 用于显示在执行期间的每个 Goroutine 运行阶段有多少个协程在运行,其包含 GC 等待(GCWaiting)、可运行(Runnable)、运行中(Running)这三种状态。 OS 线程 显示在执行期间有多少个线程在运行,其包含正在调用 SyscallInSyscall)、运行中(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网关

技术是开放的,我们的心态,更应是开放的。拥抱变化,向阳而生,努力向前行。

我是小魔童哪吒,欢迎点赞关注收藏,下次见~