一次 Go 程序 out of memory 排查及反思
【導讀】遇到 OOM 不要手慌腳亂，細心大膽用 pprof 看起來問題。本文介紹了一個 OOM 問題從發現到解決的過程。
前言
最近在搞數據導出模塊，在測試大文件下載的過程中，報了 Out of memory (OOM) 錯誤，因爲之前沒有遇到過這類問題，導致此次排查問題花費了大半天，也走了不少彎路，特此覆盤記錄。
現象描述
和往常一樣複製粘貼完最後一個下載接口，沒什麼問題的話，導出模塊就可以收工了。
上服務器部署完，隨便測試了幾個小文件的下載，一切按照預期正常地運行。
隨後我點擊下載了一個 2.6G 的大文件，情況變得糟糕起來，通過 docker stats 觀察到其內存一直上漲到 7G 左右，然後容器 Exit 2，日誌報 fatal error: runtime: out of memory。
bigfile
stats
exit
此時我一點都不緊張，甚至有點高興，剛好這幾天在看 pprof，並且平時 curd 幹多了，正好來點 bug 調解一下心情~
排查過程
現場日誌
fatal error: runtime: out of memory
runtime stack:
runtime.throw(0x1447dc3, 0x16)
runtime/panic.go:774 +0x72
runtime.sysMap(0xc13c000000, 0x130000000, 0x3202418)
runtime/mem_linux.go:169 +0xc5
runtime.(*mheap).sysAlloc(0x31e12c0, 0x130000000, 0x7f4cfdffaae8, 0x43d067)
runtime/malloc.go:701 +0x1cd
runtime.(*mheap).grow(0x31e12c0, 0x98000, 0xffffffff)
runtime/mheap.go:1255 +0xa3
runtime.(*mheap).allocSpanLocked(0x31e12c0, 0x98000, 0x3202428, 0x7f4c00000000)
runtime/mheap.go:1170 +0x266
runtime.(*mheap).alloc_m(0x31e12c0, 0x98000, 0x101, 0x7f4cfdffac08)
runtime/mheap.go:1022 +0xc2
runtime.(*mheap).alloc.func1()
runtime/mheap.go:1093 +0x4c
runtime.(*mheap).alloc(0x31e12c0, 0x98000, 0x7f4cfd010101, 0x43e155)
runtime/mheap.go:1092 +0x8a
runtime.largeAlloc(0x12fffff10, 0xc000040101, 0xc001816180)
runtime/malloc.go:1138 +0x97
runtime.mallocgc.func1()
runtime/malloc.go:1033 +0x46
runtime.systemstack(0xc001d80180)
runtime/asm_amd64.s:370 +0x66
runtime.mstart()
runtime/proc.go:1146由於 go panic 時，將所有的 goroutine 調用棧都打印了出來，報錯信息鋪了好幾頁，而且第一行是一個 runtime error，所以當時我就粗略地看了一下，並沒有找到什麼有用日誌。
分析代碼
// file download
filePath := path.Join(ms.Configs().GetString("system.exportPath"), filename)
f, _ := os.Open(filePath)
defer f.Close()
stat, _ := f.Stat()
c.Writer.WriteHeader(http.StatusOK)
c.Header("Content-Disposition", "attachment; filename="+filename)
c.Header("Content-Type", "application/octet-stream")
c.Header("Content-Length", fmt.Sprintf("%d", stat.Size()))
c.File(filePath)核心代碼就這麼幾行，而且還是從老項目中複製過來的，怎麼可能出問題？？？
此時我的內心開始甩鍋了，可能是環境的問題？老項目用的是 k8s，現在用的是 docker-compose、老項目用的是 go1.13 現在是 go1.15。
demo 測試
由於項目依賴較多，本地運行不太方便，於是我寫了一個小 demo，打算不用 docker 直接跑起來（準備把鍋甩給 docker）
func main() {
r := gin.Default()
r.GET("/download", func(c *gin.Context) {
filename := "cb6mp2mh843u.zip"
filePath := path.Join("/data", filename)
c.Writer.WriteHeader(http.StatusOK)
c.Header("Content-Disposition", "attachment; filename="+filename)
c.Header("Content-Type", "application/octet-stream")
c.File(filePath)
})
r.Run("0.0.0.0:8686")
}demo 跑起來後，多次測試，內存使用情況一切正常，此時我陷入了沉思......
pprof
沒辦法，只好用 pprof 了，剛好現學現用。
pprof
使用 pprof 採集了 heap 的數據，很快就找到了問題，項目使用的小組內基於 gin 封裝的一個輪子，爲了記錄 response body 日誌，將其 Dump 了下來，2.6G 的數據呀...
於是我順手加了個 if else 判斷，修了這個 bug
log
dump
覆盤反思
所以當時我就粗略地看了一下，並沒有找到什麼有用日誌
程序出錯時報的日誌，裏面包含了最重要，直接的排查線索，一定要仔細地將每一行都看一遍，不能由於信息較多，就忽略它。
事後統計當時報錯的日誌就 300 多行，12 個 goroutine，如果稍微仔細看一下，我相信很快就能定位到問題所在，也不用水這一篇文章了。
logs
可能是環境的問題？老項目用的是 k8s，現在用的是 docker-compose、老項目用的是 go1.13 現在是 go1.15
在出現問題時，程序員總是喜歡將鍋甩給環境、工具等，不是說這些基礎組件一定沒有 bug，而是對於大多數的 CRUD 程序來說，根本觸發不了底層組件的問題。
所以當沒有十足的證據來表明是基礎組件的問題時，我們還是老老實實地分析自己的代碼，別把路走偏了。
由於項目依賴較多，本地運行不太方便，於是我寫了一個小 demo
在寫 demo 時，一定要注意單一變量原則，項目中使用了組內基於 gin 封裝的一個小輪子，而 demo 中使用的是原生的 gin，最難受的是，最終排查到是小輪子的 bug。
轉自：
cnblogs.com/yahuian/p/once-go-programe-oom-fix.html
本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/idmvr9mKZ8YL_I8WC645zg