記一次內存泄漏的解決
內存泄漏
內存泄漏(Memory Leak)是指程序中已動態(tài)分配的堆內存由于某種原因程序未釋放或無法釋放,造成系統(tǒng)內存的浪費,導致程序運行速度減慢甚至內存溢出,系統(tǒng)崩潰等嚴重后果。
????在Go語言服務中,內存泄漏的大多數原因是goroutine泄露。
問題發(fā)現
????在巡檢過程中忽然發(fā)現某個服務模塊服務的內存瘋漲,剛剛部署時候很小,過了兩個月左右達到了驚人的200倍左右,繼續(xù)增長下去的結果就是內存溢出導致該服務的pod重啟(該服務使用k8s的deploy部署)。需要排查一下泄露問題出在哪里,于是在本地自己模擬了一套邏輯相似的環(huán)境(自測用的,模擬了一個簡單場景)。
pprof工具
????pprof?是一個強大的性能分析工具,可以捕捉到多維度的運行狀態(tài)的數據,便于排查程序的堆棧信息,goroutine分布等。
排查過程
1、程序中添加pprof工具
????
????首先在程序添加監(jiān)聽端口,如下:

????然后導入pprof包:

2、啟動程序
????訪問本地端口6060(主要關注goroutine數量)
????
3、使用goTest發(fā)起請求?
????這里模擬了20個并發(fā)量,一次請求。

4、使用pprof查看樣本數據
????
可以看到在請求結束之后,goroutine數量依然存在,并沒有被回收。

????
猜測原因:大量goroutine滯留導致棧空間沒有被釋放(影響較小),goroutine沒有被釋放,goroutine指向的heap一系列對象沒有被回收掉,heap越用越多,持續(xù)申請內存造成內存持續(xù)異常增長,也就是內存泄漏。
點擊goroutine查看詳細信息:

可以看到有四種類型的goroutine棧居高不下,grpc的出現率很高,猜測是在發(fā)起請求時創(chuàng)建的grpc連接沒有釋放掉。
??
gRpc的源碼不必追溯,也沒有完整的調用棧信息,作為一個rpc庫,已經封裝了關閉請求流的方法。應該關注引用的它庫的位置,看看是否在應用層有暴露出來的關閉流的方法。

選擇從該處向上追溯,首先定位到該處的源碼:

每次的請求在該處都會阻塞住,是否需要在該處上游有一個釋放信號,將該context構造的goroutine樹釋放掉。
?
一路向上追溯源碼(不詳述),看到一個在應用層結構體實現了close方法,點到close方法,可以看到該方法可以釋放連接與緩存。于是在應用層找到合適的位置調用了close方法。

???
?再次發(fā)起模擬請求,查看pprof工具:

??
可以看到協(xié)程數量恢復如初,業(yè)務正常沒受影響,初步猜測是該處的原因。接下來各種業(yè)務驗證不詳述...
5、并發(fā)測試進程memory
????
繼續(xù)單元測試。
????
創(chuàng)建20個協(xié)程,每個協(xié)程100個請求,中間休眠一秒(為了防止速度太快腳本無法記錄)。

????
監(jiān)控腳本一覽:
#!/bin/bashread -p "輸入進程的id:" processIdwhile [ 1 ]do#每隔五秒讀一次進程內存,看結束之后內存情況ProcessMem=`cat /proc/$processId/status |grep VmRSS|awk '{print $2,$3}'`DateTime=` date "+%H:%M:%S"`echo $DateTime "| 進程內存:"$ProcessMem >> noclose-process-mem.txtsleep 5sdone
6、測試結果
不關閉流:

? ?
內存情況(腳本統(tǒng)計):16M -> 822M,相當大
???
貼出來一部分腳本統(tǒng)計數據:
????
09:33:11 | 進程內存:16580 kB09:33:16 | 進程內存:16580 kB09:33:21 | 進程內存:16580 kB09:33:26 | 進程內存:16580 kB09:33:31 | 進程內存:16580 kB #發(fā)起請求,內存開始暴漲09:33:36 | 進程內存:44324 kB09:33:41 | 進程內存:74400 kB09:33:46 | 進程內存:98708 kB09:33:51 | 進程內存:122612 kB09:33:56 | 進程內存:147912 kB.....10:05:57 |??進程內存:822224 kB #請求結束慢慢恢復穩(wěn)定10:06:12 | 進程內存:822488 kB10:06:17 | 進程內存:822488 kB......10:06:47 | 進程內存:822488 kB10:06:52 | 進程內存:822488 kB10:06:57 | 進程內存:822488 kB#之后內存并沒有縮小
????
查看一下goroutine:

關閉流:

?
內存統(tǒng)計:16M -> 44M(優(yōu)化了80%左右,請求時間也縮短)
?
每次請求關閉流:
09:25:44 | 進程內存:16496 kB#初始內存----往下表示發(fā)起請求,內存開始增長09:25:49 | 進程內存:35948 kB09:25:54 | 進程內存:41320 kB09:25:59 | 進程內存:41776 kB......09:29:24 | 進程內存:43976 kB#逐漸趨于穩(wěn)定09:29:29 | 進程內存:43976 kB09:29:34 | 進程內存:43976 kB09:29:39 | 進程內存:44180 kB#已經穩(wěn)定在44M09:29:44 | 進程內存:44180 kB
7、再次定位
????
定位到問題,雖然上述方法可以解決內存泄露的問題,但是并沒有選擇這種方式,因為和最初的設計模式相悖,最初針對這塊設計模式是單例模式。
之后又是抓耳撓腮的讀代碼,調試,終于發(fā)現問題所在.......
查看一波自己寫的該部分代碼:
/*源代碼不能泄露,這是本地自己編寫的代碼,大概邏輯類似*/func?GetClient(userName?string)?*Client{//先在緩存讀,讀不到就new,存mapkey := userName??//從map中獲取,該map是sync.map,并發(fā)安全??value,?ok?:=?Map.Load(key)if ok{fmt.Println("讀syncmap")return value.(*Client)}??client?:=?newClient(userName)??Map.Store(key,client)return client}
發(fā)現客戶端作為單例對象,不是線程安全的,沒有并發(fā)控制機制,當初始遇到并發(fā)請求時候,就會創(chuàng)建大量的客戶端,請求結束無法釋放,導致程序中大量無感的客戶端占用內存。
最終解決方法:既然不是線程安全,加個鎖。
/*本地模擬的代碼*/func GetClient(userName string) *Client{??//加鎖保證線程安全lock.Lock()??defer?lock.UnLock()??key?:=??userNamevalue, ok := Map.Load(key)if ok{fmt.Println("讀syncmap")return value.(*Client)}client := newClient(userName)Map.Store(key,client)return client}
果斷修改調試.....
等待一天后......
goroutine數雖然有所減少還是讓人抓狂
,陷入自我懷疑
猜測問題是不是出在map里面,開始一波針對性的檢查。
終于又發(fā)現問題:
首先,map在清理的時候沒有釋放掉里面的連接(在第一種方案時候就定位到了)。
map清理的定期時間是可配的,讀取配置文件出錯沒有異常處理,使用了默認值(默認值很小)。
完成問題定位,最終修改完成,調試,內存雖然有增長,但是要優(yōu)化了很多。
問題解決
這次問題的解決并不是一帆風順,這個泄露問題是好多點綜合作用的結果,期間還有很多繁瑣的點,要復現某個泄露的點真的很讓人頭大,pprof顯示的所有泄露的點調用棧都在引用的庫源碼里,和網上的定位文章一點不一樣,算是在摸索著前進。最終主要的優(yōu)化方式就是上述兩種方式。選擇了后者
,最初設計是不能亂改的嘛,不過正因為這次問題出現,對Golang有了更深層的了解。
也得到一點經驗教訓:
一定要在測試機上仔細檢查,業(yè)務驗證同時要關注服務的內存與CPU。
goroutine泄露的點主要發(fā)生在channel的阻塞上。
對于Golang錯誤處理留個心眼,萬一在沒有察覺的地方出錯了呢?
推薦閱讀


