Go性能调优-pprof

在计算机性能调试领域里，profiling是指对应用程序的画像，画像就是应用程序使用 CPU 和内存的情况。 Go语言是一个对性能特别看重的语言，因此语言中自带了profiling的库，这篇文章就要讲解怎么在golang中做profiling。

Go性能优化

Go语言项目中的性能优化主要有以下几个方面：

CPU profile：报告程序的 CPU 使用情况，按照一定频率去采集应用程序在 CPU 和寄存器上面的数据Memory Profile（Heap Profile）：报告程序的内存使用情况Block Profiling：报告 goroutines 不在运行状态的情况，可以用来分析和查找死锁等性能瓶颈Goroutine Profiling：报告 goroutines 的使用情况，有哪些 goroutine，它们的调用关系是怎样的

采集性能数据

Go语言内置了获取程序的运行数据的工具，包括以下两个标准库：

runtime/pprof：采集工具型应用运行数据进行分析net/http/pprof：采集服务型应用运行时数据进行分析

pprof开启后，每隔一段时间（10ms）就会收集下当前的堆栈信息，获取各个函数占用的CPU以及内存资源；最后通过对这些采样数据进行分析，形成一个性能分析报告。

注意，我们只应该在性能测试的时候才在代码中引入pprof。

工具型应用

如果你的应用程序是运行一段时间就结束退出类型。那么最好的办法是在应用退出的时候把 profiling 的报告保存到文件中，进行分析。对于这种情况，可以使用runtime/pprof库。 首先在代码中导入runtime/pprof工具：

import "runtime/pprof"

CPU性能分析

开启CPU性能分析：

pprof.StartCPUProfile(w io.Writer)

停止CPU性能分析：

pprof.StopCPUProfile()

应用执行结束后，就会生成一个文件，保存了我们的 CPU profiling 数据。得到采样数据之后，使用go tool pprof工具进行CPU性能分析。

内存性能优化

记录程序的堆栈信息

pprof.WriteHeapProfile(w io.Writer)

得到采样数据之后，使用go tool pprof工具进行内存性能分析。

go tool pprof默认是使用-inuse_space进行统计，还可以使用-inuse-objects查看分配对象的数量。

数据分析

go tool pprof最简单的使用方式为:

go tool pprof [binary] [source]

其中：

binary 是应用的二进制文件，用来解析各种符号；source 表示 profile 数据的来源，可以是本地的文件，也可以是 http 地址。

注意事项：获取的 Profiling 数据是动态的，要想获得有效的数据，请保证应用处于较大的负载（比如正在生成中运行的服务，或者通过其他工具模拟访问压力）。否则如果应用处于空闲状态，得到的结果可能没有任何意义。

具体示例

首先我们来写一段有问题的代码：

package mainimport ("flag""fmt""os""runtime/pprof""time")// 一段有问题的代码func logicCode() {var c chan intfor {select {case v := <-c:fmt.Printf("recv from chan, value:%v\n", v)default://修正让出CPU//time.Sleep(time.Millisecond)}}}func main() {var isCPUPprof boolvar isMemPprof boolflag.BoolVar(&isCPUPprof, "cpu", false, "turn cpu pprof on")flag.BoolVar(&isMemPprof, "mem", false, "turn mem pprof on")flag.Parse()if isCPUPprof {f1, err := os.Create("./cpu.pprof")if err != nil {fmt.Printf("create cpu pprof failed, err:%v\n", err)return}_ = pprof.StartCPUProfile(f1)defer func() {pprof.StopCPUProfile()_ = f1.Close()}()}for i := 0; i < 6; i++ {go logicCode()}time.Sleep(10 * time.Second)if isMemPprof {f2, err := os.Create("./mem.pprof")if err != nil {fmt.Printf("create mem pprof failed, err:%v\n", err)return}defer func() {_ = pprof.WriteHeapProfile(f2)_ = f2.Close()}()}}

通过flag我们可以在命令行控制是否开启CPU和Mem的性能分析。 将上面的代码保存并编译成runtime_pprof可执行文件，执行时加上-cpu命令行参数如下：

./runtime_pprof -cpu

等待30秒后会在当前目录下生成一个cpu.pprof文件。

命令行交互界面

我们使用go工具链里的pprof来分析一下。

go tool pprof cpu.pprof

执行上面的代码会进入交互界面如下：

runtime_pprof $ go tool pprof cpu.pprofType: cpuTime: Jun 28, at 11:28am (CST)Duration: 20.13s, Total samples = 1.91mins (568.60%)Entering interactive mode (type "help" for commands, "o" for options)(pprof)

我们可以在交互界面输入top3来查看程序中占用CPU前3位的函数：

(pprof) top3Showing nodes accounting for 100.37s, 87.68% of 114.47s totalDropped 17 nodes (cum <= 0.57s)Showing top 3 nodes out of 4flat flat% sum% cum cum%42.52s 37.15% 37.15%91.73s 80.13% runtime.selectnbrecv35.21s 30.76% 67.90%39.49s 34.50% runtime.chanrecv22.64s 19.78% 87.68% 114.37s 99.91% main.logicCode

其中：

flat：当前函数占用CPU的耗时flat：:当前函数占用CPU的耗时百分比sun%：函数占用CPU的耗时累计百分比cum：当前函数加上调用当前函数的函数占用CPU的总耗时cum%：当前函数加上调用当前函数的函数占用CPU的总耗时百分比最后一列：函数名称

在大多数的情况下，我们可以通过分析这五列得出一个应用程序的运行情况，并对程序进行优化。

我们还可以使用list 函数名命令查看具体的函数分析，例如执行list logicCode查看我们编写的函数的详细分析。

(pprof) list logicCodeTotal: 1.91minsROUTINE ================ main.logicCode in .../runtime_pprof/main.go22.64s 1.91mins (flat, cum) 99.91% of Total..12:func logicCode() {..13: var c chan int..14: for {..15: select {..16: case v := <-c:22.64s 1.91mins17: fmt.Printf("recv from chan, value:%v\n", v)..18: default:..19:..20: }..21: }..22:}

通过分析发现大部分CPU资源被17行占用，我们分析出select语句中的default没有内容会导致上面的case v:=<-c:一直执行。我们在default分支添加一行time.Sleep(time.Second)即可。

图形化

或者可以直接输入web，通过svg图的方式查看程序中详细的CPU占用情况。 想要查看图形化的界面首先需要安装graphviz图形化工具。

Mac：

brew install graphviz

Windows: 下载graphviz 将graphviz安装目录下的bin文件夹添加到Path环境变量中。 在终端输入dot -version查看是否安装成功。

关于图形的说明： 每个框代表一个函数，理论上框的越大表示占用的CPU资源越多。 方框之间的线条代表函数之间的调用关系。 线条上的数字表示函数调用的次数。 方框中的第一行数字表示当前函数占用CPU的百分比，第二行数字表示当前函数累计占用CPU的百分比。

除了分析CPU性能数据，pprof也支持分析内存性能数据。比如，使用下面的命令分析http服务的heap性能数据，查看当前程序的内存占用以及热点内存对象使用的情况。

# 查看内存占用数据go tool pprof -inuse_space http://127.0.0.1:8080/debug/pprof/heapgo tool pprof -inuse_objects http://127.0.0.1:8080/debug/pprof/heap# 查看临时内存分配数据go tool pprof -alloc_space http://127.0.0.1:8080/debug/pprof/heapgo tool pprof -alloc_objects http://127.0.0.1:8080/debug/pprof/heap

火焰图

火焰图（Flame Graph）是 Bredan Gregg 创建的一种性能分析图表，因为它的样子近似 🔥而得名。上面的 profiling 结果也转换成火焰图，如果对火焰图比较了解可以手动来操作，不过这里我们要介绍一个工具：go-torch。这是 uber 开源的一个工具，可以直接读取 golang profiling 数据，并生成一个火焰图的 svg 文件。

新版的Go内置pprof已内置火焰图插件, 网上大多数教程是独立安装

新版只需运行一下命令

go tool pprof -http=:8080 cpu.pprofServing web UI on http://localhost:8080

打开浏览器访问:http://localhost:8080

点击上方菜单，切换视图

服务型应用

如果你的应用程序是一直运行的，比如 web 应用，那么可以使用net/http/pprof库，它能够在提供 HTTP 服务进行分析。

如果使用了默认的http.DefaultServeMux（通常是代码直接使用http.ListenAndServe(“0.0.0.0:8000”, nil)），只需要在你的web server端代码中按如下方式导入net/http/pprof

import _ "net/http/pprof"

如果你使用自定义的 Mux，则需要手动注册一些路由规则：

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)

如果你使用的是gin框架，那么推荐使用/gin-contrib/pprof，在代码中通过以下命令注册pprof相关路由。

pprof.Register(router)

不管哪种方式，你的 HTTP 服务都会多出/debug/pprof endpoint，访问它会得到类似下面的内容：

这个路径下还有几个子页面：

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

gin框架使用

main.go

package mainimport ("fmt""/DeanThompson/ginpprof""/gin-gonic/gin""io""os""pprof/controllers")func main() {gin.DisableConsoleColor() //关闭颜色//gin.SetMode(gin.DebugMode)gin.SetMode(gin.ReleaseMode)logfile, err := os.OpenFile("logs/gin_http.log", os.O_CREATE|os.O_APPEND|os.O_RDWR, 0666)if err != nil {fmt.Println("Could not create log file")}gin.DefaultWriter = io.MultiWriter(logfile)r := gin.Default()//r.Use(middlewares.Cors())Group := r.Group("user"){Group.GET("/reg", controllers.Reg)}ginpprof.Wrap(r)// ginpprof also plays well with *gin.RouterGroup// group := router.Group("/debug/pprof")// ginpprof.WrapGroup(group)_ = r.Run(":8880")}

controllers/user.go

package controllersimport ("/gin-gonic/gin""net/http")func Reg(context *gin.Context) {uid := context.DefaultQuery("uid", "0")context.JSON(http.StatusOK, gin.H{"code": 1,"msg": "Success","data": uid,})}

压测工具wrk

推荐使用/wg/wrk 或 /adjust/go-wrk, 或者使用apache的ab进行压测

启动分析程序：

go tool pprof -http=:8080 http://localhost:8880/debug/pprof/profileFetching profile over HTTP from http://localhost:8880/debug/pprof/profileSaved profile in C:\Users\soul\pprof\pprof.samples.cpu.004.pb.gzServing web UI on http://localhost:8080

启动wrk进行压测:

go-wrk -n 10000 http://localhost:8880/user/reg?uid=10000

我这里使用ab进行压测：

ab -n100000 -c 200 http://localhost:8880/user/reg?uid=10000This is ApacheBench, Version 2.3 <$Revision: 1843412 $>Copyright 1996 Adam Twiss, Zeus Technology Ltd, /Licensed to The Apache Software Foundation, /Benchmarking localhost (be patient)Completed 10000 requestsCompleted 20000 requestsCompleted 30000 requestsCompleted 40000 requestsCompleted 50000 requestsCompleted 60000 requestsCompleted 70000 requestsCompleted 80000 requestsCompleted 90000 requestsCompleted 100000 requestsFinished 100000 requestsServer Software:Server Hostname: localhostServer Port: 8880Document Path:/user/reg?uid=10000Document Length: 41 bytesConcurrency Level:200Time taken for tests: 40.115 secondsComplete requests:100000Failed requests: 0Total transferred:16400000 bytesHTML transferred: 4100000 bytesRequests per second: 2492.85 [#/sec] (mean)Time per request: 80.229 [ms] (mean)Time per request: 0.401 [ms] (mean, across all concurrent requests)Transfer rate:399.25 [Kbytes/sec] receivedConnection Times (ms)min mean[+/-sd] median maxConnect: 0 0 0.40 3Processing: 12 80 5.579123Waiting: 2 58 15.259121Total: 12 80 5.579123Percentage of the requests served within a certain time (ms)50%7966%8175%8280%8490%8695%8898%9299%94100% 123 (longest request)

30秒之后会自动打开浏览器：http://localhost:8080

查看火焰图

火焰图的y轴表示cpu调用方法的先后，x轴表示在每个采样调用时间内，方法所占的时间百分比，越宽代表占据cpu时间越多。通过火焰图我们就可以更清楚的找出耗时长的函数调用，然后不断的修正代码，重新采样，不断优化。

pprof与性能测试结合

go test命令有两个参数和pprof相关，它们分别指定生成的CPU和Memory profiling保存的文件：

-cpuprofile：cpu profiling 数据要保存的文件地址-memprofile：memory profiling 数据要报文的文件地址

我们还可以选择将pprof与性能测试相结合，比如：

比如下面执行测试的同时，也会执行 CPU profiling，并把结果保存在 cpu.prof 文件中：

go test -bench . -cpuprofile=cpu.prof

比如下面执行测试的同时，也会执行Mem profiling，并把结果保存在cpu.prof文件中：

go test -bench . -memprofile=./mem.prof

需要注意的是，Profiling 一般和性能测试一起使用，这个原因在前文也提到过，只有应用在负载高的情况下 Profiling 才有意义。

参考文章：/posts/Go/performance_optimisation/

如果觉得《Go性能调优-pprof》对你有帮助，请点赞、收藏，并留下你的观点哦！