golang：快來抓住讓我內(nèi)存泄漏的“真兇”！

導(dǎo)語 | 有句話說得好：“golang10次內(nèi)存泄漏，8次goroutine泄漏，1次真正內(nèi)存泄漏”，那還有一次是什么呢？別急，下面就結(jié)合本次線上遇到的問題來講一講golang的內(nèi)存泄漏和分析解決辦法。

在平常開發(fā)中golang的gc已經(jīng)幫我們解決了很多問題了，甚至逐漸已經(jīng)忘了有g(shù)c這種操作。但是在近期線上的一個trpc-go項(xiàng)目的表現(xiàn)實(shí)在讓人匪夷所思，先讓我們看看該患者的癥狀：

也是那么巧，每天晚上八點(diǎn)左右，服務(wù)的內(nèi)存就開始暴漲，曲線驟降的地方都是手動重啟服務(wù)才降下來的，內(nèi)存只要上去了就不會再降了，有時候內(nèi)存激增直接打爆了內(nèi)存觸發(fā)了OOM，有的同學(xué)可能就會說了“啊，你容器的內(nèi)存是不是不夠啊，開大一點(diǎn)不就好了？”，容器已經(jīng)開到20G內(nèi)存了…我們再用top看看服務(wù)內(nèi)存情況：

讓我忍不住直呼好家伙，服務(wù)進(jìn)程使用的常駐內(nèi)存RES居然有6G+，這明顯沒把我golang的gc放在眼里，該項(xiàng)目也沒用本地緩存之類的，這樣的內(nèi)存占用明顯不合理，沒辦法只好祭出我們golang內(nèi)存分析利器：pprof。

（一）內(nèi)部pprof

相信很多同學(xué)都已經(jīng)用過pprof了，那我們就直入主題，怎么快速地用pprof分析golang的內(nèi)存泄漏。

首先說一下內(nèi)部如何使用pprof，如果123平臺的服務(wù)的話，默認(rèn)是開啟了admin服務(wù)的，我們可以直接在對應(yīng)容器的容器配置里看到ip和admin服務(wù)對應(yīng)的端口。

公司內(nèi)部已經(jīng)搭好了pprof的代理，只需要輸入ip和剛才admin服務(wù)端口就能看到相應(yīng)的內(nèi)存分配和cpu分配圖。

但是上面的可視化界面偶爾會很慢或者失敗，所以我們還是用簡單粗暴的方式，直接用pprof的命令。

（二）pprof heap

有了pprof就很好辦了是吧，瞬間柳暗花明啊，“這個內(nèi)存泄漏我馬上就能fix”，找了一天晚上八點(diǎn)鐘，準(zhǔn)時蹲著內(nèi)存泄漏。我們直接找一臺能ping通容器并且裝了golang的機(jī)器，直接用下面的命令看看當(dāng)前服務(wù)的內(nèi)存分配情況：

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

-inuse_space參數(shù)就是當(dāng)前服務(wù)使用的內(nèi)存情況，還有一個-alloc_space參數(shù)是指服務(wù)啟動以來總共分配的內(nèi)存情況，顯然用前者比較直觀，進(jìn)入交互界面后我們用top命令看下當(dāng)前占用內(nèi)存最高的部分：

“結(jié)果是非常的amazing啊”，當(dāng)時的內(nèi)存分配最大的就是bytes.makeSlice，這個是不存在內(nèi)存泄漏問題的，我們再用命令png生成分配圖看看（需要裝graphviz）：

看起來除了bytes.makeSlice分配內(nèi)存比較大，其他好像也并沒有什么問題，不行，再抓一下當(dāng)前內(nèi)存分配的詳情：

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

這個命令其實(shí)就是把當(dāng)前內(nèi)存分配的詳情文件抓了下來，本地會生成一個叫heap?debug=1的文件，看一看服務(wù)內(nèi)存分配的具體情況：

帶著上面的疑惑又思考了許久，突然又想到了導(dǎo)語的那句話：golang10次內(nèi)存泄漏，8次goroutine泄漏，1次真正內(nèi)存泄漏。

對啊，說不定是goroutine泄漏呢！于是趕在內(nèi)存暴漲結(jié)束之際，又火速敲下以下命令：

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

debug=1就是獲取服務(wù)當(dāng)前goroutine的數(shù)目和大致信息，debug=2獲取服務(wù)當(dāng)前goroutine的詳細(xì)信息，分別在本地生成了goroutine？debug=1和goroutine？debug=2文件，先看前者：

服務(wù)當(dāng)前的goroutine數(shù)也就才1033，也不至于占用那么大的內(nèi)存。再看看服務(wù)線程掛的子線程有多少：

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

好像也不多，只有20多。我們再看看后者，不看不知道，一看嚇一跳:

可以看到goroutine里面有很多chan send這種阻塞了很長時間的case，“這不就找到問題了嗎？就這？嗯？就這？”，趕緊找到對應(yīng)的函數(shù)，發(fā)現(xiàn)之前的同學(xué)寫了類似這樣的代碼：

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處理耗時任務(wù)，最后等待三者完成或者超時失敗返回，因?yàn)檫@里的channel在make的時候沒有設(shè)置緩沖值，所以當(dāng)超時的時候函數(shù)返回，此時ch沒有消費(fèi)者了，就一直阻塞了?？匆豢催@里超時的監(jiān)控項(xiàng)和內(nèi)存泄漏的曲線：

時間上基本是吻合的，“哎喲，問題解決，叉會腰！”，在ch創(chuàng)建的時候設(shè)置一下緩沖，這個阻塞問題就解決了：

ch := make(chan struct{}, 1)

于是一頓操作：打鏡像——喝茶——等鏡像制作——等鏡像制作——等鏡像制作……發(fā)布，"哎，又fix一個bug，工作真飽和！"

發(fā)布之后滿懷期待地敲下top看看RES，什么？怎么RES還是在漲？但是現(xiàn)在已經(jīng)過了內(nèi)存暴漲的時間了，已經(jīng)不好復(fù)現(xiàn)分析了，只好等到明天晚上八點(diǎn)了……

（一）http超時阻塞導(dǎo)致goroutine泄露

第二天又蹲到了晚上八點(diǎn)，果然內(nèi)存又開始暴漲了，重復(fù)了之前的內(nèi)存檢查操作后發(fā)現(xiàn)服務(wù)內(nèi)存分配依然是正常的，但是仿佛又在goroutine上找到了點(diǎn)蛛絲馬跡。

再次把goroutine的詳情抓下來看到，又有不少http阻塞的goroutine：

看了下監(jiān)控項(xiàng)也跟內(nèi)存的曲線可以對得上，仿佛又看到了一絲絲希望……跟一下這里的代碼，發(fā)現(xiàn)http相關(guān)使用也沒什么問題，全局也用的同一個http client，也設(shè)置了相應(yīng)的超時時間，但是定睛一看，什么？這個超時的時間好像有問題：

// 默認(rèn)的httpClientvar DefaultCli *http.Client
func init() {  DefaultCli = &http.Client{    Transport: &http.Transport{      DialContext: (&net.Dialer{        Timeout:   2 * time.Second,        KeepAlive: 30 * time.Second,      }).DialContext,  }}}

這個確實(shí)已經(jīng)設(shè)了一個DialContext里面的Timeout超時時間，跟著看一下源碼：

func init() {  DefaultCli = &http.Client{    Timeout: time.Second * 4,    Transport: &http.Transport{      DialContext: (&net.Dialer{        Timeout:   2 * time.Second,        KeepAlive: 30 * time.Second,      }).DialContext,  }}}

fix之后又是一頓操作：打鏡像——喝茶——等鏡像制作——等鏡像制作——等鏡像制作……發(fā)布，發(fā)布后相應(yīng)阻塞的goroutine確實(shí)也已經(jīng)沒有了。

在組內(nèi)匯報已經(jīng)fix內(nèi)存泄漏的文案都已經(jīng)編輯好了，心想著這回總該解決了吧，用top一看，內(nèi)存曲線還是不健康，尷尬地只能把編輯好的匯報文案刪掉了……

（二）go新版本內(nèi)存管理問題

正苦惱的時候，搜到了一篇文章，主要是描述:Go1.12中使用的新的MADV_FREE模式，這個模式會更有效的釋放無用的內(nèi)存，但可能會讓RSS增高。

但是不應(yīng)該啊，如果有這個問題的話大家很早就提出來了，本著刨根問底的探索精神，我在123上面基于官方的golang編譯和運(yùn)行鏡像重新打了一個讓新的MADV_FREE模式失效的compile和runtime鏡像：

還是一頓操作：打鏡像——喝茶——等鏡像制作——等鏡像制作——等鏡像制作……發(fā)布，結(jié)果還是跟預(yù)期的一樣，內(nèi)存的問題依然沒有解決，到了特定的時候內(nèi)存還是會激增，并且上去后就不會下來了。

經(jīng)歷了那么多還是沒有解決問題，雖然很失落，但是冥冥中已經(jīng)有種接近真相的感覺了……

每晚望著內(nèi)存的告警還是很不舒服，一晚正一籌莫展的時候打開了監(jiān)控項(xiàng)走查了各項(xiàng)指標(biāo)，竟然有大發(fā)現(xiàn)……點(diǎn)開ThreadNum監(jiān)控項(xiàng)，發(fā)現(xiàn)他的曲線可以說跟內(nèi)存曲線完全一致，繼續(xù)對比了幾天的曲線完全都是一樣的！

詢問了007相關(guān)同學(xué)，因?yàn)橛術(shù)olang的runtime進(jìn)行管理，所以一般ThreadNum的數(shù)量一般來說是不會有太大變動或者說不會激增太多，但是這個服務(wù)的ThreadNum明顯就不正常了，真相只有一個：服務(wù)里面有用到cgo。

對于cgo而言，為了不讓goroutine阻塞，cgo都是單獨(dú)開一個線程進(jìn)行處理的，這種是runtime不能管理的。

到這，基本算是找到內(nèi)存源頭了，服務(wù)里面有用到cgo的一個庫進(jìn)行圖片處理，在處理的時候占用了很大的內(nèi)存，由于某種原因阻塞或者沒有釋放線程，導(dǎo)致服務(wù)的線程數(shù)暴漲，最終導(dǎo)致了golang的內(nèi)存泄漏。

再看看服務(wù)線程掛的子線程有多少：

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

此時已經(jīng)有幾百了，之前沒發(fā)現(xiàn)問題的原因是那個時候內(nèi)存沒有暴漲。

根據(jù)數(shù)據(jù)的對比又重新燃起了信心，花了一晚上時間用純go重寫了圖片處理模塊，還是一頓操作后發(fā)布，這次，仿佛嗅到了成功的味道，感覺敲鍵盤都帶火花。

果不其然，修改了發(fā)布后內(nèi)存曲線穩(wěn)定，top數(shù)據(jù)也正常了，不會出現(xiàn)之前內(nèi)存暴漲的情況，總算是柳暗花明了。

這次內(nèi)存泄漏的分析過程好像已經(jīng)把所有內(nèi)存泄漏的情況都經(jīng)歷了一遍：goroutine內(nèi)存泄漏 —— cgo導(dǎo)致的內(nèi)存泄漏。

其實(shí)go的內(nèi)存泄漏都不太常見，因?yàn)閞untime的gc幫我們管理得太好了，常見的內(nèi)存泄漏一般都是一些資源沒有關(guān)閉，比如http請求返回的rsp的body，還有一些打開的文件資源等，這些我們一般都會注意到用defer關(guān)掉。

排除了常見的內(nèi)存泄漏可能，那么極有可能內(nèi)存泄漏就是goroutine泄漏造成的了，可以分析一下代碼里有哪些地方導(dǎo)致了goroutine阻塞導(dǎo)致gooutine泄漏了。

如果以上兩者都分析正常，那基本可以斷定是cgo導(dǎo)致的內(nèi)存泄漏了。遇到內(nèi)存泄漏不要害怕，根據(jù)下面這幾個步驟基本就可以分析出來問題了。

（壹）

先用top看下服務(wù)占用的內(nèi)存有多少（RES），如果很高的話那確實(shí)就是服務(wù)發(fā)生內(nèi)存泄漏了。

（貳）

在內(nèi)存不健康的時候快速抓一下當(dāng)前內(nèi)存分配情況，看看有沒有異常的地方。

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

這個操作會在當(dāng)前目錄下生成一個pprof目錄，進(jìn)去目錄后會生成一個類似這么一個打包的東西：

它保存了當(dāng)時內(nèi)存的分配情況，之后想重新查看可以重新通過以下命令進(jìn)去交互界面進(jìn)行查看：

$ go tool pprof pprof.extern_access_svr.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz

我們分析的時候可以先用命令生成一次，等待一段時間后再用命令生成一次，此時我們就得到了兩個這個打包文件，然后通過以下命令可以對比兩個時間段的內(nèi)存分配情況：

$ go tool pprof -base pprof.extern_access_svr.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz pprof.extern_access_svr.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz

通過上述命令進(jìn)入交互界面后我們可以通過top等命令看到兩個時間內(nèi)存分配的對比情況，如果存在明顯內(nèi)存泄漏問題的話這樣就能一目了然：

進(jìn)一步確認(rèn)內(nèi)存分配的詳情，我們可以通過以下命令抓一下內(nèi)存分配的文件，看看當(dāng)前堆棧的分配情況，如果棧占用的空間過高，有可能就是全局變量不斷增長或者沒有釋放的問題：

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

（叁）

如果上述內(nèi)存分配沒有問題，接下來我們抓一下當(dāng)前goroutine的情況：

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

通過debug=1抓下來的文件可以看到當(dāng)前goroutine的數(shù)量，通過debug=2抓下來的文件可以看到當(dāng)前goroutine的詳情，如果存在大量阻塞的情況，就可以通過調(diào)用棧找到對應(yīng)的問題分析即可。

（肆）

如果通過以上分析內(nèi)存分配和goroutine都正常，就基本可以斷定是cgo導(dǎo)致的了，我們可以看看代碼里面是否有引用到cgo的庫，看看是否有阻塞線程的情況，也可以通過pstack命令分析一下具體是阻塞在哪了。

以上分析過程中可能有不嚴(yán)謹(jǐn)或者錯誤的地方歡迎各位指正，也希望大家看了本篇分析之后在處理內(nèi)存泄漏的問題上能得心應(yīng)手。

golang10次內(nèi)存泄漏，8次goroutine泄漏，1次是真正內(nèi)存泄漏，還有1次是cgo導(dǎo)致的內(nèi)存泄漏。

李卓奕

騰訊后臺開發(fā)工程師

騰訊后臺開發(fā)工程師。目前負(fù)責(zé)手機(jī)瀏覽器后臺相關(guān)開發(fā)工作，有較豐富的直播開發(fā)經(jīng)驗(yàn)，對微服務(wù)框架、go語言性能有較為深入的研究。

一文讀懂@Decorator裝飾器——理解VS Code源碼的基礎(chǔ)（下）

一文讀懂@Decorator裝飾器——理解VS Code源碼的基礎(chǔ)（上）

go語言最全優(yōu)化技巧總結(jié)，值得收藏！

消息隊(duì)列：聽我解釋，我真的不是只有Kafka！