內存泄漏，8次goroutine泄漏，1次真正內存泄漏

golang：快來抓住讓我內存泄漏的“真凶”！ https://mp.weixin.qq.com/s/FyHEiaa-UfyLStMKl2VFGA

原創 李卓奕 雲加社區 2021-08-30

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

 

 

一、起——內存泄漏表現

 

在平常開發中golang的gc已經幫我們解決了很多問題了，甚至逐漸已經忘了有gc這種操作。但是在近期線上的一個trpc-go項目的表現實在讓人匪夷所思，先讓我們看看該患者的症狀：

 

 

 

 

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

 

 

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

 

 

二、承——用pprof分析

 

（一）內部pprof

 

相信很多同學都已經用過pprof了，那我們就直入主題，怎么快速地用pprof分析golang的內存泄漏。

 

首先說一下內部如何使用pprof，如果123平台的服務的話，默認是開啟了admin服務的，我們可以直接在對應容器的容器配置里看到ip和admin服務對應的端口。

 

 

公司內部已經搭好了pprof的代理，只需要輸入ip和剛才admin服務端口就能看到相應的內存分配和cpu分配圖。

 

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

 

 

（二）pprof heap

 

有了pprof就很好辦了是吧，瞬間柳暗花明啊，“這個內存泄漏我馬上就能fix”，找了一天晚上八點鍾，准時蹲着內存泄漏。我們直接找一台能ping通容器並且裝了golang的機器，直接用下面的命令看看當前服務的內存分配情況：

 

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

 

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

 

 

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

 

 

看起來除了bytes.makeSlice分配內存比較大，其他好像也並沒有什么問題，不行，再抓一下當前內存分配的詳情：

 

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

 

這個命令其實就是把當前內存分配的詳情文件抓了下來，本地會生成一個叫heap?debug=1的文件，看一看服務內存分配的具體情況：

 

 

 

三、落——channel導致goroutine泄漏

 

帶着上面的疑惑又思考了許久，突然又想到了導語的那句話：golang10次內存泄漏，8次goroutine泄漏，1次真正內存泄漏。

 

對啊，說不定是goroutine泄漏呢！於是趕在內存暴漲結束之際，又火速敲下以下命令：

 

$ 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文件，先看前者：

 

 

服務當前的goroutine數也就才1033，也不至於占用那么大的內存。再看看服務線程掛的子線程有多少：

 

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

 

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

 

 

可以看到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沒有消費者了，就一直阻塞了。看一看這里超時的監控項和內存泄漏的曲線：

 

 

 

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

 

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

 

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

 

發布之后滿懷期待地敲下top看看RES，什么？怎么RES還是在漲？但是現在已經過了內存暴漲的時間了，已經不好復現分析了，只好等到明天晚上八點了……

 

 

四、再落——深究問題所在

 

（一）http超時阻塞導致goroutine泄露

 

第二天又蹲到了晚上八點，果然內存又開始暴漲了，重復了之前的內存檢查操作后發現服務內存分配依然是正常的，但是仿佛又在goroutine上找到了點蛛絲馬跡。

 

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

 

 

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

 

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

 

這個確實已經設了一個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之后又是一頓操作：打鏡像——喝茶——等鏡像制作——等鏡像制作——等鏡像制作……發布，發布后相應阻塞的goroutine確實也已經沒有了。

 

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

 

 

（二）go新版本內存管理問題

 

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

 

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

 

 

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

 

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

 

 

五、轉——幕后真凶：“cgo”

 

每晚望着內存的告警還是很不舒服，一晚正一籌莫展的時候打開了監控項走查了各項指標，竟然有大發現……點開ThreadNum監控項，發現他的曲線可以說跟內存曲線完全一致，繼續對比了幾天的曲線完全都是一樣的！

 

 

詢問了007相關同學，因為有golang的runtime進行管理，所以一般ThreadNum的數量一般來說是不會有太大變動或者說不會激增太多，但是這個服務的ThreadNum明顯就不正常了，真相只有一個：服務里面有用到cgo。

 

對於cgo而言，為了不讓goroutine阻塞，cgo都是單獨開一個線程進行處理的，這種是runtime不能管理的。

 

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

 

再看看服務線程掛的子線程有多少：

 

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

 

此時已經有幾百了，之前沒發現問題的原因是那個時候內存沒有暴漲。

 

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

 

果不其然，修改了發布后內存曲線穩定，top數據也正常了，不會出現之前內存暴漲的情況，總算是柳暗花明了。

 

 

 

 

六、合——常規分析手段

 

這次內存泄漏的分析過程好像已經把所有內存泄漏的情況都經歷了一遍：goroutine內存泄漏 —— cgo導致的內存泄漏。

 

其實go的內存泄漏都不太常見，因為runtime的gc幫我們管理得太好了，常見的內存泄漏一般都是一些資源沒有關閉，比如http請求返回的rsp的body，還有一些打開的文件資源等，這些我們一般都會注意到用defer關掉。

 

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

 

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

 

（壹）

 

先用top看下服務占用的內存有多少（RES），如果很高的話那確實就是服務發生內存泄漏了。

 

（貳）

 

在內存不健康的時候快速抓一下當前內存分配情況，看看有沒有異常的地方。

 

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

 

這個操作會在當前目錄下生成一個pprof目錄，進去目錄后會生成一個類似這么一個打包的東西：

 

 

它保存了當時內存的分配情況，之后想重新查看可以重新通過以下命令進去交互界面進行查看：

 

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

 

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

 

$ 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

 

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

 

 

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

 

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

 

（叄）

 

如果上述內存分配沒有問題，接下來我們抓一下當前goroutine的情況：

 

$ 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都正常，就基本可以斷定是cgo導致的了，我們可以看看代碼里面是否有引用到cgo的庫，看看是否有阻塞線程的情況，也可以通過pstack命令分析一下具體是阻塞在哪了。

 

 

七、總結

 

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

 

golang10次內存泄漏，8次goroutine泄漏，1次是真正內存泄漏，還有1次是cgo導致的內存泄漏。