Go 库性能分析工具pprof
作者:小马别过河
场景
我们一般没必要过度优化 Go 程序性能。但是真正需要时,Go 提供的 pprof 工具能帮我们快速定位到问题。比如,我们团队之前有一个服务,在本地和测试环境没问题,一到灰度环境,就报 cpu 负载过高,后经排查,发现某处代码死循环了。我把代码简化成如下:
// 处理某些业务,真实的代码中这个死循环很隐蔽 func retrieveSomeThing() { for {} } // 处理其他的一些业务,无意义,用于后续做例子 func doSomeThing() { do1() for i := 0; i < 200000000; i++ {} do2() } // 无意义 func do1() { for i := 0; i < 200000000; i++ {} } // 无意义 func do2() { for i := 0; i < 200000000; i++ {} } func main() { go retrieveSomeThing() go doSomeThing() // 阻塞一下 time.Sleep(3 * time.Second) }
解决问题前,先介绍下 pprof。
pprof
pprof 包会输出运行时的分析数据(profiling data),这些数据可以被 pprof 的可视化工具解析。Go 标准库主要提供了两个包:
runtime/pprof
通过写入到文件的方式暴露 profile 数据;net/http/pprof
通过 http 服务暴露 profile 数据,适用于守护进程。
生成 profile 文件
CPU 性能分析
在 runtime/pprof
中,使用StartCPUProfile
开启 CPU 性能分析。退出程序前,需要调用StopCPUProfile
把采样数据 flush 到输出文件。
采样的频率默认是 100 Hz(每秒 100 次)。
// 输出到标准输出,一般是指定文件 if err := pprof.StartCPUProfile(os.Stdout); err != nil { log.Fatal("could not start CPU profile: ", err) } defer pprof.StopCPUProfile()
内存性能分析
调用 WriteHeapProfile
开启内存性能分析:
// 输出到标准输出,一般是指定文件 if err := pprof.WriteHeapProfile(os.Stdout); err != nil { log.Fatal("could not write memory profile: ", err) } }
分析 profile 文件 && 优化代码
以开篇的代码为例,由于是 CPU 过载,我们可以在 main 函数开启 CPU Profile:
// 通过参数指定 cpu profile 输出的文件 var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to `file`") func main() { flag.Parse() if *cpuprofile != "" { f, err := os.Create(*cpuprofile) if err != nil { log.Fatal("could not create CPU profile: ", err) } // 开启 CPU 分析 if err := pprof.StartCPUProfile(f); err != nil { log.Fatal("could not start CPU profile: ", err) } defer pprof.StopCPUProfile() } // 业务代码 go retrieveSomeThing() go doSomeThing() // 模拟阻塞 time.Sleep(5 * time.Second) }
我们执行命令,输出 profile 文件到 cpu.prof。
go run main.go -cpuprofile cpu.prof
go tool pprof
Go 提供性能解析工具:go tool pprof
。我们使用 go tool 打开 profile 文件。
> go tool pprof cpu.prof Type: cpu Time: Nov 16, 2022 at 1:40pm (CST) Duration: 5.17s, Total samples = 4.54s (87.75%) Entering interactive mode (type "help" for commands, "o" for options) (pprof)
这是个交互式的界面,输入help
可以查看所有命令。
top 命令
我们使用 topN 命令,查看根据 flat 从大到小排序的前 N 条数据。
(pprof) top10 Showing nodes accounting for 4650ms, 100% of 4650ms total flat flat% sum% cum cum% 4220ms 90.75% 90.75% 4450ms 95.70% main.retrieveSomeThing 230ms 4.95% 95.70% 230ms 4.95% runtime.asyncPreempt 80ms 1.72% 97.42% 200ms 4.30% main.doSomeThing 70ms 1.51% 98.92% 70ms 1.51% main.do2 (inline) 50ms 1.08% 100% 50ms 1.08% main.do1 (inline)
top 命令返回数据有5个指标:
- flat : 本函数占用的 CPU 时间,不包括调用函数的时间;
- flat% : flat 占的百分比;
- sum% : 前面 flat% 的总和;
- cum : 累计时间,包括调用的函数的时间;
- cum% : cum 的百分比。
以main.doSomeThing
(排第三的函数)为例子,耗时为:
func doSomeThing() { // flat: 80ms cum: 200ms do1() // 执行时间 50ms for i := 0; i < 200000000; i++ {} // 执行时间 80ms do2() // 执行时间 70ms }
doSomeThing
的 flat 的值为:
for i := 0; i < 200000000; i++ {}的执行时间(80ms),不包括do1和do2的时间。
doSomeThing
的 cum 的值为:
cum(200ms) = doSomething的flat(80ms) + do1的flat(50ms) + do2的flat(70ms)
ps: top 可以使用 -cum 参数来指定,根据 cum 排序。
list 命令
明白了 top 的指标的意思,我们关注到,排在 top1 的函数是 retrieveSomeThing。可以使用 list 命令,查看 retrieveSomeThing 耗时:
(pprof) list retrieveSomeThing Total: 4.65s ROUTINE ======================== main.retrieveSomeThing in /xxxx/pprof_note/pprof/main.go 4.22s 4.45s (flat, cum) 95.70% of Total 10ms 10ms 1:package main . . 2: . . 3:import ( . . 4: "flag" . . 5: "log" . . 6: "os" . . 7: "runtime/pprof" . . 8: "time" . . 9:) . . 10: . . 11:// 处理某些业务,真实的代码中这个死循环很隐蔽 . . 12:func retrieveSomeThing() { 4.21s 4.44s 13: for { . . 14: } . . 15:} . . 16: . . 17:// 处理其他的一些业务,无意义,用于后续做例子 . . 18:func doSomeThing() {
我们定位到13行需要优化。
总结
pprof 还有很多玩法,包括其他的性能指标,go tool 的其他命令,profile 文件的可视化等。这个留给读者自行扩展阅读。
本文主要参考了 Russ Cox 大神的文章:《Profiling Go Programs》 (go.dev/blog/pprof)… 文章为反驳 "Go性能不如其他语言"的观点,借助 pprof 大幅度优化了程序的运行时间和内存。
以上就是Go 库性能分析工具pprof的详细内容,更多关于Go pprof性能分析的资料请关注脚本之家其它相关文章!