修復我的 Golang 網頁應用程式中的記憶體耗盡錯誤
今年稍早,我建立了一個名為 PicoShare 的開源應用程式。這是一個用於分享檔案的簡易 Golang 網頁應用程式。我用它來傳送太大而無法作為電子郵件附件的檔案,同時又不希望收件人還得處理 Dropbox 或 Google Drive。

幾個月前,我發現我的 PicoShare 伺服器每隔幾天就會當掉。查看日誌後,我看到了記憶體不足(out of memory)錯誤:

當時沒時間除錯這個當機問題,所以我只是把伺服器的記憶體從 512 MB 加到 1 GB。之後還是持續當機,於是我又加到了 2 GB。
只靠增加 RAM 來解決當機問題實在令人不滿意,因此過去兩週我一直在除錯這些當機問題,並在 Twitter 上分享進度。
到目前為止,我已經修復了所有導致當機的問題,並在過程中學到了關於 Go、SQLite 與除錯的一些實用經驗。
如果你想看整個過程是如何展開的,請查看 Twitter 討論串。如果想看整理過、精簡版的心得,請繼續往下閱讀。
前言:我以奇怪的方式使用 SQLite
我在 PicoShare 上做的一個奇怪架構決策,就是把所有檔案資料都儲存在 SQLite 中。這是一個不尋常的選擇,因為網頁應用程式通常會將上傳的檔案直接儲存在檔案系統中,而非資料庫中。當上傳的檔案可能任意龐大時,尤其如此。
將檔案資料寫入 SQLite 的好處是,PicoShare 的所有應用程式狀態都集中在單一資料庫中。這本身沒什麼特別,但我設計 PicoShare 時讓它與 Litestream 整合——這是一款將 SQLite 資料庫複製到雲端儲存空間的工具。Litestream 基本上讓 PicoShare 免費獲得了備份與還原功能。我可以把整台伺服器完全清除,然後在任何地方(甚至是另一家雲端主機服務商)重新部署,PicoShare 都會以完全相同的狀態醒來,並繼續提供所有相同的檔案。
除錯過程
重現錯誤
我每隔幾天才會看到 PicoShare 當機一次,因此第一步是想辦法更快地強制觸發當機。
我透過在只有 256 MB 記憶體的 Fly 執行個體上部署 PicoShare,並上傳大型檔案,成功重現了這個錯誤。我使用短片 Big Buck Bunny 的高解析度版本作為測試檔,檔案大小從 269 MB 到 618 MB 不等。

我使用短片Big Buck Bunny作為測試檔案,因為它的容量夠大,適合測試大型上傳。
同時平行上傳兩個 618 MB 版本的檔案,幾乎都能在一分鐘內穩定地讓 PicoShare 因記憶體不足而當掉。
使用效能分析工具找出記憶體膨脹的原因
調查過程中的第一個突破來自 Litestream 的作者、也是近期加入 Fly 團隊的 Ben Johnson(班·強森)。班·強森提交了一份詳細的 pull request,解釋了一行程式碼如何導致 PicoShare 消耗大量記憶體。
班·強森在效能分析方面經驗豐富,因此他透過建立新的單元測試並在測試後分析記憶體使用情況,重現了這個問題。之後班·強森又向我展示了更簡單的方法來取得相同資訊,所以接下來我要介紹這個方法,但你也可以在他的 pull request 中找到他最初的做法。
結果發現 Go 標準函式庫本身就提供了一個用於除錯網頁應用程式問題的神奇工具。你只需要在 import 中加入這一行:
_ "net/http/pprof"現在當你執行應用程式時,就會有一個 /debug/pprof/ 路徑,提供大量實用的除錯資訊。

我很驚訝這樣就能輕鬆加上這個功能。這個網頁介面中有許多有趣的資料,但我使用的是 heap。要使用它,我先上傳一個大型檔案到 PicoShare,然後執行以下指令:
go tool pprof \
-http=:8081 \
-alloc_space \
call_tree \
http://localhost:4001/debug/pprof/heap這會彈出一個網頁介面並繪製出這張圖:

在底部,你可以看到一個標示為 bytes makeSlice 63.99 MB 的大型紅色區塊,代表 PicoShare 已配置的記憶體中有 64 MB 來自 Go 的 makeSlice 函式。
makeSlice 位於 Go 標準函式庫中,而非我的程式碼。為了找出 PicoShare 中是哪段程式碼導致這次記憶體配置,我沿著圖表往上追蹤,直到找到一個 PicoShare 的函式:

這條呼叫鏈中最後一個 PicoShare 函式是 handlers.fileFromRequest,它呼叫了 Go 標準函式庫的函式 *Request.ParseMultipartForm。該函式負責解析 multipart HTTP 資料,而 PicoShare 正是透過這種方式接收檔案上傳。
ParseMultipartForm 接受一個 maxMemory 參數,其文件說明如下:
整個請求主體會被解析,其中檔案部分的總量最多有 maxMemory 位元組會儲存在記憶體中,其餘部分則會以暫存檔的形式儲存在磁碟上。
PicoShare 的呼叫如下所示:
r.ParseMultipartForm(32 << 20) // 32 MB即使我們指定的上限是 32 MB,Go 卻配置了 64 MB 的記憶體。
班·強森嘗試將 maxMemory 參數降至 1 << 20(1 MB),結果 ParseMultipartForm 的記憶體使用量降至僅 2.5 MB:

這是記憶體使用量的大幅下降,所以我一度以為班·強森已經解決了問題。
可惜的是,我部署了包含班·強森修正的測試版本,結果仍然當機。
套用班·強森的修正後,PicoShare 在當機前能承受更大的負載,所以看起來確實有效果。不過,當我同時平行上傳三個大型檔案時,伺服器仍因同樣的記憶體不足錯誤而當掉。
在呼叫 ParseMultipartForm 後釋放資源
透過 Google 搜尋,我發現了 ParseMultipartForm 的另一個陷阱。
文件並未提醒讀者,但呼叫者有責任呼叫 r.MultipartForm.RemoveAll() 來釋放 Go 在 ParseMultipartForm 期間配置的資源。因此,我每次呼叫 ParseMultipartForm 時都在洩漏記憶體。
更新(2022-08-11):Damien Neil(達米安·尼爾)在留言中指出,Go 應該會自動清理這些資源。在 Go 的 HTTP/1 實作中,會自動清理資源,而達米安·尼爾已提交了一個錯誤修正,讓 Go 的 HTTP/2 實作行為保持一致。
為了修復這個洩漏,我重寫了程式碼以清理 multipart 資源:
multipartMaxMemory := 1 << 20 // 1 MiB
if err := r.ParseMultipartForm(multipartMaxMemory); err != nil {
return err
}
// Free form resources before returning from function.
defer func() {
if err := r.MultipartForm.RemoveAll(); err != nil {
log.Printf("failed to free multipart form resources: %v", err)
}
}()這個修正看起來很有希望,因為在明確釋放資源後,我在 Fly 上看到記憶體使用量大幅下降:

可惜的是,即使有了這個修正,當機仍然持續發生。
最佳化下載
就在這個時候,Dan Wilhelm(丹·威廉)開始關注這則 Twitter 討論串。儘管他從未用過 Go,他還是捲起袖子,在自己的開發機上開始實驗程式碼。
丹·威廉注意到下載檔案時記憶體使用量會飆升。這很奇怪,因為下載不應該消耗太多記憶體。解析 multipart 表單很複雜,有許多因素可能導致記憶體膨脹,但提供檔案服務應該是相當單純的。
PicoShare 將所有檔案資料以328 KB 為單位分塊儲存在 SQLite 中。這不應該會耗用大量記憶體,因為我們應該只需要將一些區塊讀入記憶體、傳送給客戶端,然後釋放記憶體即可。
丹·威廉在負責從資料庫讀取 PicoShare 檔案資料的程式碼中發現了一個錯誤。看看你能不能找出來:
func (fr *fileReader) populateBuffer() error {
if fr.offset == int64(fr.fileLength) {
return io.EOF
}
startChunk := fr.offset / int64(fr.chunkSize)
stmt, err := fr.db.Prepare(`
SELECT
chunk
FROM
entries_data
WHERE
id=? AND
chunk_index>=?
ORDER BY
chunk_index ASC
`)
if err != nil {
log.Printf("reading chunk failed: %v", err)
return err
}
defer stmt.Close()
var chunk []byte
err = stmt.QueryRow(fr.entryID, startChunk).Scan(&chunk)
if err != nil {
return err
}
// Move the start index to the position in the chunk we want to read.
readStart := fr.offset % int64(fr.chunkSize)
fr.buf = bytes.NewBuffer(chunk[readStart:])
fr.offset += int64(len(chunk)) - readStart
return nil
}錯誤出在 SQL 查詢的 WHERE 子句中:
WHERE
id=? AND
chunk_index>=?這個查詢原本應該只擷取單一區塊的檔案資料,卻把目標區塊以及之後的所有區塊都讀出來了。
修正方法很簡單,只要把 >= 改成 = 即可:
WHERE
id=? AND
chunk_index=?附註:閱讀這段程式碼時,我也意識到自己在不需要的時候使用了 prepared statements,不過我認為這並未影響記憶體使用。
丹·威廉的改動是在下載端,因此我原本就不期待它能修復我在上傳時看到的當機問題。事實上也的確沒有,但提供下載的效能卻有了大幅改善。特別是在串流影片或音訊等內容時,當我在檔案中跳轉到不同位置,PicoShare 的反應變得靈敏許多。
移除 SQLite 交易
在 Twitter 討論串中,有幾個人認為 PicoShare 的 SQLite 交易很可能是導致記憶體膨脹的原因。
當 PicoShare 將檔案資料寫入 SQLite 時,我是在交易中執行的。目的是確保資料庫始終處於一致的狀態。
透過使用交易,SQLite 保證即使部分寫入失敗,我也不會陷入只有部分檔案在資料庫中的狀態。它也確保我不會意外地只寫入檔案詮釋資料而未寫入檔案內容,反之亦然。
一些 Google 搜尋結果顯示,大型的 SQLite 交易可能是記憶體膨脹的來源之一,因此我覺得值得一試。我嘗試改為立即將變更提交至 SQLite,而不使用交易,但記憶體仍然膨脹。看起來交易似乎沒有造成任何差異。
記憶體膨脹沒關係,但當機不行
在這個階段,我從三個不同角度測量記憶體使用量,但結果彼此都不一致:
- Go 的除錯指標顯示已配置了多少記憶體
- 虛擬機器內的
htop - 來自虛擬機器主機的 Fly 記憶體指標


我用來測量記憶體使用量的不同工具彼此不一致
特別是,Fly 的指標經常顯示記憶體已滿載,而 Go 和 htop 卻顯示幾乎沒有使用量。這讓除錯變得很挫折,因為我越深入挖掘,記憶體測量結果就越偏離我實際觀察到的當機行為。
改變局勢的洞見來自 Andrew Ayer(安德魯·艾爾),他指出記憶體膨脹很可能是一個假議題:

Fly 的執行長 Kurt Mackey(柯特·麥基)也加入討論串,證實了安德魯·艾爾的假設:

所以,Fly 的記憶體指標包含了 page cache(分頁快取),但如果執行中的應用程式需要記憶體,虛擬機器應該會回收那些 RAM。
這是一個重大的領悟。由於很難重現記憶體不足的當機,我一直把記憶體膨脹當作當機的近似指標。但只要虛擬機器仍有足夠的記憶體讓我的處理程序繼續執行,記憶體膨脹其實是沒關係的。
我現在必須重新評估一切。當我排除其他修正時,是因為它們只造成無害的記憶體膨脹嗎?還是我真的觀察到了當機?
重新檢視 SQLite 交易
考慮到安德魯·艾爾對於記憶體膨脹的說法,我重新檢視了 PicoShare 的 SQLite 交易。當我嘗試不使用交易的實作時,我看到的是當機還是只是記憶體膨脹?我已經記不得了。
我再次嘗試執行無交易的版本。果然,記憶體膨脹了,但 PicoShare 仍持續運作。我同時平行上傳了三個 618 MB 的檔案,每個上傳都成功,且 PicoShare 持續處理 HTTP 請求。

成功了!我終於找到了效能問題的根源。
至少我當時是這麼想的……
我讓伺服器整夜持續運作,隔天早上查看時,它又因同樣的記憶體不足錯誤而失敗。

移除 SQLite VACUUM
我立刻懷疑整夜後的當機與 SQLite VACUUM 指令有關,該指令會壓縮資料庫檔案以回收未使用的磁碟空間。
當機時沒有人在使用 PicoShare 伺服器,但時間點恰好與 PicoShare 排程的資料庫維護吻合。每隔七小時,PicoShare 會從資料庫中移除過期的項目,並執行 VACUUM 以回收未使用的磁碟空間。
我在伺服器上測試執行 VACUUM 指令,發現它確實縮小了主 .db 檔案的大小,但卻增加了 SQLite write-ahead log 的大小。

在這個時候,班·強森問我為什麼需要執行 VACUUM:

對啊,我到底為什麼要這麼做?
當我最初推出 PicoShare 時,使用者抱怨刪除檔案後並未釋出磁碟空間。這對我沒什麼影響,因為我在 Fly 虛擬機器上執行 PicoShare,使用的是固定大小的磁碟區,因此用了多少磁碟空間並不重要。但定期執行 VACUUM 很容易加入,所以我就做了。
經過深思後,我決定改變 PicoShare 的行為,讓 VACUUM 預設為關閉,但使用者可以透過命令列旗標啟用它。
dbPath := flag.String("db", "data/store.db", "path to database")
vacuumDb := flag.Bool("vacuum", false, "vacuum database periodically to reclaim disk space")
flag.Parse()成功:PicoShare 在 256 MB 記憶體上穩定執行
在預設停用 VACUUM 並套用其他效能修正後,PicoShare 終於能在低記憶體的情況下穩定執行。
我在只有 256 MB 記憶體的 Fly 虛擬機器上,讓 PicoShare 連續執行了 24 小時而沒有任何當機。


過去 24 小時 100% 正常運作
其他學到的經驗
除了上述學到的內容外,我在這次除錯探索中也獲得了一些實用的額外收穫。
最佳化你的建置與測試循環
有一件事我希望能更早去做,那就是最佳化我的建置與測試循環。為了測試任何假設,我的流程是:
- 將變更部署到 Fly(2 至 3 分鐘)
- 上傳一個大型檔案(1 至 2 分鐘)
- 等待 Fly 的記憶體指標更新(30 至 60 秒)
所以,光是測試任何一項變更就最多需要六分鐘,而且每個步驟都需要手動操作。這還不包括撰寫程式碼變更的時間。
我原本嘗試在限制記憶體的 Docker 容器中執行 PicoShare,但它從未當機。
RAM_LIMIT="64m"
PORT=3001
PS_SHARED_SECRET="somesecretpass"
docker run \
--memory "${RAM_LIMIT}" \
--env "PORT=${PORT}" \
--env "PS_SHARED_SECRET=${PS_SHARED_SECRET}" \
--publish "${PORT}:${PORT}/tcp" \
--name picoshare \
mtlynch/picoshare:1.1.7$ docker stats
CONTAINER ID NAME CPU % MEM USAGE / LIMIT MEM % NET I/O BLOCK I/O PIDS
1ababd398113 picoshare 3.82% 63.68MiB / 64MiB 99.50% 278MB / 208MB 6.09GB / 7.1MB 21我仍然不明白為什麼 PicoShare 在 Docker 下的表現與在真正的虛擬機器上不同,但我最好的猜測是 Docker 並沒有像虛擬機器那樣嚴格地限制記憶體使用。
當丹·威廉回報他在本地執行 PicoShare 並觀察記憶體使用量所取得的進展時,我才意識到自己每次變更都部署到 Fly 浪費了多少時間。我嘗試在自家的虛擬機器伺服器上執行 PicoShare,但它從未像在 Fly 上那樣當機或出現記憶體膨脹。
最終有效的方法是在 Fly 上建立我自己的開發環境。我撰寫了一個 Dockerfile,其中包含 PicoShare 原始碼和一些開發工具,並將其部署到 Fly。之後,我就能使用 fly ssh console 在伺服器上開啟 shell,然後快速測試程式碼變更。
這仍然不是超級快速,因為 Fly 的記憶體指標更新前約有 30 秒的延遲,但比起每次都要從頭部署,已經是很大的改進。
使用描述性的 Git 分支與提交訊息來記錄筆記
在這次調查中,我發現一個實用的技巧:為每個假設建立獨立的 Git 分支進行測試,然後用提交訊息記錄結果:

由於有這麼多不同的假設在流傳,很難記得測試每個想法時程式碼處於什麼狀態。例如,有一次我看到的當機其實是由於我在除錯時引入的新錯誤所導致。
記錄程式碼當時的狀態以及我如何測試,有助於我整理思緒並避免重複工作。
Go 的測量工具無法看到 cgo 中的記憶體配置
我最早的除錯步驟之一是在 PicoShare 中加入一個頁面,顯示來自 runtime.ReadMemStats 的部分記憶體指標(後來我才意識到 net/http/pprof 在這方面做得更好)。

James Tucker(詹姆斯·塔克)指出,這種測量方式會排除我透過 cgo 配置的任何資源:

我的確是透過 cgo 使用 SQLite。PicoShare 使用的是 mattn/go-sqlite3,這是 Go 最受歡迎的 SQLite 函式庫。
使用 cgo 會讓 Go 無法顯示準確的效能指標,這是很合理的。如果你使用 Go 來呼叫外部的 C 語言程式碼,Go 就無法追蹤外部程式碼中的資源。
為了解決這個問題,我嘗試使用 modernc.org/sqlite,這是一個純 Go 實作的 SQLite。但不知為何,即使使用純 Go 程式碼,我也看不到資源洩漏的情況。
Fly 擁有驚人的磁碟效能
有一次,Twitter 上的留言者認為我可能是因為磁碟寫入而耗盡記憶體。如果 PicoShare 寫入 Fly 虛擬機器磁碟的速度,快於磁碟將資料寫入實體媒體的速度,資料就會在記憶體中排隊。
為了驗證這個理論,我使用了之前從未用過的 fio 磁碟效能測試工具。我一度以為自己用錯了工具,因為它回報的寫入速度為 3353 MB/s,這對雲端虛擬機器來說似乎快得不可思議。作為對比,這比我在自家 NAS 伺服器上做相同測試時快了約 30 倍。
柯特·麥基證實這些測量結果很可能是正確的,因為 Fly 的本地磁碟是企業級 NVMe 硬碟:

死胡同
儘管我多麼希望這次調查是一段持續進展的過程,但我走了許多冤枉路,也追隨了一些毫無結果的假設。以下是其中一些死胡同。
歸咎於 Litestream
除錯的第一條規則是假設問題出在自己的程式碼中。但我在這裡打破了這個規則,部分原因是因為我害怕追查這些錯誤會耗費大量工作。
話雖如此,懷疑 Litestream 也有合理的理由。儘管 PicoShare 以奇怪的方式使用 SQLite,但在 SQLite 中儲存 1 GB 的資料並沒有那麼奇怪。Litestream 相對較新,且以新穎的方式使用 SQLite,因此想像當機來自 Litestream 並非太大的跳躍。
即使我懷疑 Litestream,我也不想為 Litestream 的維護者班·強森增加更多工作。我知道 PicoShare 是 Litestream 一個不尋常的使用案例,而且我沒有簡單的重現方式來隔離問題。
但接著在五月,Fly 收購了 Litestream並聘請班·強森來維護它。現在似乎正是拿這個問題去煩班·強森的完美時機,因為這同時牽涉到 Litestream 和 Fly!
我在 Litestream 上提交了一個錯誤回報,解釋了我嘗試過什麼以及為何認為問題與 Litestream 有關。結果 15 分鐘後,我在停用 Litestream 的情況下成功讓 PicoShare 當機,因此就把這個錯誤回報關閉了。
話雖如此,針對 Litestream 提交問題還是很有用的,因為它迫使我以足夠嚴謹的方式來處理問題,才能寫出一份詳細的錯誤回報。這也引起了班·強森的好奇心,讓他在確認 Litestream 並非原因後,仍提供了許多實用的建議。
歸咎於 Fly
當我在本地虛擬機器或 Docker 下無法重現當機時,我開始懷疑問題出在 Fly 那端。這似乎不太可能,因為我並沒有做什麼特別的事情,如果 Fly 的其他使用者都沒有注意到他們的部署因記憶體不足而當掉,那就很奇怪了。
不過,我還是想排除 Fly 的可能性。我將 PicoShare 部署到 Lightsail,也就是 Amazon 代管的 Docker 容器服務。他們沒有 256 MB 記憶體的選項,所以我部署到 512 MB 的執行個體。幾分鐘內,我就在那裡成功重現了當機,排除了 Fly 是罪魁禍首的可能性。
/tmp 不是 RAM 磁碟
在 Twitter 討論串中,有幾位留言者認為 Fly 可能將其暫存目錄掛載為 RAM 磁碟。Go 的 ParseMultipartForm 函式會將檔案上傳保存在暫存目錄中,因此如果 Fly 將暫存目錄掛載為 RAM 磁碟,就能解釋為何一般的檔案上傳會耗盡記憶體。
但當我執行 lblk 時,並未看到任何跡象顯示 /tmp 或其他暫存目錄是 RAM 磁碟。系統看起來只有一般的磁碟:
$ lsblk
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINTS
vda 254:0 0 128M 0 disk
vdb 254:16 0 8G 0 disk /
$ du -h /tmp/*
149.3M /tmp/multipart-338465586
7.66 /tmp/test1撰寫手工打造的 multipart 表單讀取器
Go 標準函式庫的 ParseMultipartForm 函式似乎比其文件所述的上限消耗更多記憶體,這是一個警訊。我也注意到,如果我呼叫 ParseMultipartForm 並丟棄位元組,記憶體同樣會被耗盡。
為了看看是否能繞過 ParseMultipartForm 的問題,我嘗試為我的特定情境撰寫自己的手工 multipart 讀取器。
可惜的是,我的 multipart 讀取器表現並不比標準函式庫好,但在更底層處理 multipart 資料倒是很有趣。
限制上傳速度
我很好奇,如果放慢資料上傳速度,是否會對記憶體有任何影響。我嘗試從客戶端限制上傳速度,將 Chrome 設定為模擬 3G 速度,但 PicoShare 的行為還是一樣。
我也嘗試在伺服器端進行限速,以降低寫入磁碟的速度,但同樣沒有任何效果。
不過,我倒是學到了在 Go 中限制 I/O 有多容易。如果你使用的是 io.Reader 介面,只要像這樣用限速的讀取器包裝 Reader 即可:
import "github.com/juju/ratelimit"
...
throttleRate := 1 << 20 // 1 MB
bucket := ratelimit.NewBucketWithRate(float64(throttleRate), throttleRate)
throttledReader := ratelimit.Reader(reader, bucket)
w := file.NewWriter(tx, metadata.ID, d.chunkSize)
if _, err := io.Copy(w, throttledReader); err != nil {
return err
}PicoShare 1.2.0
在週末,我發布了 PicoShare 的 1.2.0 版本,其中包含了我在這次調查中發現的所有效能問題的修正。
致謝
非常感謝所有協助我調查此問題的人,特別要感謝以下幾位付出額外心力的朋友:
隨機一篇部落格