Go 库性能分析工具pprof
小马别过河 人气:0场景
我们一般没必要过度优化 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 大幅度优化了程序的运行时间和内存。
加载全部内容