场景
我们一般没必要过度优化 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性能分析的资料请关注编程网其它相关文章!