Go调试神器pprof使用教程【实战分享】

浅浅的花香味﹌ 2024-03-23 17:46 60阅读 0赞

## Go调试神器pprof使用教程 ##

> go的GC会自动管理内存，但是这不代表go程序就不会内存泄露了。 go常见产生内存泄露的原因就是goroutine没有结束，简单说就是goroutine 被阻塞了，这样就会导致goroutine引用的内存不被GC回收。

### 1 概念 ###

在Go中，我们可以通过标准库的代码包runtime和runtime/pprof中的程序来生成三种包含实时性数据的概要文件，分别是CPU概要文件、内存概要文件和程序阻塞概要文件。

*  CPU概要文件：默认情况下，Go的运行时系统会以100Hz的频率对CPU的使用情况进行取样
 *  内存概要文件：程序运行过程中堆内存的分配情况
 *  程序阻塞概要文件：用于保护用户程序中的Goroutine阻塞事件的记录
    
     *  Goroutine 活跃Goroutine信息的记录 仅在获取时取样一次
     *  Threadcreate 系统线程创建情况的记录 仅在获取时取样一次
     *  Heap 堆内存分配情况的记录 默认每分配512K字节时取样一次
     *  Block Goroutine阻塞事件的记录 默认每发生一次阻塞事件时取样一次

### 2 使用 ###

前提：代码中引入pprof

package main
    
    import "net/http"
    import _ "net/http/pprof"
    
    func main() {
        
        go func() {
        
           http.ListenAndServe("0.0.0.0:80", nil)
        }()
        select {
        }
    }

#### ①浏览器中查看 ####

1.  浏览器中输入地址localhost/debug/pprof  
    ![在这里插入图片描述][d65c2d169ad54c3c8527e6f63090e428.png]

> profiles下分别是block(阻塞情况)、goroutine数量、heap(堆)、mutex(锁)和threadcreate(创建的物理线程)  
> 点击heap可以看到如下堆内存及GC相关的参数信息

![在这里插入图片描述][fb012653817c467ea3824763d770ef39.png]  
这里是调用Go底层的runtime.MemStats结构体获取，该结构体相关字段解释如下:

Alloc uint64 //golang语言框架堆空间分配的字节数
    TotalAlloc uint64 //从服务开始运行至今分配器为分配的堆空间总 和，只有增加，释放的时候不减少
    Sys uint64 //服务现在系统使用的内存
    Lookups uint64 //被runtime监视的指针数
    Mallocs uint64 //服务malloc heap objects的次数
    Frees uint64 //服务回收的heap objects的次数
    HeapAlloc uint64 //服务分配的堆内存字节数
    HeapSys uint64 //系统分配的作为运行栈的内存
    HeapIdle uint64 //申请但是未分配的堆内存或者回收了的堆内存（空闲）字节数
    HeapInuse uint64 //正在使用的堆内存字节数
    HeapReleased uint64 //返回给OS的堆内存，类似C/C++中的free。
    HeapObjects uint64 //堆内存块申请的量
    StackInuse uint64 //正在使用的栈字节数
    StackSys uint64 //系统分配的作为运行栈的内存
    MSpanInuse uint64 //用于测试用的结构体使用的字节数
    MSpanSys uint64 //系统为测试用的结构体分配的字节数
    MCacheInuse uint64 //mcache结构体申请的字节数(不会被视为垃圾回收)
    MCacheSys uint64 //操作系统申请的堆空间用于mcache的字节数
    BuckHashSys uint64 //用于剖析桶散列表的堆空间
    GCSys uint64 //垃圾回收标记元信息使用的内存
    OtherSys uint64 //golang系统架构占用的额外空间
    NextGC uint64 //垃圾回收器检视的内存大小
    LastGC uint64 // 垃圾回收器最后一次执行时间。
    PauseTotalNs uint64 // 垃圾回收或者其他信息收集导致服务暂停的次数。
    PauseNs [256]uint64 //一个循环队列，记录最近垃圾回收系统中断的时间
    PauseEnd [256]uint64 //一个循环队列，记录最近垃圾回收系统中断的时间开始点。
    NumForcedGC uint32 //服务调用runtime.GC()强制使用垃圾回收的次数。
    GCCPUFraction float64 //垃圾回收占用服务CPU工作的时间总和。如果有100个goroutine，垃圾回收的时间为1S,那么就占用了100S。
    BySize //内存分配器使用情况

> 如果觉得文字展示不够直观，我们也可以通过导入第三方组建来动态展示图表

package main
    
    import (
    	"fmt"
    	_ "github.com/mkevac/debugcharts" // 可选，添加后可以查看几个实时图表数据
    	"net/http"
    	_ "net/http/pprof" // 必须，引入 pprof 模块
    )
    
    func main() {
        
    	go func() {
        
    		// terminal: $ go tool pprof -http=:8081 http://localhost:6060/debug/pprof/heap
    		// web:
    		// 1、http://localhost:8081/ui
    		// 2、http://localhost:6060/debug/charts
    		// 3、http://localhost:6060/debug/pprof
    		fmt.Println(http.ListenAndServe("0.0.0.0:6060", nil))
    	}()
    	fmt.Println("this is a demo about how to use go pprof")
    	select {
        }
    }

> 输入网址：http://localhost:6060/debug/charts/
> 
>  *  查看效果

![在这里插入图片描述][9fe59675706645f299bf12c1e694aad9.png]

#### ②go tool pprof 命令行工具 ####

##### 例：查看内存使用情况 #####

# 在bash控制台执行如下命令，查看内存使用情况
    > go tool pprof  http://localhost:80/debug/pprof/heap

会进入如下gdb交互模式:  
![在这里插入图片描述][a614ac42880f4c05a363a840558af691.png]

> help可以查看使用说明
     
    > top 可以查看前10个的内存分配情况
     
    > tree 以树状显示
     
    > png 以图片格式输出
     
    > svg 生成浏览器可以识别的svg文件

##### 例：查看cpu使用情况 #####

> go tool pprof  http://localhost:80/debug/pprof/profile

该操作默认需要等待30s

> 查看其他信息同上操作。

#### ③实战：排查线上问题（内存暴涨） ####

1.  问题：内存暴涨

> 每天晚上八点左右，服务的内存就开始暴涨，曲线骤降的地方都是手动重启服务才降下来的，内存只要上去了就不会再降了，有时候内存激增直接打爆了内存触发了OOM。

![在这里插入图片描述][a842ff8f693c4c05ba419b3abd1e30ea.png]

1.  有的同学可能就会说了“啊，你容器的内存是不是不够啊，开大一点不就好了？”，容器已经开到20G内存了…我们再用top看看服务内存情况：

![在这里插入图片描述][7f599dd5aca54a2792c225e91ba62cc6.png]

> 让我忍不住直呼好家伙，服务进程使用的常驻内存RES居然有6G+，这明显没把我golang的gc放在眼里，该项目也没用本地缓存之类的，这样的内存占用明显不合理，没办法只好祭出我们golang内存分析利器：pprof。

1.  有了pprof就很好办了是吧，瞬间柳暗花明啊，“这个内存泄漏我马上就能fix”，找了一天晚上八点钟，准时蹲着内存泄漏。我们直接找一台能ping通容器并且装了golang的机器，直接用下面的命令看看当前服务的内存分配情况：

$ go tool pprof -inuse_space http://ip:amdin_port/debug/pprof/heap

> \-inuse\_space参数就是当前服务使用的内存情况  
> 还有一个-alloc\_space参数是指服务启动以来总共分配的内存情况，显然用前者比较直观，进入交互界面后我们用top命令看下当前占用内存最高的部分：

![在这里插入图片描述][c5c6920282194ba7a545772081520d31.png]

> “结果是非常的amazing啊”，当时的内存分配最大的就是bytes.makeSlice，这个是不存在内存泄漏问题的，我们再用命令png生成分配图看看（需要装graphviz）：

![在这里插入图片描述][0e52bb9d9d2b4b96bb36fb8ae53b106a.png]  
4. 看起来除了bytes.makeSlice分配内存比较大，其他好像也并没有什么问题，不行，再抓一下当前内存分配的详情：

$ wget http://ip:admin_port/debug/pprof/heap?debug=1

> 这个命令其实就是把当前内存分配的详情文件抓了下来，本地会生成一个叫heap?debug=1的文件，看一看服务内存分配的具体情况：

![在这里插入图片描述][fea27b163e534c3f8ddde88caeb80c5c.png]  
`有句话说的好啊：golang10次内存泄漏，8次goroutine泄漏，1次真正内存泄漏`，于是我敲下了下面的命令：

$ wget http://ip:admin_port/debug/pprof/goroutine?debug=1
    $ wget http://ip:admin_port/debug/pprof/goroutine?debug=2

*  debug=1就是获取服务当前goroutine的数目和大致信息
 *  debug=2获取服务当前goroutine的详细信息，分别在本地生成了goroutine？debug=1和goroutine？debug=2文件，先看前者：  
    ![在这里插入图片描述][381aa0b35c1d4f45a0472443ac2ee454.png]

> 服务当前的goroutine数也就才1033，也不至于占用那么大的内存。再看看服务线程挂的子线程有多少：

$ ps mp 3030923 -o THREAD,tid | wc -l

好像也不多，只有20多。我们再看看后者，不看不知道，一看吓一跳:  
![在这里插入图片描述][56a700186d664c47b79b0140a8c02419.png]  
可以看到goroutine里面有很多chan send这种阻塞了很长时间的case，“这不就找到问题了吗？就这？嗯？就这？”，赶紧找到对应的函数，发现之前的同学写了类似这样的代码：

func RebuildImage() {
          var wg sync.WaitGroup  wg.Add(3)
      // 耗时1  go func() {    // do sth    defer wg.Done()  } ()
      // 耗时2  go func() {    // do sth    defer wg.Done()  } ()
      // 耗时3  go func() {    // do sth    defer wg.Done()  } ()
      ch := make(chan struct{
        })
      go func () {
            wg.Wait()    ch <- struct{
        }{
        }  }()
      // 接收完成或者超时  select {  case <- ch:    return  case <- time.After(time.Second * 10):    return  }}

> 简单来说这段代码就是开了3个goroutine处理耗时任务，最后等待三者完成或者超时失败返回，因为这里的channel在make的时候没有设置缓冲值，所以当超时的时候函数返回，此时ch没有消费者了，就一直阻塞了。看一看这里超时的监控项和内存泄漏的曲线：

![在这里插入图片描述][fca177761b0046ecb1e1938b91b7d461.png]  
![在这里插入图片描述][3339354af35844bd9ec8ed7209eec869.png]  
时间也能对上，至此问题解决。

参考：  
https://blog.csdn.net/skh2015java/article/details/102748222  
https://cloud.tencent.com/developer/article/2279678

[d65c2d169ad54c3c8527e6f63090e428.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/2f16448a9e1444c1b9fb690c51dbf010.png
[fb012653817c467ea3824763d770ef39.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/c67917c8997a4989900cb51336986f69.png
[9fe59675706645f299bf12c1e694aad9.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/8ad0f19635e44c90be708571093c87a0.png
[a614ac42880f4c05a363a840558af691.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/01861d415f6445c38184dbdb1049b972.png
[a842ff8f693c4c05ba419b3abd1e30ea.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/f32e07d02b034d9792984a94c51f192a.png
[7f599dd5aca54a2792c225e91ba62cc6.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/5f4091e3f2c346a4aa258c415cfed4a9.png
[c5c6920282194ba7a545772081520d31.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/01b6a2395aa14b159b0d3256c80fc5aa.png
[0e52bb9d9d2b4b96bb36fb8ae53b106a.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/2ae4adbd790a4719b8898fe3d9acbb0d.png
[fea27b163e534c3f8ddde88caeb80c5c.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/531506ffe7e14451b39ff47c69532459.png
[381aa0b35c1d4f45a0472443ac2ee454.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/978399b276b14803abedb38797723de3.png
[56a700186d664c47b79b0140a8c02419.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/4de1624a92f74b2b994378b6cfa8f64a.png
[fca177761b0046ecb1e1938b91b7d461.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/36d27216df9f4080893f53c97f14ec7c.png
[3339354af35844bd9ec8ed7209eec869.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/14/ee79a9e898eb40a38984c498a7ecb134.png