golang性能分析工具pprof介绍

1 golang性能分析工具pprof介绍

pprof是golang内置的性能分析工具，在进行性能问题分析(入内存泄露，goroutine泄露,cpu资源占用较高等分析)时使用，其可成为我们进行golang开发时，调试应用性能的常用工具。
本文从介绍pprof，到如何集成到代码中，再到如何使用pprof来进行cpu耗时分析、内存分析、锁耗时分析、阻塞分析、goroutine泄露等场景

1.1 pprof简介

profile在计算机领域，我们可以将其理解为当前应用程序运行状态的画像。当程序性能不佳时，我们希望知道应用在 什么地方耗费了多少 CPU、memory等资源，golang是非常注重性能的语言，其内置的pprof就是为了分析调优程序运行性能而生。

pprof主要模块介绍：

• CPU profile：当前程序的CPU使用情况，pprof按照一定频率去采集应用程序在CPU和寄存器上面的数据
• Memory Profile（Heap Profile）：当前程序的内存使用情况，可查看heap和alloc的情况
• Block Profiling：程序当前goroutines不在运行状态的情况，可以用来分析和查找死锁等性能瓶颈
• Goroutine Profiling：程序当前goroutines的使用情况，查看所有goroutine，产看调用关系，可发现未释放的go程

1.2 pprof引入方法

pprof引入代码有两种方式，一种是项目中导入runtime/pprof,主要用来产生dump文件，然后再使用 Go Tool PProf 来分析这运行日志，此种方式在普通的单机程序未使用http网络服务上使用。另一种方式是项目中导入net/http/pprof,net/http/pprof是对runtime/pprof的封装，如果当前程序已启用http服务，使用此种方式非常方便，以做到直接在web上看到当前 web 服务的状态，包括 CPU 占用情况和内存使用情况等，由于我当前参与的项目都会开启http，因此本文主要介绍第二种方式。

使用import "net/http/pprof"也可以很方面的集成到我们代码中，其方式如下：

//再main包中加入
import _ "net/http/pprof"
1
2

其调用pprof的init函数如下：

//pprof.go
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)
}
1
2
3
4
5
6
7
8

可以看到其把相关的路由加到DefaultServeMux路由器中了，如果我们程序开启了http服务，并使用HTTP默认路由分发器DefaultServeMux，则只需要再main包中导入import _ "net/http/pprof",即可通过"http://ip:port/debug/pprof"进行pprof接口访问，如果程序未开启使用默认路由器的http服务，可再main函数中开启一个httpserver即可，如下例子：

package main

import (
    "log"
    "net/http"
    _ "net/http/pprof"
)

func main() {
    go func() {
        http.ListenAndServe("0.0.0.0:9009", nil)//开启一个http服务，nil表示绑定默认路由器DefaultServeMux
    }()
  // ... rest of the program ...
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14

如果程序开启了http服务器，并自定义了路由器ServeMux，则只需要把pprof相关的路径加入到自定义的ServeMux中即可，不需要单独开启http服务：

r := http.NewServeMux()
r.HandleFunc("/debug/pprof/", pprof.Index)
r.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
r.HandleFunc("/debug/pprof/profile", pprof.Profile)
r.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
r.HandleFunc("/debug/pprof/trace", pprof.Trace)
http.ListenAndServe("0.0.0.0:9009", r)//程序业务的httpserver，自定义了mux，需要把pprof的路径加进去ike
1
2
3
4
5
6
7

以上三种方式都可开启pprof，最好的方式还是把pprof集成到当前已开启的httpserver中去，如果http的server采用默认的servermux，则只需要在main中导入
import _ "net/http/pprof"即可通过http://ip:port/debug/pprof来访问。

假设本机启动，http端口为9009，启动程序后访问：http://127.0.0.1:9009/debug/pprof，即可看到pprof>监控界面：

还可直接访问如下几个路径：

• /debug/pprof/profile：自动进行CPU profiling，持续 30s，并生成一个文件供下载
• /debug/pprof/heap： Memory Profiling 的路径，访问这个链接会得到一个内存 Profiling 结果的文件
• /debug/pprof/block：block Profiling 的路径
• /debug/pprof/goroutines：运行的 goroutines 列表，以及调用关系

1.3 使用pprof进行分析的方法

可通过网页进行分析，通过http://127.0.0.1:9009/debug/pprof打开pprof网页，点击各个分类可直接进入日志文件，页面各个分类解释如下：

通过网页方式分析，可看整体情况，比如gotouine持续增多，说明有go程未被正确释放，但是器可读性不高，一般可以通过go tool方式进行分析。

1.3.1 内存占用分析

分析代码中内存占用较大的地方，分析潜在的内存泄漏，优化内存分配，示例代码如下：

package main

import (
 "fmt"
 "net/http"
 _ "net/http/pprof"
 "time"
)

func main() {
 fmt.Println("hello world")
 go func() {
  http.ListenAndServe("0.0.0.0:9009", nil)
 }()
 go gotest()
 done := make(chan any)
 <-done
}

func gotest() {
 a := make([]int, 0)
 for {
  fmt.Println("go test")
  a = append(a, []int{9: 10}...)
  fmt.Println("go test,len(a):", len(a))
  time.Sleep(time.Duration(5) * time.Second)
 }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28

运行后在终端执行命令：go tool pprof -inuse_space http://127.0.0.1:9009/debug/pprof/heap
参数说明:

• inuse_space：分析应用程序的常驻内存占用情况(默认类型)
• alloc_objects：分析应用程序的内存临时分配情况

下载后得到可交互的命令行，然后输入top10，来查看正在使用的对象较多的10个函数入口。通常用来检测有没有不符合预期的内存对象引用。

参数解释：

• flat：指的是该方法所占用的CPU时间（不包含这个方法中调用其他方法所占用的时间）
• flat%: 指的是该方法flat时间占全部采样时间的比例
• cum：指的是该方法以及方法中调用其他方法所占用的CPU时间总和，这里注意区别于flat
• cum%:指的是该方法cum时间占全部采样时间的比例
• sum%: 指的是执行到当前方法累积占用的CPU时间总和，也即是前面flat%总和

上图中可以根据list [函数名] 查看main函数详细内存分配情况：
list main 可查看main函数查看具体函数占用情况

通过执行如下命令：go tool pprof -alloc_objects http://127.0.0.1:9009/debug/pprof/heap
看下临时内存分配情况，步骤同上(top10->list main)

list main命令之后，可以看到具体再append函数，内存一直增长，应该对代码进行优化。
top -cum命令：-cum表示将函数调用关系中的数据进行累积，比如A函数调用的B函数，则B函数中的内存分配量也会累积到A上面，这样能够明确定位到那个函数内存出现问题。

1.3.2 CPU耗时分析

执行: go tool pprof http://127.0.0.1:9009/debug/pprof/profile
会搜集30s对cpu采样，对cpu性能进行分析，可查看正在使用的一些CPU相关信息

从上图可以看出gotest函数占用过多cpu，list gotest 可以看到里面有一个死循环。

1.3.3 goroutine泄露分析

执行命令：go tool pprof http://127.0.0.1:9009/debug/pprof/goroutine
可以查看当前goroutine的信息
输入：trace
可以打出各个goroutine的调用栈

从图中可以看出main启动的gotest较多，阻塞再runtime/gopark，又读取chan引起的，也可以通过’traces runtime.gopark’ 查看那些方法最终阻塞

1.3.4 锁耗时分析

锁的问题可能导致程序运行缓慢，pprof mutex 相关的需要设置采样率,再main函数中加入runtime.SetMutexProfileFraction(1)
执行命令：go tool pprof http://127.0.0.1:9009/debug/pprof/mutex
通过top->traces [函数] ->list [函数]
最终可以可以检查出那个锁耗时较大

1.3.5 goroutine阻塞等待分析

同样需要设置采样率：runtime.SetBlockProfileRate(1)
执行命令：go tool pprof http://127.0.0.1:9009/debug/pprof/block
主要是记录goroutine阻塞等待同步的位置,通过top->traces [函数] ->list [函数],查看等待位置

从图中可以看到最终阻塞的地方