这是我参与「第三届青训营 -后端场」笔记创作活动的的第2篇笔记
pprof
pprof是GoLang程序性能分析工具,prof是profile(画像)的缩写,用pprof我们可以分析多种数据,其中最常用的是以下5种
- CPU
- heap
- goroutine
- mutex
- block
pprof实战
采用wolfogre/go-pprof-practice: go pprof practice. (github.com)github仓库代码进行pprof实战
首先使用git clone将项目拉取到本地并运行
访问http://localhost:6060/debug/pprof/进入到pprof界面如下
直接点击链接查看采样信息并不直观,可以借助
go tool pprof命令来排查问题,go原生自带,不需要额外安装
排查cpu问题
打开任务管理器(windows)或mac的活动监视器,linux的top命令
在对应目录打开cmd终端,或在vscode、goland中打开terminal
输入go tool pprof http://localhost:6060/debug/pprof/profile
等待后输入top命令
可以发现
github.com/wolfogre/go-pprof-practice/animal/felidae/tiger.(*Tiger).Eat占用了相较更高的(除了main) cum
| 指令 | 详情 |
|---|---|
| flat | 当前函数本身执行耗时 |
| flat% | flat占cpu总时间的比例 |
| sum% | 每一行flat%总和 |
| cum | 当前函数加其调用函数总耗时 |
| cum% | cum占cpu总时间的比例 |
通过list Eat可以查看问题出现在代码的具体位置 |
可以发现问题出现在空的for循环处
在终端中输入web可以通过图形化显示调用栈信息(需要事先安装graphviz)如果出现dot not found的错误,可以将安装目录下bin目录添加进环境变量中,
可以看到下图
解决该问题,直接注释掉空的for循环即可
排查内存占用问题
此时可以看到,cpu占用下降明显,但内存占用仍非常高,在终端中输入go tool pprof http://localhost:6060/debug/pprof/heap及top命令
可以看到Steal占用内存异常的高,通过list Steal可以查看问题出现在代码中的何处\
可以看到代码50行处,向buffer一直追加长度为1M的数组,直到达到1G
通过web命令查看可视化界面
注释掉相关代码即可解决掉该问题,此时可以发现内存占用明显下降
查看内存分配
运行命令go tool pprof http://localhost:6060/debug/pprof/allocs
同样是top,list,web命令
可以发现在Run函数中频繁的无意义的申请内存,直接注释掉代码即可
查看goroutine问题
运行命令go tool pprof http://localhost:6060/debug/pprof/goroutine
同样是top,list,web命令
虽然比较藏得比较深,但还是可以看到,Drink函数不停地创建没有任何意义的协程,并睡眠了30秒。将此处代码注释掉即可。
火焰图
还原注释的代码,待程序运行一段时间后,命令行中输入go tool pprof -http=:8080 xxx/debug/pprof/goroutine可以看到如下界面
在左上角VIEW中选择Flame Graph即可以查看火焰图
由上到下表示调用顺序
每一块代表一个函数,越长代表占用cpu越长
排查锁和阻塞
通过命令go tool pprof http://localhost:6060/debug/pprof/mutex或go tool pprof http://localhost:6060/debug/pprof/block以及top,list,web相同操作查看具体的问题所出现的位置,在这里就不再赘述,具体过程与上文基本一致。