下载的文件为:/home//pprof/pprof.demo.....001.pb.gz,里面包含了程序名demo,类型alloc分配的内存,inuse代表正在使用的内存。help可以获得帮助,支持的命令会先列出来。想要掌握pprof,需要多看多尝试。
关于命令,本文只会用到我认为最常用的3个:top、list、。我会一一介绍。
顶部
按指标大小列出前 10 个函数,例如按内存使用量列出内存,按执行时间列出 CPU。
(pprof) top Showing nodes accounting for 814.62MB, 100% of 814.62MB total flat flat% sum% cum cum% 814.62MB 100% 100% 814.62MB 100% main.main 0 0% 100% 814.62MB 100% runtime.main
Top 将列出 5 个统计数据:
列表
查看某个函数的代码,以及函数内每一行代码的指标信息,如果函数名不清楚,会进行模糊匹配,例如list main会列出main.main和.main。
(pprof) list main.main // 精确列出函数 Total: 814.62MB ROUTINE ======================== main.main in /home/ubuntu/heap/demo2.go 814.62MB 814.62MB (flat, cum) 100% of Total . . 20: }() . . 21: . . 22: tick := time.Tick(time.Second / 100) . . 23: var buf []byte . . 24: for range tick { 814.62MB 814.62MB 25: buf = append(buf, make([]byte, 1024*1024)...) . . 26: } . . 27:} . . 28: (pprof) list main // 匹配所有函数名带main的函数 Total: 814.62MB ROUTINE ======================== main.main in /home/ubuntu/heap/demo2.go 814.62MB 814.62MB (flat, cum) 100% of Total . . 20: }() . . 21: ..... // 省略几行 . . 28: ROUTINE ======================== runtime.main in /usr/lib/go-1.10/src/runtime/proc.go 0 814.62MB (flat, cum) 100% of Total . . 193: // A program compiled with -buildmode=c-archive or c-shared ..... // 省略几行
我们可以看到main.main中第25行占用了814.62MB内存,左右两个数据分别是flat和cum,含义和上面解释的一样。
打印所有调用堆栈及其指标。
(pprof) traces File: demo2 Type: inuse_space Time: May 16, 2019 at 7:08pm (CST) -----------+------------------------------------------------------- bytes: 813.46MB 813.46MB main.main runtime.main -----------+------------------------------------------------------- bytes: 650.77MB 0 main.main runtime.main ....... // 省略几十行
每一个- - - - -之间都有一个调用栈进行分隔,我们可以看到.main调用了main.main,而main.main占用了813.46MB的内存。
其余操作与内存类似,这里不再赘述。
这里只是简单介绍了一下本文用到的 pprof 的功能,pprof 很强大,而且经常和 结合使用,但这不是本文的重点,就不详细介绍了,推荐几篇文章给大家仔细看完并练习一下:
Go 官方博客对 pprof 有非常详细的介绍,也包含实际使用的示例:Go。我也和建宇讨论过 pprof,建宇的这篇文章也很适合入门:杀手级性能分析工具 PProf。
什么是内存泄漏?
内存泄漏是指程序执行过程中,不再使用的内存没有得到释放,导致该内存直到程序结束为止都无法使用的问题。
虽然Go有GC来回收未使用的堆内存,减轻了开发者的内存管理负担,但这并不意味着Go程序不会再出现内存泄漏。在Go程序中,如果不用Go语言编程的思维方式,不遵循良好的编程习惯,就有可能埋下隐患,发生内存泄漏。
如何检测内存泄漏
Go中查找内存泄漏的方法有两种,一种是通用监控工具,一种是go pprof:
监控工具:以固定周期对进程的内存使用情况进行采样,将数据可视化后,根据内存使用趋势(持续增加)可以很容易判断是否发生内存泄漏。 go pprof:适用于没有监控工具的情况,使用Go提供的pprof工具可以判断是否发生内存泄漏。
下面分别介绍这两种方法。
监控工具来查看进程内部使用情况
如果使用云平台部署 Go 程序,云平台提供了内存查看工具,可以查看 OS 的内存使用情况,以及某个进程的内存使用情况。例如在阿里云,我们只在一台云主机上部署了一个 Go 服务,所以 OS 的内存使用情况基本就体现了进程的内存使用情况。OS 内存使用情况如下,可以看到随着时间的推移,内存使用率在不断的增加,这是内存泄漏最明显的现象:
如果没有云平台之类的内存监控工具,可以制作一个简单的内存记录工具。
1、创建一个.sh,用于获取进程占用的物理内存,脚本内容如下:
复制
#!/bin/bash prog_name="your_programe_name" prog_mem=$(pidstat -r -u -h -C $prog_name |awk 'NR==4{print $12}') time=$(date "+%Y-%m-%d %H:%M:%S") echo $time"\tmemory(Byte)\t"$prog_mem >>~/record/prog_mem.log
2.然后使用命令创建计划任务,每分钟记录一次,使用-e编辑配置,在最后添加一行:
*/1 * * * * ~/record/prog_mem.sh
脚本输出结果保存在.log中,一眼就能看出内存增长情况,判断是否存在内存泄漏。如果需要可视化,可以直接将.log内容粘贴到Excel或其他表格工具中,绘制内存使用情况图表。
Go pprof 发现内存问题
温馨提示:如果对 pprof 不理解,可以先看下一篇 go pprof 的基础知识,看完再回过头来再看。
如果你在百度上搜索关于 Go 程序内存泄漏的文章,总会被告知使用 pprof heap 可以生成漂亮的调用路径图、火焰图等,然后根据调用路径就可以定位内存泄漏。我一开始也是信服这个,但是尝试了几天之后发现内存泄漏和某个场景有关,根本找不到内存泄漏的根源。如果有朋友会使用 heap 定位线上内存泄漏,请告诉我一下。
后来看了Dave的《High Go》,刷新了我对heap的认识, pprof简要内容如下:
Dave 提出了以下几点:
记录的是堆内存分配和调用栈信息,而不是进程完整的内存情况。我猜这也是为什么叫 heap 而不是 go pprof 的原因。栈内存分配是调用栈结束后会释放的内存,所以不在内存里。 是基于采样的,默认是每 1000 次堆内存分配记录一次。因为 是基于采样的,而且它跟踪的是分配的内存,而不是正在使用的内存(比如有些内存分配了,看上去是在使用,但实际上并没有使用,比如内存泄漏的那一部分),所以 不能用来衡量程序整体的内存使用情况。Dave 个人观点:使用 是检测不到内存泄漏的。
根据我目前对堆的理解,我有两种看法:
堆可以帮助我们发现内存问题,但不一定能发现内存泄漏。这个观点和Dave的类似,堆记录了内存的分配情况,我们可以通过堆来观察内存的变化、增长、减少情况,哪些代码主要占用了内存,程序中是否存在内存问题。这只能说明内存使用不合理,但并不代表这就是内存泄漏。堆对于帮助定位内存泄漏原因的贡献非常小。就像第一点提到的,通过堆可以找到占用内存较多的位置,但这个位置通常不一定就是内存泄漏,即使是内存泄漏,也只是内存泄漏的结果,而不是内存泄漏的真正原因。
接下来我会向大家展示如何使用堆来查找问题,然后解释为什么堆几乎无法定位内存泄漏的根本原因。
如何使用堆查找内存问题
使用pprof的heap在程序运行时获取内存信息。在程序运行平稳时,每隔一段时间使用heap获取内存,然后使用base对比两个文件的区别,就像diff命令一样展示增加和减少的变化。用一个简单的demo来说明heap和base的使用,依然使用demo2进行展示。
文件:/pprof/heap/demo2.go
// 展示内存增长和pprof,并不是泄露 package main import ( "fmt" "net/http" _ "net/http/pprof" "os" "time" ) // 运行一段时间:fatal error: runtime: out of memory func main() { // 开启pprof go func() { ip := "0.0.0.0:6060" if err := http.ListenAndServe(ip, nil); err != nil { fmt.Printf("start pprof failed on %s\n", ip) os.Exit(1) } }() tick := time.Tick(time.Second / 100) var buf []byte for range tick { buf = append(buf, make([]byte, 1024*1024)...) } }
运行上述代码,执行以下命令,获取文件,按Ctrl-D退出,1分钟后再次获取。
go tool pprof http://localhost:6060/debug/pprof/heap
我获得了两个文件:
$ ls pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz
使用base以文件001为基准,然后将文件002与文件001进行比较,先执行top查看top的比较情况,再执行list main列出main函数的内存比较情况,结果如下:
$ go tool pprof -base pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz File: demo2 Type: inuse_space Time: May 14, 2019 at 2:33pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (pprof) (pprof) top Showing nodes accounting for 970.34MB, 32.30% of 3003.99MB total flat flat% sum% cum cum% 970.34MB 32.30% 32.30% 970.34MB 32.30% main.main // 看这 0 0% 32.30% 970.34MB 32.30% runtime.main (pprof) (pprof) (pprof) list main.main Total: 2.93GB ROUTINE ======================== main.main in /home/ubuntu/heap/demo2.go 970.34MB 970.34MB (flat, cum) 32.30% of Total . . 20: }() . . 21: . . 22: tick := time.Tick(time.Second / 100) . . 23: var buf []byte . . 24: for range tick { 970.34MB 970.34MB 25: buf = append(buf, make([]byte, 1024*1024)...) // 看这 . . 26: } . . 27:} . . 28:
top列出了main.main和.main,main.main是我们编写的main函数,.main是包中的main函数,是所有main函数的入口,这里就不多介绍了,有兴趣的可以看之前的文章《Go 系列(二)的宏观看》。
Top 显示 main.main 第二次内存使用量比第一次内存使用量多了 970.34MB。
list main.main 告诉我们增加的内存在这行:
buf = append(buf, make([]byte, 1024*1024)...)
001和002这两个文件你不用去看,你在本地测试一下,算一下差值,肯定就是你刚才对比的那个970.34MB。
堆“无法”定位内存泄漏
Heap 可以展示内存分配情况,哪一行代码占用了多少内存,我们可以很轻松的找到占用内存最多的地方,如果这个地方的值还在增加,那么基本可以确定这里就是内存泄露的位置。
我曾经以为顺着线索,按照调用堆栈往上搜索就能找到内存泄漏的原因,这个解决办法看似不错,但是我实现的时候却怎么也找不到内存泄漏的原因,真是事倍功半。
原因是 Go 程序中协程数量比较多,它们之间的调用关系可能比较复杂,可能内存泄漏在第三方包中,比如下图中,每个椭圆代表 1,数字为编号,箭头代表调用关系,堆显示协程 g111(最下方红色节点)的代码存在泄漏,从 g101 到 g111 的任何调用路径都有可能导致 g111 发生内存泄漏,有两种可能:
这个函数只被调用了很少的几次,但是却消耗了大量的内存,也就是说每次调用都会消耗大量的内存。造成内存泄漏的原因基本就在这个协程内部,这个函数被调用的次数很多,虽然每次协程调用消耗的内存很少,但是在这个调用路径上存在大量的协程,消耗了大量的内存。而且这些协程因为某些原因无法退出,占用的内存也不会得到释放。造成内存泄漏的原因是到g111的调用路径上某一段代码的实现有问题,从而产生了大量g111。
第二种情况就是泄漏,通过堆是无法发现的,所以堆对于定位内存泄漏的作用不大。
泄漏如何导致内存泄漏
什么是泄漏?
如果您启动了一个进程,但是它直到程序结束才按预期退出,那么它就发生了泄漏。
提前思考:什么原因会导致无法退出/阻塞?
泄漏如何导致内存泄漏
每个占用 2KB 内存。100 万个泄漏将至少泄漏 2KB * = 2GB 内存。为什么至少?
执行过程中还存在一些变量,如果这些变量指向的是堆内存中的内存,那么GC就会认为这块内存还在使用中,不会去回收,没有人能够使用这块内存,从而造成内存泄漏。
所以造成内存泄漏有两种方式:
栈本身占用的空间会造成内存泄漏,堆中的变量占用的堆内存会造成堆内存泄漏,通过堆可以体现出来。
Dave 在文章中还提到,如果你不知道何时停止一个线程,这是一个潜在的内存泄漏:
7.1.1 知道何时停止你不知道的,这是一个泄漏,因为它会将其堆栈固定在堆上,以及堆栈中的任何堆。
如何判断内存泄漏是否由泄漏引起
掌握了 pprof 命令行的基本使用方法后,可以快速确认是否有内存泄漏。如果不记得了,可以回去复习一下 go pprof 的基础。
判断依据:节点在正常运行的情况下,如果经过一段时间后获取的数据个数较之前有所增大,且多次获取之后还继续增长,那么就很有可能是发生了漏网之鱼。
造成内存泄漏的Demo:
文件:/pprof//.go
// goroutine泄露导致内存泄露 package main import ( "fmt" "net/http" _ "net/http/pprof" "os" "time" ) func main() { // 开启pprof go func() { ip := "0.0.0.0:6060" if err := http.ListenAndServe(ip, nil); err != nil { fmt.Printf("start pprof failed on %s\n", ip) os.Exit(1) } }() outCh := make(chan int) // 死代码,永不读取 go func() { if false { <-outCh } select {} }() // 每s起100个goroutine,goroutine会阻塞,不释放内存 tick := time.Tick(time.Second / 100) i := 0 for range tick { i++ fmt.Println(i) alloc1(outCh) } } func alloc1(outCh chan<- int) { go alloc2(outCh) } func alloc2(outCh chan<- int) { func() { defer fmt.Println("alloc-fm exit") // 分配内存,假用一下 buf := make([]byte, 1024*1024*10) _ = len(buf) fmt.Println("alloc done") outCh <- 0 // 53行 }() }
编译运行上述代码,然后使用go tool pprof获取该文件。
go tool pprof http://localhost:6060/debug/pprof/goroutine
通过pprof命令获得了两个文件:
$ ls /home/ubuntu/pprof/pprof.leak_demo.goroutine.001.pb.gz /home/ubuntu/pprof/pprof.leak_demo.goroutine.002.pb.gz
与堆类似,我们可以使用base来比较两个文件:
$go tool pprof -base pprof.leak_demo.goroutine.001.pb.gz pprof.leak_demo.goroutine.002.pb.gz File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (pprof) top Showing nodes accounting for 20312, 100% of 20312 total flat flat% sum% cum cum% 20312 100% 100% 20312 100% runtime.gopark 0 0% 100% 20312 100% main.alloc2 0 0% 100% 20312 100% main.alloc2.func1 0 0% 100% 20312 100% runtime.chansend 0 0% 100% 20312 100% runtime.chansend1 0 0% 100% 20312 100% runtime.goparkunlock (pprof)
可以看到运行到的次数增加了20312次,那么通过002文件看一下执行的次数,也就是挂掉的次数:
go tool pprof pprof.leak_demo.goroutine.002.pb.gz File: leak_demo Type: goroutine Time: May 16, 2019 at 2:47pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) top Showing nodes accounting for 24330, 100% of 24331 total Dropped 32 nodes (cum <= 121) flat flat% sum% cum cum% 24330 100% 100% 24330 100% runtime.gopark 0 0% 100% 24326 100% main.alloc2 0 0% 100% 24326 100% main.alloc2.func1 0 0% 100% 24326 100% runtime.chansend 0 0% 100% 24326 100% runtime.chansend1 0 0% 100% 24327 100% runtime.goparkunlock
显示有24330个被暂停。如果这不是泄漏,那是什么?已经确认其中80%到90%是泄漏的。
是什么原因导致这么多的挂起和无法退出呢?接下来我们看看如何定位泄漏。
查找泄漏的两种方法
pprof的使用方式有两种,一种是web页面,一种是go tool pprof 命令行交互。两种方式都支持,但是稍有不同,各有优缺点。
我们先来看一下Web方式,再来看看命令行交互方式,两种方式都比较好用,而且可以配合使用。
Web 可视化视图
Web方式适用于Web服务器端口可以访问的情况,使用简单,有两种方法:
查看当前在某个呼叫路径上被阻止的人数。查看所有正在运行的堆栈(呼叫路径)以显示它们被阻止的时间。
方法 1
在URL请求中设置debug=1:
复制
http://ip:port/debug/pprof/goroutine?debug=1
效果如下:
看上去密密麻麻,其实很简单也很实用。带图标的部分在手机上可能不方便看,可以放大看,或者直接看下面字段的含义:
:total 32023:32023是总数,32015@…:32015表示有32015个正在运行这个调用栈,并且停在了同一个位置。@后面的16进制现在用不到了,就先不多说了。下面是当前的调用栈,列出了函数以及它们所在文件的行号,这个行号对定位很有帮助,如下:
32015 @ 0x42e15a 0x42e20e 0x40534b 0x4050e5 0x6d8559 0x6d831b 0x45abe1 # 0x6d8558 main.alloc2.func1+0xf8 /home/ubuntu/heap/leak_demo.go:53 # 0x6d831a main.alloc2+0x2a /home/ubuntu/heap/leak_demo.go:54
根据以上提示,我们可以确定32015次运行都在.go的第53行:
func alloc2(outCh chan<- int) { func() { defer fmt.Println("alloc-fm exit") // 分配内存,假用一下 buf := make([]byte, 1024*1024*10) _ = len(buf) fmt.Println("alloc done") outCh <- 0 // 53行 }() }
阻塞的原因是outCh的写操作无法完成,outCh是一个无缓冲的通道,而由于下面的代码是死代码,没有从outCh读出任何数据,导致outCh被阻塞,进而引发无数的阻塞,形成内存泄漏:
if false { <-outCh }
方法 2
在URL请求中设置debug=2:
http://ip:port/debug/pprof/goroutine?debug=2
第二种方法与第一种方法是互补的,可以看到各自的信息:
20 [chan send, 2 ]:20 是 id,[] 是当前状态,阻塞在写入中,阻塞时间为 2 分钟。在长时间运行的系统中,可以看到阻塞时间更长。同时,还可以看到调用堆栈,查看当前执行停止在何处:.go 第 53 行,
goroutine 20 [chan send, 2 minutes]: main.alloc2.func1(0xc42015e060) /home/ubuntu/heap/leak_demo.go:53 +0xf9 // 这 main.alloc2(0xc42015e060) /home/ubuntu/heap/leak_demo.go:54 +0x2b created by main.alloc1 /home/ubuntu/heap/leak_demo.go:42 +0x3f
命令行交互方式
Web方式简单粗暴,不需要登录服务器,打开浏览器看看就行。但是前面也说了,在没有浏览器访问的时候,命令行交互是最好的方式,也容易做到,感觉跟Web一样方便。
命令行交互方式只有一种获取文件的方式,不像网页有debug=1和debug=22,并且将文件保存在本地:
// 注意命令没有`debug=1`,debug=1,加debug有些版本的go不支持 $ go tool pprof http://0.0.0.0:6060/debug/pprof/goroutine Fetching profile over HTTP from http://localhost:6061/debug/pprof/goroutine Saved profile in /home/ubuntu/pprof/pprof.leak_demo.goroutine.001.pb.gz // profile文件保存位置 File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof)
命令行只需要掌握三个命令就行,上面已经介绍过了,具体可以回头看看top、list、还有:
top:显示正在运行的函数数量;list:显示所有的调用堆栈;并列出代码的详细信息。
我们仍然使用.go演示。
$ go tool pprof -base pprof.leak_demo.goroutine.001.pb.gz pprof.leak_demo.goroutine.002.pb.gz File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) (pprof) (pprof) top Showing nodes accounting for 20312, 100% of 20312 total flat flat% sum% cum cum% 20312 100% 100% 20312 100% runtime.gopark 0 0% 100% 20312 100% main.alloc2 0 0% 100% 20312 100% main.alloc2.func1 0 0% 100% 20312 100% runtime.chansend 0 0% 100% 20312 100% runtime.chansend1 0 0% 100% 20312 100% runtime.goparkunlock (pprof) (pprof) traces File: leak_demo Type: goroutine Time: May 16, 2019 at 2:44pm (CST) -----------+------------------------------------------------------- 20312 runtime.gopark runtime.goparkunlock runtime.chansend runtime.chansend1 // channel发送 main.alloc2.func1 // alloc2中的匿名函数 main.alloc2 -----------+-------------------------------------------------------
在如何判断是否是内存泄漏导致的,top命令已经介绍过了。直接看命令,可以列出002中比001中多的调用栈。这里只有一个调用栈,其中有20312个执行了这个调用路径。可以看到中的匿名函数.func1调用了write操作然后阻塞挂起了。使用list列出.func1的代码,可以看到有20312个都阻塞在第53行:
(pprof) list main.alloc2.func1 Total: 20312 ROUTINE ======================== main.alloc2.func1 in /home/ubuntu/heap/leak_demo.go 0 20312 (flat, cum) 100% of Total . . 48: // 分配内存,假用一下 . . 49: buf := make([]byte, 1024*1024*10) . . 50: _ = len(buf) . . 51: fmt.Println("alloc done") . . 52: . 20312 53: outCh <- 0 // 看这 . . 54: }() . . 55:} . . 56:
友情提醒:使用list命令的前提是程序的源代码在当前机器上,否则无法列出源代码。服务器上一般是没有源代码的,那怎么办呢?刚才介绍了在网页上查看的方式,网页上会列出代码行数。我们可以使用wget下载网页:
$ wget http://localhost:6060/debug/pprof/goroutine?debug=1
下载网页后,用编辑器打开文件,用关键字main..func1搜索,找到和当前相同的调用栈,就可以看到阻塞在哪一行了。别忘了用debug=2看看阻塞了多长时间,以及原因。这个在Web方法中已经介绍过了,这里就省略几十行代码了。
总结
文章有点长,但是干货满满,感谢阅读,看完之后一定想掌握 pprof,建议大家练习一下,现在我们来回顾一下本文的主要内容。
泄漏的性质
泄漏的本质是阻塞,导致无法继续向下执行,从而导致相关内存无法释放,进一步造成内存泄漏。
泄漏检测和定位
利用go pprof获取文件,然后使用top、list三个命令定位内存泄漏的原因。
泄露的场景
泄漏场景不仅限于以下两类,但相关泄漏是最常见的。
读或写:无缓冲阻塞一般是由于没有读操作,导致写操作被阻塞。有缓冲阻塞是由于缓冲区已满,写操作被阻塞,等待读取数据,结果没有写操作。这里也有操作。如果所有情况下的操作都被阻塞,执行就无法继续。
编码泄漏建议
为了避免泄漏导致的内存泄漏,在开始之前请仔细考虑:
如何退出?会不会有阻碍退出的障碍?如果有,这条路径会不会产生大量的障碍?示例源代码
本文所有示例源代码、历史文章及代码均保存在 中,您可以直接跳转至原文: 。
扫一扫在手机端查看
我们凭借多年的网站建设经验,坚持以“帮助中小企业实现网络营销化”为宗旨,累计为4000多家客户提供品质建站服务,得到了客户的一致好评。如果您有网站建设、网站改版、域名注册、主机空间、手机网站建设、网站备案等方面的需求,请立即点击咨询我们或拨打咨询热线: 13761152229,我们会详细为你一一解答你心中的疑难。