# 简介 pprof是性能调试工具，可以生成类似火焰图、堆栈图，内存分析图等。整个分析的过程分为两步：1. 导出数据，2. 分析数据。 # 导出数据 ## 网页两步，第一步，在引用中加上 ``` "net/http" _ "net/http/pprof" ``` 第二步，在代码开始运行的地方加上 ``` go func() { log.Println(http.ListenAndServe(":6060", nil)) }() ``` 接着，我们访问，即可看到 ![image-20210716210533942.png](http://p1-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/99bcbe911cbe4b619b1990d81427df8e~tplv-k3u1fbpfcp-watermark.image?) - allocs：查看过去所有内存分配的样本。 - block：查看导致阻塞同步的堆栈跟踪。 - cmdline：当前程序的命令行的完整调用路径。 - goroutine：查看当前所有运行的 goroutines 堆栈跟踪。 - heap：查看活动对象的内存分配情况。 - mutex：查看导致互斥锁的竞争持有者的堆栈跟踪。 - profile：默认进行 30s 的 CPU Profiling，得到一个分析用的 profile 文件。 - threadcreate：查看创建新 OS 线程的堆栈跟踪。 - trace：注意，默认情况下是不追踪block和mutex的信息的，如果想要看这两个信息，需要在代码中加上两行： ``` runtime.SetBlockProfileRate(1) // 开启对阻塞操作的跟踪，block runtime.SetMutexProfileFraction(1) // 开启对锁调用的跟踪，mutex ``` 注意，上文的所有信息都是实时的，如果你刷新一下，是可以看到数字在变化的。此时如果点击蓝色的连接，可以看到一些协程的栈信息，这些信息并不容易阅读。如果想要更加清晰的数据，需要将信息保存下来，在本地进行分析。有两种方式下载信息方法一（推荐）：直接运行`go tool pprof http://localhost:6060/debug/pprof/XXX`，其会自动下载数据到本地，然后供你分析。（这个命令具体怎么用，见后文）方法二：访问`http://localhost:6060/debug/pprof/XXX`，游览器就会提醒你下载文件。这里有一个小点要注意，在这个页面下，点击`profile`和`trace`总是会下载文件。而点击其他链接会跳转到另一个页面，来展示一些数据，但是可读性也比较差。如果点击`profile`，程序会开始进行半分钟（默认值）的CPU采样，然后才会下载文件。 ![image-20210716210533942.png](http://p1-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/99bcbe911cbe4b619b1990d81427df8e~tplv-k3u1fbpfcp-watermark.image?) 在跳转到页面中，会发现URL带有`?debug=1`的后缀，如果把这个后缀去掉，则也会提示你下载文件。总之，目前这个页面最有用的数据就是直接看看协程数，看看同步数，看看堆和线程创建数。点进去的链接基本都没太强的可读性。操作到这里，能看到这个网页即可。 ## test 编写一个test程序，可以更加精准地进行测试。同时一起把性能表现看了，棒！和网页导出一样，test导出也拥有多个指标的查看方式，具体查看哪些指标，通过命令行的参数来配置。由于go test相比网页，更加定向，因此可以方便地来查看一些数据。这也一并列在这里。 ``` -bench=. 进行性能测试，“.”是正则匹配，匹配了所有的测试函数 -benchmem 打印出申请内存的次数。一般用于简单的性能测试，不会导出数据文件。 -blockprofile block.out 将协程的阻塞数据写入特定的文件（block.out）。如果-c，则写成二进制文件。 -cpuprofile cpu.out 将协程的CPU使用数据写入特定的文件（cpu.out）。如果-c，则写成二进制文件。 -memprofile mem.out 将协程的内存申请数据写入特定的文件（mem.out）。如果-c，则写成二进制文件。 -mutexprofile mutex.out 将协程的互斥数据写入特定的文件（mutex.out）。如果-c，则写成二进制文件。 -trace trace.out 将执行调用链写入特定文件（trace.out）。 ``` 可以看到，go test会把数据导出在特定的文件之中。之后分析数据就需要读取这些数据。和网页相似，这些数据本身的可读性很差，还是需要借助`go tool pprof`来分析。 # 分析数据现在要么已经可以打开`http://127.0.0.1:6060/debug/pprof`，要么已经有了一个数据文件。我们以CPU指标为例，看一下如何做分析。 ``` # 网页，运行该命令让程序开始半分钟（默认值）的CPU采样 $ go tool pprof http://127.0.0.1:6060/debug/pprof/profile # 看下图的红字，会把文件保存到某一个地址 ``` ![image-20210804142500950.png](http://p6-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/f6566fbf0ddc41efb0fdd0204107c8e2~tplv-k3u1fbpfcp-watermark.image?) ``` # 文件 $ go tool pprof cpu.out # 或者 $ go tool pprof pprof.XXX.samples.cpu.001.pb.gz ``` ![image-20210804142612570.png](http://p6-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/edb132d80d3c4335a8773f8806f238a3~tplv-k3u1fbpfcp-watermark.image?) 运行上面任一一个命令之后，pprof会等待我们进一步的指示，我们来运行一下help看一看 ``` (pprof) help Commands: callgrind Outputs a graph in callgrind format comments Output all profile comments disasm Output assembly listings annotated with samples dot Outputs a graph in DOT format eog Visualize graph through eog evince Visualize graph through evince gif Outputs a graph image in GIF format gv Visualize graph through gv kcachegrind Visualize report in KCachegrind list Output annotated source for functions matching regexp pdf Outputs a graph in PDF format peek Output callers/callees of functions matching regexp png Outputs a graph image in PNG format proto Outputs the profile in compressed protobuf format ps Outputs a graph in PS format raw Outputs a text representation of the raw profile svg Outputs a graph in SVG format tags Outputs all tags in the profile text Outputs top entries in text form top Outputs top entries in text form topproto Outputs top entries in compressed protobuf format traces Outputs all profile samples in text form tree Outputs a text rendering of call graph web Visualize graph through web browser weblist Display annotated source in a web browser o/options List options and their current values q/quit/exit/^D Exit pprof Options: call_tree Create a context-sensitive call tree compact_labels Show minimal headers divide_by Ratio to divide all samples before visualization drop_negative Ignore negative differences edgefraction Hide edges below *total focus Restricts to samples going through a node matching regexp hide Skips nodes matching regexp ignore Skips paths going through any nodes matching regexp intel_syntax Show assembly in Intel syntax mean Average sample value over first value (count) nodecount Max number of nodes to show nodefraction Hide nodes below *total noinlines Ignore inlines. normalize Scales profile based on the base profile. output Output filename for file-based outputs prune_from Drops any functions below the matched frame. relative_percentages Show percentages relative to focused subgraph sample_index Sample value to report (0-based index or name) show Only show nodes matching regexp show_from Drops functions above the highest matched frame. source_path Search path for source files tagfocus Restricts to samples with tags in range or matched by regexp taghide Skip tags matching this regexp tagignore Discard samples with tags in range or matched by regexp tagshow Only consider tags matching this regexp trim Honor nodefraction/edgefraction/nodecount defaults trim_path Path to trim from source paths before search unit Measurement units to display Option groups (only set one per group): granularity functions Aggregate at the function level. filefunctions Aggregate at the function level. files Aggregate at the file level. lines Aggregate at the source code line level. addresses Aggregate at the address level. sort cum Sort entries based on cumulative weight flat Sort entries based on own weight : Clear focus/ignore/hide/tagfocus/tagignore type "help " for more information (pprof) ``` 参数很多，但是我们常用的很少。我个人常用的只有两个，`top`和`web`。分别对应来文本分析和图分析。 ## 文本 `top`默认按flat排序，打印出消耗前10的函数。也可以选择消耗前N的函数，比如`top5`，`top20`。其中一共有五个指标。这些指标的含义见下文“理解指标”。 ``` (pprof) top Showing nodes accounting for 69.80s, 50.30% of 138.77s total Dropped 995 nodes (cum <= 0.69s) Showing top 10 nodes out of 133 flat flat% sum% cum cum% 19.83s 14.29% 14.29% 60.39s 43.52% runtime.mallocgc 10.03s 7.23% 21.52% 10.66s 7.68% runtime.heapBitsForAddr (inline) 7.22s 5.20% 26.72% 7.22s 5.20% runtime.nextFreeFast 6.28s 4.53% 31.25% 16.84s 12.14% runtime.heapBitsSetType 5.71s 4.11% 35.36% 6.75s 4.86% runtime.(*itabTableType).find 5.47s 3.94% 39.30% 10.19s 7.34% context.(*valueCtx).Value 4.24s 3.06% 42.36% 21.78s 15.70% errors.Is 3.90s 2.81% 45.17% 16.37s 11.80% runtime.gcDrain 3.71s 2.67% 47.84% 10.46s 7.54% runtime.getitab 3.41s 2.46% 50.30% 7.30s 5.26% runtime.scanobject ``` ## 图片要看图片，要先[安装graphviz](https://graphviz.org/download/)。 `web` 将会生成一张svg格式的图片，并用默认打开程序打开（一般是游览器）。 ![image-20210804150014494.png](http://p9-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/033120600c5045b291017a32d08fe62b~tplv-k3u1fbpfcp-watermark.image?) 另一种更加简便的看图的方式，运行如下命令 ``` $ go tool pprof -http=:8000 http://127.0.0.1:6060/debug/pprof/profile $ go tool pprof -http=:8000 cpu.out $ go tool pprof -http=:8000 pprof.XXX.samples.cpu.001.pb.gz ``` 这将会启动一个web服务器，并自动打开一个网页。这个网页最上方有一个header，我们可以切换到火焰图、top、连线图。 ![image-20220516115903957.png](http://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/66354ba269714d048319019117422a4f~tplv-k3u1fbpfcp-watermark.image?) 如果是内存信息`SAMPLE`这一栏有四个选项 `alloc_objects`：已分配的对象总量（不管是否已释放） `alloc_space`：已分配的内存总量（不管是否已释放） `inuse_objects`：已分配但尚未释放的对象数量 `inuse_sapce`：已分配但尚未释放的内存数量怎么看图，见下文“理解指标”、“理解连线图”、“理解火焰图” # 理解指标这一部分很重要！图中的参数也不会超过下面介绍的这些，只是调用关系更加清晰一点。 ## flat flat% 一个函数内的directly操作的物理耗时。例如 ``` func foo(){ a() // step1 largeArray := [math.MaxInt64]int64{} // step2 for i := 0; i < math.MaxInt64; i++ { // step3 c() // step4 } } ``` flat只会记录step2和step3的时间；flat%即是flat/总运行时间。内存等参数同理。所有的flat相加即是总采样时间，所有的flat%相加应该等于100%。 flat一般是我们最关注的。其代表一个函数可能非常耗时，或者调用了非常多次，或者两者兼而有之，从而导致这个函数消耗了最多的时间。如果是我们自己编写的代码，则很可能有一些无脑for循环、复杂的计算、字符串操作、频繁申请内存等等。如果是第三方库的代码，则很可能我们过于频繁地调用了这些第三方库，或者以不正确的方式使用了这些第三方库。 ## cum cum% 相比flat，cum则是这个函数内所有操作的物理耗时，比如包括了上述的step1、2、3、4。 cum%即是cum的时间/总运行时间。内存等参数同理。一般cum是我们次关注的，且需要结合flat来看。flat可以让我们知道哪个函数耗时多，而cum可以帮助我们找到是哪些函数调用了这些耗时的（flat值大的）函数。 ## sum% 其上所有行的flat%的累加。可以视为，这一行及其以上行，其所有的directly操作一共占了多少物理时间。 # 理解连线图每个节点的信息包括了包名、函数名、flat、flat%、cum、cum% ![image-20210804150822773.png](http://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/9d29848e0b424454a59eb6fe4f925847~tplv-k3u1fbpfcp-watermark.image?) 节点的颜色越红，其cum和cum%越大。其颜色越灰白，则cum和cum%越小。节点越大，其flat和flat%越大；其越小，则flat和flat%越小线条代表了函数的调用链，线条越粗，代表指向的函数消耗了越多的资源。反之亦然。线条的样式代表了调用关系。实线代表直接调用；虚线代表中间少了几个节点；带有inline字段表示该函数被内联进了调用方（不用在意，可以理解成实线）。 > 对于一些代码行比较少的函数，编译器倾向于将它们在编译期展开从而消除函数调用，这种行为就是内联。 # 理解火焰图火焰图的横向长度表示cum，相比下面超出的一截代表flat。 ![image-20210804174326198.png](http://p6-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/01a278f1122145cb93631d917e9ebd40~tplv-k3u1fbpfcp-watermark.image?) 火焰图可以进行点击 ![image-20210804174723028.png](http://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/b8dccec713174c84b6cb06c93a5b867b~tplv-k3u1fbpfcp-watermark.image?) # 内存分析 ## MemStats ![image-20220516115500163.png](http://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/076b35ee9dcb4131bee63fda104b7aa1~tplv-k3u1fbpfcp-watermark.image?) 有时候，pprof显示的内存占用比操作系统看到的少，其中，内存的 gap 主要来源于： 0. heap 上 Idle span，分配了但是未使用的（往往出现这种情况是一波波的请求峰值导致的，冲上去就一时半会不下来）； 0. 栈的内存占用； 0. OS 分配但是是 reserved 的； 0. runtime 的 Gc 元数据，mcache，mspan 等管理内存； ## Top 使用linux的top命令，其中关于程序使用内存的项介绍： - %MEM：Memory usage (RES) 内存占用使用的物理内存 - VIRT：Virtual Image (kb) 虚拟镜像总虚拟内存的使用数量 - SWAP：Swapped size (kb) 非驻留但是存在于程序中的内存，虚拟内存减去物理内存 - RES：Resident size (kb) 非swap的物理内存 - SHR：Shared Mem size (kb) 程序使用的共享内存，可以被其它进程所共享参考： # 参考资料 [大杀器之性能剖析 PProf](https://golang2.eddycjy.com/posts/ch6/01-pprof-1/) [golang pprof 实战](https://blog.wolfogre.com/posts/go-ppof-practice/#%E6%8E%92%E6%9F%A5%E9%94%81%E7%9A%84%E4%BA%89%E7%94%A8) [深入浅出 Go trace](https://mp.weixin.qq.com/s/I9xSMxy32cALSNQAN8wlnQ) [Go调优神器trace介绍](https://mp.weixin.qq.com/s?__biz=MzA4ODg0NDkzOA==&mid=2247487568&idx=1&sn=d5e747058f75c4d8547c7b0aa33f7c25&source=41#wechat_redirect) [Go高性能系列教程：读懂pprof生成的报告](https://zhuanlan.zhihu.com/p/376191268) 本文正在参加[技术专题18期-聊聊Go语言框架](https://juejin.cn/post/7117898969866305566 "https://juejin.cn/post/7117898969866305566")