Golang 大杀器之跟踪剖析 trace(转载)
转载地址:https://mp.weixin.qq.com/s/iXkbF018fxgTWtMqxZfo6g
以下文章来源于不会写Go的煎鱼 ,作者陈煎鱼
不会写Go的煎鱼
知其然,知其所以然。
在 Go 中有许许多多的分析工具,在之前我有写过一篇 《Golang 大杀器之性能剖析 PProf》 来介绍 PProf,如果有小伙伴感兴趣可以去我博客看看。
但单单使用 PProf 有时候不一定足够完整,因为在真实的程序中还包含许多的隐藏动作,例如 Goroutine 在执行时会做哪些操作?执行/阻塞了多长时间?在什么时候阻止?在哪里被阻止的?谁又锁/解锁了它们?GC 是怎么影响到 Goroutine 的执行的?这些东西用 PProf 是很难分析出来的,但如果你又想知道上述的答案的话,你可以用本文的主角 go tool trace
来打开新世界的大门。目录如下:
初步了解
import (
"os"
"runtime/trace"
)
func main() {
trace.Start(os.Stderr)
defer trace.Stop()
ch := make(chan string)
go func() {
ch <- "EDDYCJY"
}()
<-ch
}
生成跟踪文件:
$ go run main.go 2> trace.out
启动可视化界面:
$ go tool trace trace.out
2019/06/22 16:14:52 Parsing trace...
2019/06/22 16:14:52 Splitting trace...
2019/06/22 16:14:52 Opening browser. Trace viewer is listening on http://127.0.0.1:57321
查看可视化界面:
View trace:查看跟踪
Goroutine analysis:Goroutine 分析
Network blocking profile:网络阻塞概况
Synchronization blocking profile:同步阻塞概况
Syscall blocking profile:系统调用阻塞概况
Scheduler latency profile:调度延迟概况
User defined tasks:用户自定义任务
User defined regions:用户自定义区域
Minimum mutator utilization:最低 Mutator 利用率
Scheduler latency profile
在刚开始时,我们一般先查看 “Scheduler latency profile”,我们能通过 Graph 看到整体的调用开销情况,如下:
因为演示程序比较简单,因此这里就两块,一个是 trace
本身,另外一个是 channel
的收发。
Goroutine analysis
第二步看 “Goroutine analysis”,我们能通过这个功能看到整个运行过程中,每个函数块有多少个有 Goroutine 在跑,并且观察每个的 Goroutine 的运行开销都花费在哪个阶段。如下:
通过上图我们可以看到共有 3 个 goroutine,分别是 runtime.main
、 runtime/trace.Start.func1
、 main.main.func1
,那么它都做了些什么事呢,接下来我们可以通过点击具体细项去观察。如下:
同时也可以看到当前 Goroutine 在整个调用耗时中的占比,以及 GC 清扫和 GC 暂停等待的一些开销。如果你觉得还不够,可以把图表下载下来分析,相当于把整个 Goroutine 运行时掰开来看了,这块能够很好的帮助我们对 Goroutine 运行阶段做一个的剖析,可以得知到底慢哪,然后再决定下一步的排查方向。如下:
名称 | 含义 | 耗时 |
---|---|---|
Execution Time | 执行时间 | 3140ns |
Network Wait Time | 网络等待时间 | 0ns |
Sync Block Time | 同步阻塞时间 | 0ns |
Blocking Syscall Time | 调用阻塞时间 | 0ns |
Scheduler Wait Time | 调度等待时间 | 14ns |
GC Sweeping | GC 清扫 | 0ns |
GC Pause | GC 暂停 | 0ns |
View trace
在对当前程序的 Goroutine 运行分布有了初步了解后,我们再通过 “查看跟踪” 看看之间的关联性,如下:
这个跟踪图粗略一看,相信有的小伙伴会比较懵逼,我们可以依据注解一块块查看,如下:
时间线:显示执行的时间单元,根据时间维度的不同可以调整区间,具体可执行
shift
+?
查看帮助手册。堆:显示执行期间的内存分配和释放情况。
协程:显示在执行期间的每个 Goroutine 运行阶段有多少个协程在运行,其包含 GC 等待(GCWaiting)、可运行(Runnable)、运行中(Running)这三种状态。
OS 线程:显示在执行期间有多少个线程在运行,其包含正在调用 Syscall(InSyscall)、运行中(Running)这两种状态。
虚拟处理器:每个虚拟处理器显示一行,虚拟处理器的数量一般默认为系统内核数。
协程和事件:显示在每个虚拟处理器上有什么 Goroutine 正在运行,而连线行为代表事件关联。
点击具体的 Goroutine 行为后可以看到其相关联的详细信息,这块很简单,大家实际操作一下就懂了。文字解释如下:
Start:开始时间
Wall Duration:持续时间
Self Time:执行时间
Start Stack Trace:开始时的堆栈信息
End Stack Trace:结束时的堆栈信息
Incoming flow:输入流
Outgoing flow:输出流
Preceding events:之前的事件
Following events:之后的事件
All connected:所有连接的事件
View Events
我们可以通过点击 View Options-Flow events、Following events 等方式,查看我们应用运行中的事件流情况。如下:
通过分析图上的事件流,我们可得知这程序从 G1 runtime.main
开始运行,在运行时创建了 2 个 Goroutine,先是创建 G18 runtime/trace.Start.func1
,然后再是 G19 main.main.func1
。而同时我们可以通过其 Goroutine Name 去了解它的调用类型,如:runtime/trace.Start.func1
就是程序中在 main.main
调用了 runtime/trace.Start
方法,然后该方法又利用协程创建了一个闭包 func1
去进行调用。
在这里我们结合开头的代码去看的话,很明显就是 ch
的输入输出的过程了。
结合实战
今天生产环境突然出现了问题,机智的你早已埋好 _"net/http/pprof"
这个神奇的工具,你麻利的执行了如下命令:
curl http://127.0.0.1:6060/debug/pprof/trace\?seconds\=20 > trace.out
go tool trace trace.out
View trace
你很快的看到了熟悉的 List 界面,然后不信邪点开了 View trace 界面,如下:
完全看懵的你,稳住,对着合适的区域执行快捷键 W
不断地放大时间线,如下:
经过初步排查,你发现上述绝大部分的 G 竟然都和 google.golang.org/grpc.(*Server).Serve.func
有关,关联的一大串也是 Serve
所触发的相关动作。
这时候有经验的你心里已经有了初步结论,你可以继续追踪 View trace 深入进去,不过我建议先鸟瞰全貌,因此我们再往下看 “Network blocking profile” 和 “Syscall blocking profile” 所提供的信息,如下:
Network blocking profile
Syscall blocking profile
通过对以上三项的跟踪分析,加上这个泄露,这个阻塞的耗时,这个涉及的内部方法名,很明显就是哪位又忘记关闭客户端连接了,赶紧改改改。
总结
通过本文我们习得了 go tool trace
的武林秘籍,它能够跟踪捕获各种执行中的事件,例如 Goroutine 的创建/阻塞/解除阻塞,Syscall 的进入/退出/阻止,GC 事件,Heap 的大小改变,Processor 启动/停止等等。
希望你能够用好 Go 的两大杀器 pprof + trace 组合,此乃排查好搭档,谁用谁清楚,即使他并不万能。
参考
https://about.sourcegraph.com/go/an-introduction-to-go-tool-trace-rhys-hiltner
https://www.itcodemonkey.com/article/5419.html
https://making.pusher.com/go-tool-trace/
https://golang.org/cmd/trace/
https://docs.google.com/document/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub
https://godoc.org/runtime/trace
Golang 大杀器之跟踪剖析 trace(转载)相关推荐
- golang 关闭gc 并手动gc_Golang 大杀器之跟踪剖析 trace
Go语言中文网,致力于每日分享编码.开源等知识,欢迎关注我,会有意想不到的收获! 在 Go 中有许许多多的分析工具,在之前我有写过一篇 Golang 大杀器之性能剖析 PProf 来介绍 PProf, ...
- Go 大杀器之跟踪剖析 trace
大家好,我是煎鱼. 前段时间分享了<Go 程序崩了?煎鱼教你用 PProf 工具来救火!>,但有时候单单使用 pprof 还不一定足够完整观查并解决问题,因为在真实的程序 ...
- Go 工程师必学:Go 大杀器之跟踪剖析 trace
大家好,我是煎鱼. 前段时间分享了<Go 程序崩了?煎鱼教你用 PProf 工具来救火!>,但有时候单单使用 pprof 还不一定足够完整观查并解决问题,因为在真实的程序 ...
- 深度学习网络大杀器之Dropout(II)——将丢弃学习视为集成学习之我见
原帖:阿里云云栖社区: https://yq.aliyun.com/articles/110002 关于dropout的分析,可以见博主的另外一篇文章: <深度学习网络大杀器之Dropout-- ...
- Python爬虫大杀器之Requests快速入门
转载:http://blog.csdn.net/iloveyin/article/details/21444613 快速上手 迫不及待了吗?本页内容为如何入门Requests提供了很好的指引.其假设你 ...
- mysql数据库mha_MySQL高可用性大杀器之MHA
提到MySQL高可用性,很多人会想到MySQL Cluster,亦或者Heartbeat+DRBD,不过这些方案的复杂性常常让人望而却步,与之相对,利用MySQL复制实现高可用性则显得容易很多,目前大 ...
- Python 提速大杀器之 numba 篇
你是不是曾经有这样的苦恼,python 真的太好用了,但是它真的好慢啊(哭死) ; C++ 很快,但是真的好难写啊,此生能不碰它就不碰它.老天啊,有没有什么两全其美的办法呢?俗话说的好:办法总是比困难 ...
- .Net大杀器之基于Newlife.Redis的可重复消费+共享订阅队列来替换第三方MQ
一.前言 消息队列(Message Queue)是分布式系统必不可少的中间件,大部分消息队列产品(如RocketMQ/RabbitMQ/Kafka等)要求团队有比较强的技术实力,不适用于中小团队,并且 ...
- 小工匠聊架构- 提升性能的大杀器之缓存技术
文章目录 Pre 为何使用缓存 CPU瓶颈 IO瓶颈 本地缓存or分布式缓存 本地缓存 分布式缓存 如何选择缓存框架 缓存通用知识 缓存命中率 缓存更新策略 主动请求DB数据,更新缓存 被动请求DB数 ...
最新文章
- linux shell的配置文件信息
- python 图像识别_python图像识别之图片相似度计算
- chinese-typesetting:更好的中文文案排版
- 南京金陵中学2021高考成绩查询,2021高考成绩出炉 南京各大高中喜报来了!
- SpringBoot基础系列-SpringCache使用
- 1个系统节拍 c语言_自己写的非抢占式嵌入式操作系统ATOS,全c语言,移植太......
- DCMTK:类DcmUnsigned64bitVeryLong的测试程序
- 移动端rem适配-JS
- SAP LUW Database update discuss mengniu 蒙牛
- maven 排除某个类_java-如何从Maven依赖项中排除某些程序包(在JAR中)?
- sap 测试数据生成报表
- mess组网 中继_Mesh路由和无线中继的差距在哪里?谁才是更好的选择?
- 航空订票系统java_航空订票系统(JAVA+SSH+MYSQL)
- 勒索病毒是什么?防勒索病毒我们该怎么做?
- JavaScript - 获取、修改 title 元素的内容
- 如何使用计算机打勾,如何用电脑在方框里面打勾
- QCC3040---Log module
- 程序员简历模版【A4纸正反两面】(20220511)
- 计算机组成原理基础知识总结
- 雷达的工作原理示意图_雷达的工作原理是什么?
热门文章
- CSS 实现必填项前/后添加红色星号
- 将csv添加到mysql,将CSV导入到mysql表
- django shortcut函数
- Spring——bean生命周期
- 关于Java静态属性初始化
- win10用计算机分区,新电脑win10怎样给系统硬盘分区?给新win10电脑分区硬盘的方法...
- ContextLoaderListener的作用详解
- python 文本框位置_「每日一练」Python文本框的显示和插入
- 几百万的数据查找重复值_如何快速查找出Excel中的重复数据,多角度分析
- 解析OA技术,规避使用风险