golang:快來抓住讓我記憶體洩漏的“真兇”!

導語 | 有句話說得好:“golang10次記憶體洩漏,8次goroutine洩漏,1次真正記憶體洩漏”,那還有一次是什麼呢?別急,下面就結合本次線上遇到的問題來講一講golang的記憶體洩漏和分析解決辦法。

一、起——記憶體洩漏表現

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

golang:快來抓住讓我記憶體洩漏的“真兇”!

golang:快來抓住讓我記憶體洩漏的“真兇”!

golang:快來抓住讓我記憶體洩漏的“真兇”!

也是那麼巧,每天晚上八點左右,服務的記憶體就開始暴漲,曲線驟降的地方都是手動重啟服務才降下來的,記憶體只要上去了就不會再降了,有時候記憶體激增直接打爆了記憶體觸發了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命令看下當前佔用記憶體最高的部分:

golang:快來抓住讓我記憶體洩漏的“真兇”!

“結果是非常的amazing啊”,當時的記憶體分配最大的就是bytes。makeSlice,這個是不存在記憶體洩漏問題的,我們再用命令png生成分配圖看看(需要裝graphviz):

golang:快來抓住讓我記憶體洩漏的“真兇”!

看起來除了bytes。makeSlice分配記憶體比較大,其他好像也並沒有什麼問題,不行,再抓一下當前記憶體分配的詳情:

這個命令其實就是把當前記憶體分配的詳情檔案抓了下來,本地會生成一個叫heap?debug=1的檔案,看一看服務記憶體分配的具體情況:

golang:快來抓住讓我記憶體洩漏的“真兇”!

三、落——channel導致goroutine洩漏

帶著上面的疑惑又思考了許久,突然又想到了導語的那句話:

golang10次記憶體洩漏,8次goroutine洩漏,1次真正記憶體洩漏

對啊,說不定是goroutine洩漏呢!於是趕在記憶體暴漲結束之際,又火速敲下以下命令:

debug=1就是獲取服務當前goroutine的數目和大致資訊,debug=2獲取服務當前goroutine的詳細資訊,分別在本地生成了goroutine?debug=1和goroutine?debug=2檔案,先看前者:

服務當前的goroutine數也就才1033,也不至於佔用那麼大的記憶體。再看看服務執行緒掛的子執行緒有多少:

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

golang:快來抓住讓我記憶體洩漏的“真兇”!

可以看到goroutine裡面有很多chan send這種阻塞了很長時間的case,“這不就找到問題了嗎?就這?嗯?就這?”,趕緊找到對應的函式,發現之前的同學寫了類似這樣的程式碼:

簡單來說這段程式碼就是開了3個goroutine處理耗時任務,最後等待三者完成或者超時失敗返回,因為這裡的channel在make的時候沒有設定緩衝值,所以當超時的時候函式返回,此時ch沒有消費者了,就一直阻塞了。看一看這裡超時的監控項和記憶體洩漏的曲線:

golang:快來抓住讓我記憶體洩漏的“真兇”!

golang:快來抓住讓我記憶體洩漏的“真兇”!

時間上基本是吻合的,“哎喲,問題解決,叉會腰!”,在ch建立的時候設定一下緩衝,這個阻塞問題就解決了:

於是一頓操作:打映象——喝茶——等映象製作——等映象製作——等映象製作……釋出,“哎,又fix一個bug,工作真飽和!”

釋出之後滿懷期待地敲下top看看RES,什麼?怎麼RES還是在漲?但是現在已經過了記憶體暴漲的時間了,已經不好復現分析了,只好等到明天晚上八點了……

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

(一)

http超時阻塞導致goroutine洩露

第二天又蹲到了晚上八點,果然記憶體又開始暴漲了,重複了之前的記憶體檢查操作後發現服務記憶體分配依然是正常的,但是彷彿又在goroutine上找到了點蛛絲馬跡。

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

golang:快來抓住讓我記憶體洩漏的“真兇”!

看了下監控項也跟記憶體的曲線可以對得上,彷彿又看到了一絲絲希望……跟一下這裡的程式碼,發現http相關使用也沒什麼問題,全域性也用的同一個http client,也設定了相應的超時時間,但是定睛一看,什麼?這個超時的時間好像有問題:

這個確實已經設了一個DialContext裡面的Timeout超時時間,跟著看一下原始碼:

fix之後又是一頓操作:打映象——喝茶——等映象製作——等映象製作——等映象製作……釋出,釋出後相應阻塞的goroutine確實也已經沒有了。

在組內彙報已經fix記憶體洩漏的文案都已經編輯好了,心想著這回總該解決了吧,用top一看,記憶體曲線還是不健康,尷尬地只能把編輯好的彙報文案刪掉了……

(二)

go新版本記憶體管理問題

正苦惱的時候,搜到了一篇文章,主要是描述:

Go1.12中使用的新的

MADV_FREE

模式,這個模式會更有效的釋放無用的記憶體,但可能會讓RSS增高

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

還是一頓操作:打映象——喝茶——等映象製作——等映象製作——等映象製作……釋出,結果還是跟預期的一樣,記憶體的問題依然沒有解決,到了特定的時候記憶體還是會激增,並且上去後就不會下來了。

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

五、轉——幕後真兇:“cgo”

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

golang:快來抓住讓我記憶體洩漏的“真兇”!

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

服務裡面有用到cgo

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

到這,基本算是找到記憶體源頭了,服務裡面有用到cgo的一個庫進行圖片處理,在處理的時候佔用了很大的記憶體,由於某種原因阻塞或者沒有釋放執行緒,導致服務的執行緒數暴漲,最終導致了golang的記憶體洩漏。

再看看服務執行緒掛的子執行緒有多少:

此時已經有幾百了,之前沒發現問題的原因是那個時候記憶體沒有暴漲。

根據資料的對比又重新燃起了信心,花了一晚上時間用純go重寫了圖片處理模組,還是一頓操作後釋出,這次,彷彿嗅到了成功的味道,感覺敲鍵盤都帶火花。

果不其然,修改了釋出後記憶體曲線穩定,top資料也正常了,不會出現之前記憶體暴漲的情況,總算是柳暗花明了。

golang:快來抓住讓我記憶體洩漏的“真兇”!

六、合——常規分析手段

這次記憶體洩漏的分析過程好像已經把所有記憶體洩漏的情況都經歷了一遍:goroutine記憶體洩漏 —— cgo導致的記憶體洩漏。

其實go的記憶體洩漏都不太常見,因為runtime的gc幫我們管理得太好了,常見的記憶體洩漏一般都是一些資源沒有關閉,比如http請求返回的rsp的body,還有一些開啟的檔案資源等,這些我們一般都會注意到用defer關掉。

排除了常見的記憶體洩漏可能,那麼極有可能記憶體洩漏就是goroutine洩漏造成的了,可以分析一下程式碼裡有哪些地方導致了goroutine阻塞導致gooutine洩漏了。

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

(壹)

先用top看下服務佔用的記憶體有多少(RES),如果很高的話那確實就是服務發生記憶體洩漏了。

(貳)

在記憶體不健康的時候快速抓一下當前記憶體分配情況,看看有沒有異常的地方。

這個操作會在當前目錄下生成一個pprof目錄,進去目錄後會生成一個類似這麼一個打包的東西:

它儲存了當時記憶體的分配情況,之後想重新檢視可以重新透過以下命令進去互動介面進行檢視:

我們分析的時候可以先用命令生成一次,等待一段時間後再用命令生成一次,此時我們就得到了兩個這個打包檔案,然後透過以下命令可以對比兩個時間段的記憶體分配情況:

透過上述命令進入互動介面後我們可以透過top等命令看到兩個時間記憶體分配的對比情況,如果存在明顯記憶體洩漏問題的話這樣就能一目瞭然:

golang:快來抓住讓我記憶體洩漏的“真兇”!

進一步確認記憶體分配的詳情,我們可以透過以下命令抓一下記憶體分配的檔案,看看當前堆疊的分配情況,如果棧佔用的空間過高,有可能就是全域性變數不斷增長或者沒有釋放的問題:

(叄)

如果上述記憶體分配沒有問題,接下來我們抓一下當前goroutine的情況:

透過debug=1抓下來的檔案可以看到當前goroutine的數量,透過debug=2抓下來的檔案可以看到當前goroutine的詳情,如果存在大量阻塞的情況,就可以透過呼叫棧找到對應的問題分析即可。

(肆)

如果透過以上分析記憶體分配和goroutine都正常,就基本可以斷定是cgo導致的了,我們可以看看程式碼裡面是否有引用到cgo的庫,看看是否有阻塞執行緒的情況,也可以透過pstack命令分析一下具體是阻塞在哪了。

七、總結

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

golang10次記憶體洩漏,8次goroutine洩漏,1次是真正記憶體洩漏,

還有1次是cgo導致的記憶體洩漏

作者簡介

李卓奕

騰訊後臺開發工程師

騰訊後臺開發工程師。目前負責手機瀏覽器後臺相關開發工作,有較豐富的直播開發經驗,對微服務框架、go語言效能有較為深入的研究。

TAG: 記憶體洩漏goroutine映象服務