記一次golang內存泄露
最近在QA環境上驗證功能時,發現機器特別卡,查看系統內存,發現可用(available)內存僅剩200多M,通過對進程耗用內存進行排序,發現有一個名為application-manager的容器服務的內存占用達到700多M,該服務使用Gin框架對外提供操作k8s資源的簡單功能,解析客戶端請求,並將結果返回給客戶端。由於是測試環境,訪問量極少,但內存一直只增不減,從最初的10M,一直增加到700多M,最終由於OOM而被重啟(Pod)。
最初使用go pprof來嘗試定位是否代碼中存在如未釋放的全局變量或存在goroutine泄露。初步定位后發現並沒有goroutine泄露。/debug/pprof/allocs導出的svg文件參見這里:
# go tool pprof http://127.0.0.1/debug/pprof/allocs
Fetching profile over HTTP from http://oms.qa.internal.hsmob.com/debug/pprof/allocs
Saved profile in C:\Users\liuch\pprof\pprof.application-manager.alloc_objects.alloc_space.inuse_objects.inuse_space.005.pb.gz
File: application-manager
Type: alloc_space
Time: May 24, 2021 at 9:21am (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) web
內存占用圖中唯一一個與自己的功能有關的代碼就是setK8sEvent,至此可以初步懷疑問題所在。但問題點並不明確。另外在圖中可以看到占用內存最多的函數是goLookupIpCNAMEOrder,該函數與域名查找有關,可能是建立鏈接前的步驟。
進入該容器(application-manager),查看底層鏈接情況,可以看到在該容器中建立了9492條TCP鏈接。至此已經找到問題根因,內存泄露的原因是沒有及時關閉TCP,導致創建了大量socket,占用大量內存。
# ss -s
Total: 10215 (kernel 15097)
TCP: 9492 (estab 7953, closed 1537, orphaned 0, synrecv 0, timewait 1106/0), ports 0
Transport Total IP IPv6
* 15097 - -
RAW 0 0 0
UDP 0 0 0
TCP 7955 7952 3
INET 7955 7952 3
FRAG 0 0 0
在容器中使用ss -ntp命令進一步查看是創建了到哪些服務鏈接。最終發現創建了大量到elasticsearch 9200端口的鏈接,結合前面提到的setK8sEvent函數(該函數會將k8s事件發送給elasticsearch),基本可以確定是在讀取es的數據之后,忘了執行resp.Body.Close()操作。
后記
代碼中的確存在沒有執行resp.Body.Close()的操作,修復之后發現內存占用正常。
總結
- 如果golang程序發現內存泄露,可以首先檢查socket泄露。
