Go 性能分析工具 PProf(下)

在上文 Go 性能分析工具 PProf(上)介绍了查看 Go 进程的 CPU、内存、火焰图。

但有时候使用 pprof 还不一定足够完整观查并解决问题,因为在真实的程序中还包含许多的隐藏动作,例如 Goroutine 在执行时会做哪些操作?执行/阻塞了多长时间?在什么时候阻止?在哪里被阻止的?GC 是怎么影响到 Goroutine 的执行的?

这就需要 Go 的 trace 工具来进行分析。

trace 工具是用于分析程序运行时行为的强大工具,它能生成程序执行期间的事件时间线,帮助开发者深入理解程序的并发、调度、垃圾回收(GC)、系统调用等底层行为。

类似的,执行命令

curl -o trace.out "http://localhost:6060/debug/pprof/trace?seconds=30"

采集程序信息,并生成 trace.out 文件,再执行命令:

go tool trace trace.out

启动可视化界面:

1、Scheduler latency profile

在刚开始查看问题时,除非是很明显的现象,否则不应该一开始就陷入细节,因此我们一般先查看 “Scheduler latency profile”,我们能通过 Graph 看到整体的调用开销情况,如下:

2、Goroutine 分析

第二步看 “Goroutine analysis”,我们能通过这个功能看到整个运行过程中,每个函数块有多少个有 Goroutine 在跑,并且观察每个的 Goroutine 的运行开销都花费在哪个阶段。

这里可以明显看到 gc 耗费了大量时间,问题应该出在 gc 上。

3、View trace by proc

现在看 View trace by proc,跟进进程查看 trace。

一个正常的 trace 图如下,横轴为时间线,纵轴为各项指标。

正常的 trace

一个不正常的 trace 图如下

不正常的 trace

可以看到,大概 10s 发生 7次 GC,并且 GC 后,Heap 几乎没有下降,可以定位到应该是 GC 出现问题,

4、Minimum mutator utilization

在 Go 的 trace 工具中,MMU(Minimum Mutator Utilization) 是一个衡量垃圾回收(GC)对程序性能影响的重要指标,表示在特定时间窗口内,应用程序(Mutator)能够执行的最小 CPU 利用率比例。MMU 越低,说明 GC 对程序运行的干扰越大。
横坐标表示时间窗口,纵坐标 mmu 是指除了 GC 外程序占用 CPU 的最小的比例。

较为正常的 MMU 曲线应该是这样:

正常的 MMU

MMU的线性状态理想目标

  1. MMU值应尽可能高(接近100%),表示GC对应用的影响极小,程序几乎无感知停顿。
  2. 曲线应保持平稳,避免频繁的剧烈波动,否则表明GC活动不稳定或存在突发性内存压力。

而不正常的 MMU 差不多是这样:

不正常的 MMU

可以看到几乎全部时间都在 gc。

5、总结

通过本文我们习得了 go tool trace 的武林秘籍,它能够跟踪捕获各种执行中的事件,例如 Goroutine 的创建/阻塞/解除阻塞,Syscall 的进入/退出/阻止,GC 事件,Heap 的大小改变,Processor 启动/停止等等。

需要用好 Go 的两大杀器 pprof + trace 组合,此乃排查好搭档,谁用谁清楚,即使他并不万能。

最后,上面这些都需要服务器正处于异常状态,才能采集到异常信息,如果服务器半夜三更处于异常,而到白天又恢复正常了,怎么知道异常原因呢?Go 性能监控—holmes 可以很好的解决问题。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
平台声明:文章内容(如有图片或视频亦包括在内)由作者上传并发布,文章内容仅代表作者本人观点,简书系信息发布平台,仅提供信息存储服务。
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 230,563评论 6 544
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 99,694评论 3 429
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 178,672评论 0 383
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 63,965评论 1 318
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 72,690评论 6 413
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 56,019评论 1 329
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 44,013评论 3 449
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 43,188评论 0 290
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 49,718评论 1 336
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 41,438评论 3 360
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 43,667评论 1 374
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 39,149评论 5 365
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 44,845评论 3 351
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 35,252评论 0 28
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 36,590评论 1 295
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 52,384评论 3 400
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 48,635评论 2 380

推荐阅读更多精彩内容