这是我参与「第五届青训营 」伴学笔记创作活动的第 4 天
2.性能调优实战
2.1 简介
- 要依靠数据而不是猜测
- 要定位最大瓶颈而不是细枝末节
- 不要过早优化
- 不要过度优化
2.2 性能分析工具pprof
2.2.1 pprof功能简介
2.2.2 pprof排查实战
-
编译运行，此时http server跑在6060端口
go build ./go-pprof-practice可以看到终端一直在打印如下的语句
-
通过活动监视器排查CPU占用过高 可以看到
go-pprof-practice的CPU占用率非常高- 使用
go tool pprof进行排查
go tool pprof http://localhost:6060/debug/pprof/profile- 使用
top命令：很明显，CPU 占用过高是
github.com/wolfogre/go-pprof-practice/animal/felidae/tiger.(*Tiger).Eat造成的 - 再使用
list Eat定位问题具体是哪一行代码可以看到是空循环占用大量CPU时间，问题定位成功
- 安装
graphviz图形化显示调用栈信息
brew install graphviz # for macos apt install graphviz # for ubuntu yum install graphviz # for centos安装完成后，我们继续在上文的交互式终端里输入
web，注意，虽然这个命令的名字叫“web”，但它的实际行为是产生一个 .svg 文件，并调用你的系统里设置的默认打开 .svg 的程序打开它。如果你的系统里打开 .svg 的默认程序并不是浏览器（比如可能是你的代码编辑器），这时候你需要设置一下默认使用浏览器打开 .svg 文件，相信这难不倒你。可以看到
而在注释了
Tiger.Eat相关代码之后，再使用web - 使用
cpu占用率也降到了0.08%
4. 排查内存占用过高
- 再次使用pprof命令
go tool pprof http://localhost:6060/debug/pprof/heap
以及top，list进行排查，发现
这里有个循环会一直向 m.buffer 里追加长度为 1 MiB 的数组，直到总容量到达 1 GiB 为止，且一直不释放这些内存
- 再使用
web - 再把
Mouse.Steal的循环注释掉，成功降低内存
- 排查频繁内存回收
- 频繁的 GC (Garbage Collection，垃圾回收)对 golang 程序性能的影响也是非常严重的
- 使用 grep 筛选出 GC 日志查看
GODEBUG=gctrace=1 ./go-pprof-practice | grep gc
发现GC每隔几秒钟就发生一次
再使用
top list web进行排查，发现是Dog.Run在申请内存
同样注释掉再运行，GC日志基本上捕捉不到了
- 排查协程泄露
go tool pprof http://localhost:6060/debug/pprof/goroutine
火焰图如下
可以看到
Wolf.Drink创建了很多协程并等待
注释掉相关代码，go程由105个降低到了7个
-
排查锁的争用 方法同上，发现是
Wolf.Howl拿着锁，注释掉即可 -
排查阻塞操作 方法同上，发现是
Cat.Pee在channel读数据时发生阻塞，注释到后block数量减少1，但还剩1，查看详细信息发现和http server相关，故忽略
2.2.3 pprof采样过程和原理
总结与思考
今天我了解了一个golang的性能分析工具pprof，并学习使用top list web三个工具对CPU占用、内存占用、频繁GC、协程泄漏、锁的争用和阻塞操作等问题进行排查。此外我还第一次自己生成并分析火焰图（之前听学长说参加ob比赛用到过），了解了go项目中常见的问题，感觉应该会在以后的实际工作中发挥作用。
参考链接
