golang性能分析利器-pprof golang后端服务器程序员

前言作为一名gopher,不知道你是否遇到过以下问题？

CPU突然飙高(甚至死循环,CPU跑满)？
某个功能接口QPS在压测中一直压不上去？
应用出现goroutine泄露？
内存居高不下？
在某处加锁的逻辑中，迟迟得不到锁？

你是否能得心应手的找到问题的症结所在，你又是使用什么方法或工具解决的呢？今天我将介绍下我经常使用的工具pprof.它是golang自带的性能分析大杀器，基本上能快速解决上述问题。
如何使用pprof 使用pprof有三种姿势，一种是使用runtime/pprof/pprof.go另一种是使用net/http/pprof/pprof.go（底层也是使用runtime/pprof）,还有一种是在单元测试中生成profile 数据。详细的方法在对应的pprof.go文件开头有说明。
1. runtime/pprof 方式pprof

package mainimport ( "flag" "log" "os" "runtime" "runtime/pprof" )var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to `file`") var memprofile = flag.String("memprofile", "", "write memory 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) } defer f.Close() // error handling omitted for example if err := pprof.StartCPUProfile(f); err != nil { log.Fatal("could not start CPU profile: ", err) } defer pprof.StopCPUProfile() }// ... rest of the program ...if *memprofile != "" { f, err := os.Create(*memprofile) if err != nil { log.Fatal("could not create memory profile: ", err) } defer f.Close() // error handling omitted for example runtime.GC()// get up-to-date statistics if err := pprof.WriteHeapProfile(f); err != nil { log.Fatal("could not write memory profile: ", err) } } }

这种方式需要你手动启动需要pprof的类型，比如，开启CPU profile 还是heap profile 等等，pprof 会在应用启动到结束的整个生命周期生成profile 文件。其实生成profile 数据是会损耗性能的，生产环境不建议一直开启，可以在需要分析的时候临时采集那个时刻的数据，如通过监听系统信号的方式开启/关闭pprof,示例代码如下：

package mainimport ( "flag" "log" "os" "runtime" "runtime/pprof" ) var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to `file`") var memprofile = flag.String("memprofile", "", "write memory profile to `file`")func signalStopPprof(f *os.File) { c := make(chan os.Signal, 1) signal.Notify(c, syscall.SIGUSR2) for _ = range c { pprof.StopCPUProfile() log.Println("stopprofile") _ = f.Close() } } func signalStartPprof(f *os.File) { c := make(chan os.Signal, 1) signal.Notify(c, syscall.SIGUSR1) for _ = range c { _ = f.Truncate(0) if err := pprof.StartCPUProfile(f); err != nil { log.Println("could not start CPU profile: ", err) } } } func main() { flag.Parse() if *cpuprofile != "" { f, err := os.Create(*cpuprofile) if err != nil { log.Fatal("could not create CPU profile: ", err) } go func() { signalStartPprof(f) }() go func() { signalStopPprof(f) }() } // ... rest of the program ... }

不过本人还是更加喜欢第二种方式net/http/pprof
2. net/http/pprof 方式pprof

package mainimport ( "log" "net/http" _ "net/http/pprof" )func main() { go func() { log.Println(http.ListenAndServe("localhost:6060", nil)) }() // ... rest of the program ... }

是不是很简单，这种方式只需要开启http服务，并且import _ "net/http/pprof",他会自动把相应的http的handleFunc 注册上去，若你使用的不是DefaultServeMux,需要自己手动注册下。

func init() { http.HandleFunc("/debug/pprof/", Index) http.HandleFunc("/debug/pprof/cmdline", Cmdline) http.HandleFunc("/debug/pprof/profile", Profile) http.HandleFunc("/debug/pprof/symbol", Symbol) http.HandleFunc("/debug/pprof/trace", Trace) }

3. 单元测试中进行profile

go test -cpuprofile cpu.prof -memprofile mem.prof -bench .

分析pprof 在上文如何使用pprof中介绍的三种开启pprof的方式，他们都会生成profile二进制文件，有三种方式可以分析这个二进制文件

姿势一：通过交互命令行,方法：go tool pprof {profile文件}
若是通过http方式开启pprof，可以
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
若是通过方式1和3生成文件,可以
go tool pprof cpu.prof
命令交互行如下
文章图片
姿势二：通过web方式查看，方法 go tool pprof -http=:6060 {profile文件}
然后就可以在浏览器中访问 http://localhost:6060/
当然也有一种方式在姿势一中介绍的命令行交互中输入web会生成 .svg文件，不过需要安装graphviz来打开这个文件，不推荐，还是建议使用命令行或本地启动web服务来查看profile 数据.

实战演练 1.定位CPU问题自己写了一个模拟程序，模拟CPU问题，
按照上述姿势一打开命令行交互，执行top10,输出采样期间CPU使用最高的10个方法

文章图片

这里简单介绍下flat flat% sum% cum cum%这五个参数的含义,详细可以查看Pprof and golang - how to interpret a results?
flat：指的是该方法所占用的CPU时间（不包含这个方法中调用其他方法所占用的时间）
flat%: 指的是该方法flat时间占全部采样时间的比例
cum：指的是该方法以及方法中调用其他方法所占用的CPU时间总和，这里注意区别于flat
cum%:指的是该方法cum时间占全部采样时间的比例
sum%: 指的是执行到当前方法累积占用的CPU时间总和，也即是前面flat%总和
上图可以看出worker()占用CPU时间较久，我们可以list main.worker查看具体代码

文章图片

当然也可以通过上述姿势二，启动web服务查看火焰图go tool pprof -http=:6061 cpu.profile
打开http://localhost:6061/ui/ 火焰图如下，其中颜色越红代表占用的CPU时间越多

文章图片

找到了耗时比较久的地方，就能看看正常的业务代码还是可以优化的逻辑，就可以优化后在pprof
2. 定位内存问题排查内存再用过高问题

文章图片

其中inuse_space表示查看常驻内存的使用情况
list 查看相应的函数

文章图片

原来是一致在append内存，并持有到1GB不释放
当然还可以使用alloc_objects：分析应用程序的内存临时分配情况

文章图片

【golang性能分析利器-pprof】可以看到应用稳定后，除了上面初始分配1GB外，应用临时内存分配主要在worker中
3.定位goroutine问题例如goroutine泄露等问题，方法如下

文章图片

可以打出各个goroutine的调用栈

文章图片

可以看到有900+ 的goroutine 阻塞在runtime/gopark并且是由main.goroutine.fun1方法引起的 list 查看方法内容list main.goroutine.fun1

文章图片

可以看出主要是阻塞在channel c 上.当然也可以通过traces runtime.gopark 查看那些方法最终阻塞在gopark上，另外也可以在web页面http://localhost:6060/debug/p...直接查看。
4.定位锁问题锁的问题可能导致程序运行缓慢，pprof mutex 相关的需要设置采样率
runtime.SetMutexProfileFraction(1),若采样率<0 将不进行采样