一、起——記憶體洩漏表現
在平常開發中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的機器,直接用下面的指令看看目前服務的記憶體配置設定情況:
-inuse_space參數就是目前服務使用的記憶體情況,還有一個-alloc_space參數是指服務啟動以來總共配置設定的記憶體情況,顯然用前者比較直覺,進入互動界面後我們用top指令看下目前占用記憶體最高的部分:
“結果是非常的amazing啊”,當時的記憶體配置設定最大的就是bytes.makeSlice,這個是不存在記憶體洩漏問題的,我們再用指令png生成配置設定圖看看(需要裝graphviz):
看起來除了bytes.makeSlice配置設定記憶體比較大,其他好像也并沒有什麼問題,不行,再抓一下目前記憶體配置設定的詳情:
這個指令其實就是把目前記憶體配置設定的詳情檔案抓了下來,本地會生成一個叫heap?debug=1的檔案,看一看服務記憶體配置設定的具體情況:
三、落——channel導緻goroutine洩漏
帶着上面的疑惑又思考了許久,突然又想到了導語的那句話:golang10次記憶體洩漏,8次goroutine洩漏,1次真正記憶體洩漏。
對啊,說不定是goroutine洩漏呢!于是趕在記憶體暴漲結束之際,又火速敲下以下指令:
debug=1就是擷取服務目前goroutine的數目和大緻資訊,debug=2擷取服務目前goroutine的詳細資訊,分别在本地生成了goroutine?debug=1和goroutine?debug=2檔案,先看前者:
服務目前的goroutine數也就才1033,也不至于占用那麼大的記憶體。再看看服務線程挂的子線程有多少:
好像也不多,隻有20多。我們再看看後者,不看不知道,一看吓一跳:
可以看到goroutine裡面有很多chan send這種阻塞了很長時間的case,“這不就找到問題了嗎?就這?嗯?就這?”,趕緊找到對應的函數,發現之前的同學寫了類似這樣的代碼:
簡單來說這段代碼就是開了3個goroutine處理耗時任務,最後等待三者完成或者逾時失敗傳回,因為這裡的channel在make的時候沒有設定緩沖值,是以當逾時的時候函數傳回,此時ch沒有消費者了,就一直阻塞了。看一看這裡逾時的監控項和記憶體洩漏的曲線:
時間上基本是吻合的,“哎喲,問題解決,叉會腰!”,在ch建立的時候設定一下緩沖,這個阻塞問題就解決了:
于是一頓操作:打鏡像——喝茶——等鏡像制作——等鏡像制作——等鏡像制作……釋出,"哎,又fix一個bug,工作真飽和!"
釋出之後滿懷期待地敲下top看看RES,什麼?怎麼RES還是在漲?但是現在已經過了記憶體暴漲的時間了,已經不好複現分析了,隻好等到明天晚上八點了……
四、再落——深究問題所在
(一)http逾時阻塞導緻goroutine洩露
第二天又蹲到了晚上八點,果然記憶體又開始暴漲了,重複了之前的記憶體檢查操作後發現服務記憶體配置設定依然是正常的,但是仿佛又在goroutine上找到了點蛛絲馬迹。
再次把goroutine的詳情抓下來看到,又有不少http阻塞的goroutine:
看了下監控項也跟記憶體的曲線可以對得上,仿佛又看到了一絲絲希望……跟一下這裡的代碼,發現http相關使用也沒什麼問題,全局也用的同一個http client,也設定了相應的逾時時間,但是定睛一看,什麼?這個逾時的時間好像有問題:
這個确實已經設了一個DialContext裡面的Timeout逾時時間,跟着看一下源碼:
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的記憶體洩漏。
再看看服務線程挂的子線程有多少:
此時已經有幾百了,之前沒發現問題的原因是那個時候記憶體沒有暴漲。
根據資料的對比又重新燃起了信心,花了一晚上時間用純go重寫了圖檔處理子產品,還是一頓操作後釋出,這次,仿佛嗅到了成功的味道,感覺敲鍵盤都帶火花。
果不其然,修改了釋出後記憶體曲線穩定,top資料也正常了,不會出現之前記憶體暴漲的情況,總算是柳暗花明了。
六、合——正常分析手段
這次記憶體洩漏的分析過程好像已經把所有記憶體洩漏的情況都經曆了一遍:goroutine記憶體洩漏 —— cgo導緻的記憶體洩漏。
其實go的記憶體洩漏都不太常見,因為runtime的gc幫我們管理得太好了,常見的記憶體洩漏一般都是一些資源沒有關閉,比如http請求傳回的rsp的body,還有一些打開的檔案資源等,這些我們一般都會注意到用defer關掉。
排除了常見的記憶體洩漏可能,那麼極有可能記憶體洩漏就是goroutine洩漏造成的了,可以分析一下代碼裡有哪些地方導緻了goroutine阻塞導緻gooutine洩漏了。
如果以上兩者都分析正常,那基本可以斷定是cgo導緻的記憶體洩漏了。遇到記憶體洩漏不要害怕,根據下面這幾個步驟基本就可以分析出來問題了。
(壹)
先用top看下服務占用的記憶體有多少(RES),如果很高的話那确實就是服務發生記憶體洩漏了。
(貳)
在記憶體不健康的時候快速抓一下目前記憶體配置設定情況,看看有沒有異常的地方。
這個操作會在目前目錄下生成一個pprof目錄,進去目錄後會生成一個類似這麼一個打包的東西:
它儲存了當時記憶體的配置設定情況,之後想重新檢視可以重新通過以下指令進去互動界面進行檢視:
我們分析的時候可以先用指令生成一次,等待一段時間後再用指令生成一次,此時我們就得到了兩個這個打封包件,然後通過以下指令可以對比兩個時間段的記憶體配置設定情況:
通過上述指令進入互動界面後我們可以通過top等指令看到兩個時間記憶體配置設定的對比情況,如果存在明顯記憶體洩漏問題的話這樣就能一目了然:
進一步确認記憶體配置設定的詳情,我們可以通過以下指令抓一下記憶體配置設定的檔案,看看目前堆棧的配置設定情況,如果棧占用的空間過高,有可能就是全局變量不斷增長或者沒有釋放的問題:
(叁)
如果上述記憶體配置設定沒有問題,接下來我們抓一下目前goroutine的情況:
通過debug=1抓下來的檔案可以看到目前goroutine的數量,通過debug=2抓下來的檔案可以看到目前goroutine的詳情,如果存在大量阻塞的情況,就可以通過調用棧找到對應的問題分析即可。
(肆)
如果通過以上分析記憶體配置設定和goroutine都正常,就基本可以斷定是cgo導緻的了,我們可以看看代碼裡面是否有引用到cgo的庫,看看是否有阻塞線程的情況,也可以通過pstack指令分析一下具體是阻塞在哪了。
七、總結
以上分析過程中可能有不嚴謹或者錯誤的地方歡迎各位指正,也希望大家看了本篇分析之後在處理記憶體洩漏的問題上能得心應手。
golang10次記憶體洩漏,8次goroutine洩漏,1次是真正記憶體洩漏,還有1次是cgo導緻的記憶體洩漏。