golang：性能分析和pprof

golang编写的程序在开发过程、运行过程中可能会出现一些意想不到的问题，诸如：cpu暴涨、内存吃紧、接口响应时间过长、goroutine数量暴涨等等问题，这个时候就涉及到性能分析和问题定位排查。

在Go语言中，PProf 是用于可视化和分析性能分析数据的工具，pprof以profile.proto读取分析样本的集合，并生成报告以可视化并帮助分析数据（支持文本和图形报告）。profile.proto是一个Protobuf v3的描述文件，它描述了一组callstack和 symbolization信息，作用是统计分析的一组采样的调用栈，是很常见的stacktrace配置文件格式。

pprof

go语言原生提供pprof工具，有两个包runtime/pprof和net/http/pprof，查找资料的过程中也有提到go test命令也可以通过写测试用例采样分析，这个不是本文的重点略过。

通过pprof这个工具也就是使用go官方提供的两个包可得到一些分析报告或执行一些分析：

生成报告：即生成一个后续可用来分析的性能分析报告文件
交互式终端里直接输入命令查看各项指标
web界面报告：即打开一个web网页，在页面里点点点就可以看到各种图形化一目了然的指标

pprof的分析报告可以为我们提供如下类型的分析指标<这段是摘除>：

CPU Profiling：CPU 分析，按照一定的频率采集所监听的应用程序 CPU（含寄存器）的使用情况，可确定应用程序在主动消耗 CPU 周期时花费时间的位置。
Memory Profiling：内存分析，在应用程序进行堆分配时记录堆栈跟踪，用于监视当前和历史内存使用情况，以及检查内存泄漏。
Block Profiling：阻塞分析，记录 Goroutine 阻塞等待同步（包括定时器通道）的位置，默认不开启，需要调用 runtime.SetBlockProfileRate 进行设置。
Mutex Profiling：互斥锁分析，报告互斥锁的竞争情况，默认不开启，需要调用 runtime.SetMutexProfileFraction 进行设置。
Goroutine Profiling： Goroutine 分析，可以对当前应用程序正在运行的 Goroutine 进行堆栈跟踪和分析。这项功能在实际排查中会经常用到，因为很多问题出现时的表象就是 Goroutine 暴增，而这时候我们要做的事情之一就是查看应用程序中的 Goroutine 正在做什么事情，因为什么阻塞了，然后再进行下一步。

http服务的pprof

go原生提供http便捷服务开发包，一个典型的http服务结构如下：

package main

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

func main()  {
	srv := &http.Server{
		Addr:           ":9080",
		Handler:        nil,
		ReadTimeout:    60 * time.Second,
		WriteTimeout:   65 * time.Second,
		MaxHeaderBytes: 1 << 20, //1MB
	}

	http.HandleFunc("/hello", func(writer http.ResponseWriter, request *http.Request) {
		_, _ = writer.Write([]byte("hello world!"))
	})

	_ = srv.ListenAndServe()
}

注意第6行import了一个_ "net/http/pprof"即仅调用了该包的init方法，可以查看该包的init方法，代码就几行如下：

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)
}

引入net/http/pprof包就是为go提供的默认服务器注册了几个路由，那么这几个路由就可以直接在浏览器访问了。那么启动这段代码，访问一下这几个路由，注意代码中注册的handler是可导出方法，这也就是意味着可以自定义路由。

一些指标的说明<这段是摘除>：

allocs：查看过去所有内存分配的样本，访问路径为 $HOST/debug/pprof/allocs
block：查看导致阻塞同步的堆栈跟踪，访问路径为 $HOST/debug/pprof/block
cmdline：当前程序的命令行的完整调用路径。
goroutine：查看当前所有运行的 goroutines 堆栈跟踪，访问路径为 $HOST/debug/pprof/goroutine
heap：查看活动对象的内存分配情况，访问路径为 $HOST/debug/pprof/heap
mutex：查看导致互斥锁的竞争持有者的堆栈跟踪，访问路径为 $HOST/debug/pprof/mutex
profile：默认进行 30s 的 CPU Profiling，得到一个分析用的 profile 文件，访问路径为 $HOST/debug/pprof/profile
threadcreate：查看创建新 OS 线程的堆栈跟踪，访问路径为 $HOST/debug/pprof/threadcreate

可视化图形分析

pprof默认提供的http访问形式的界面针对具体的指标查看分析。开发阶段大多时候会分析程序的耗时分布，便于代码调整，这就涉及到将profile文件转换成为可视化svg图。与go提供的默认网页形式的原理是一致的，可视化查看调用栈耗时分布只不过是使用了graphviz组件将抓取到的调用堆栈信息绘制成图。所以调试环境需要安装graphviz这个库。否则会提示Could not execute dot; may need to install graphviz.

1、获取profile文件

启动已加载pprof的服务，终端里通过wget命令获取profile文件：

wget http://127.0.0.1:9080/debug/pprof/profile\?seconds\=20

go1.16版里使用seconds指定采样时间，注意wget命令的URL参数会有反斜杠转义。注意获取profile文件是通过http获取，故而http超时配置中WriteTimeout会影响是否正常获取到profile，因为默认获取profile超时为30秒，如果http服务的配置中超时时长小于该值可能会出现： profile duration exceeds server's WriteTimeout 错误提示。解决方案就是url里seconds值小于http服务配置中WriteTimeout值，或者使用默认seconds即30秒调整配置值WriteTimeout大于30秒即可。

上述wget命令会阻塞采样，阻塞采样期间如果要查看某个接口的采样分析结果，这个时候需要去访问这个接口以便执行这个接口相关的逻辑。

2、生成可视化网页和图

获得文件名称为profile的文件后，通过go工具链命令即可生成更为详细的性能数据和图表。

go tool pprof -http=:6001 profile

以及所谓的火焰图

自定义抓取profile

查看net/http/pprof包里的的方法Profile方法最后还是调用了runtime/pprof包里的相关方法，所以本质上net/http/pprof包只是runtime/pprof包的一个包裹成http可访问形式的封装，核心还是runtime/pprof包。

// Profile responds with the pprof-formatted cpu profile.
// Profiling lasts for duration specified in seconds GET parameter, or for 30 seconds if not specified.
// The package initialization registers it as /debug/pprof/profile.
func Profile(w http.ResponseWriter, r *http.Request) {
	w.Header().Set("X-Content-Type-Options", "nosniff")
	sec, err := strconv.ParseInt(r.FormValue("seconds"), 10, 64)
	if sec <= 0 || err != nil {
		sec = 30
	}

	if durationExceedsWriteTimeout(r, float64(sec)) {
		serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout")
		return
	}

	// Set Content Type assuming StartCPUProfile will work,
	// because if it does it starts writing.
	w.Header().Set("Content-Type", "application/octet-stream")
	w.Header().Set("Content-Disposition", `attachment; filename="profile"`)
	if err := pprof.StartCPUProfile(w); err != nil {
		// StartCPUProfile failed, so no writes yet.
		serveError(w, http.StatusInternalServerError,
			fmt.Sprintf("Could not enable CPU profiling: %s", err))
		return
	}
	sleep(r, time.Duration(sec)*time.Second)
	pprof.StopCPUProfile()
}

故而如何使用runtime/pprof包的样例伪代码就出来了，如下：

// 启动cpu采样，参数为一个io.Writer接口，通过参数可以指定将采样写到何处，譬如：文件
pprof.StartCPUProfile(writer)
// 采样开始执行后会启动一个协程去持续的采样获取样本数据
// 故而当前协程需要暂停等待协程去执行采样
time.sleep(t)
// 采样结束调用停止方法，本质是通过chan传递一个消息告诉上述采样协程需要停止
pprof.StopCPUProfile()

---

参考资料：

① https://golang2.eddycjy.com/posts/ch6/01-pprof-1/

转载请注明本文标题和链接：《golang：性能分析和pprof》