Go Heap Profile 怎麼了？

Go heap profile 是常常用來檢查內存泄露和內存佔用大問題的問題的手段，而且非常常用。

而且，我們也經常創建兩個間隔較長的 heap profile, 獲取它們的差值來方便查看內存泄露: Hi, 使用多年的 go pprof 檢查內存泄漏的方法居然是錯的?! [1]

今天，度廠的一位同學提出了一個很有意思的案例，讓我們對 heap profile 有了更深的理解。

問題: heap profile 不能正確反應當前分配的內存?

這個同學舉了一個簡單的 Go 程序的例子:

package main

import (
 "fmt"
 "net/http"
 _ "net/http/pprof"
 "runtime"
 "time"
)

func main() {
 go func() {
  http.ListenAndServe("localhost:8080", nil)
 }()

 go func() {
  // 每秒打印內存分配情況
  for {
   var m runtime.MemStats
   runtime.ReadMemStats(&m)
   fmt.Printf("Alloc = %v MiB", bToMb(m.Alloc))
   fmt.Printf("\tTotalAlloc = %v MiB", bToMb(m.TotalAlloc))
   fmt.Printf("\tSys = %v MiB", bToMb(m.Sys))
   fmt.Printf("\tNumGC = %v\n", m.NumGC)
   time.Sleep(1 * time.Second)
  }

 }()
 time.Sleep(5 * time.Second)

 fmt.Println("start test")

 // 創建一個 200 MiB 的切片
 var memoryLeaks [][]int32
 for i := 0; i < 10; i++ {
  leak := make([]int32, 5*1024*1024) // 分配 5*1M*4bytes = 20 MiB
  memoryLeaks = append(memoryLeaks, leak)
  time.Sleep(1 * time.Second) // 延遲一秒觀察內存分配情況
 }
 // 期望至少分配了 200 MiB 內存
 fmt.Println("end test")
 // 看到上面的文字後，打開go pprof 工具，查看工具的分析
 // go tool pprof -http :8972 http://127.0.0.1:8080/debug/pprof/heap


 time.Sleep(1 * time.Hour)
 fmt.Println("test", memoryLeaks[9][5*1024*1024-1]) // 避免垃圾回收和優化

}

func bToMb(b uint64) uint64 {
 return b / 1024 / 1024
}

這個程序首先創建一個監聽 8080 端口的 web 服務，主要利用它訪問 http heap profile，所以你看導入了 _ "net/http/pprof" 包。

然後創建了了一個切片，切片包含 10 個元素，每個元素又是一個 []int32 的切片。每個元素佔用 20 MiB 的大小 (int32 是 4 個字節，510241024 是 5 M, 所以是 4*5 MiB=20 Mib)。

所以我們期望 10 個循環創建完畢後，至少此程序會佔用 200 MiB 內存，另外在加一些棧、網絡、運行時等一些額外的內存的話，略微會比 200MiB 大一些。

運行這個程序，我們看程序每秒的內存佔用統計：

可以看到使用 runtime.MemStats 統計的內存分配情況還是比較準的， 200MiB，符合預期。

當你看到 end test 時，表明 200MiB 已經分配，你可以運行下面的命令打開 heap profile:

go tool pprof -http :8972 http://127.0.0.1:8080/debug/pprof/heap

如果你使用 Mac 電腦, 可能你還需要手工安裝 graphviz:brew install graphviz

等等，不對呀！怎麼 heap profile 才顯示 160 MB 的內存？少了 40 MB。和期望的不符。

這 160 MB 內存的確是在創建元素的時候分配的：

可那 40 MB 呢？如果 Heap Profile 數據不準，可就動搖了我們一直以來分析內存泄露的技術基礎？

那肯定不會是 Go 實現的問題，否則這個問題早就被暴露和修復了。

接下來我們就介紹根因，講兩個知識點。

把 40 MiB 的分配的內存找回來

如果你再等一會，大約在命令行中看到 end test 兩分鐘後吧，當然再等長一點的時間更佳，你在重新執行命令，查看 heap profile:

go tool pprof -http :8972 http://127.0.0.1:8080/debug/pprof/heap

這個時候瀏覽器中顯示出了 200 MB 的內存分配，符合預期了：

神奇啊，等待一段時間之後，heap profile 就顯示正常了。難道過了一會才分配的內存？那不可能。因爲命令行中 runtime.MemStats 已經顯示結束測試前內存已經分配好了。

看到 end test 之後，程序也沒做啥呀，就是休眠了 1 小時。2 分鐘很像是垃圾回收搞的鬼，2 分鐘強制回收一次。

懷疑歸懷疑，我們驗證一下，在 end test 之後強制垃圾回收一下，再立即打開 heap profile 是不是顯示 200 MiB。

fmt.Println("end test")
runtime.GC()

既然知道是垃圾回收搞得鬼，那麼我們就強制垃圾回收，就可以立即顯示當前已分配的內存了，不用再等待。但是線上運行的程序中也不可能隨心所欲的讓我們在任意的地方動態加 runtime.GC() 呀。

沒關係，訪問 heap profile 我們加上 gc=1 的參數即可 (大於 0 的數都可以)：

go tool pprof -http :8972 "http://127.0.0.1:8080/debug/pprof/heap?gc=1"

你可以在程序中把 runtime.GC() 那一行去掉，使用上面的方式訪問 heap profile 驗證，我就不重複貼圖了。

順便說一下，你還可以加上 debug=1 (非 0 的參數)，可以已文字的方式查看內存分配以及 runtime.MemStats 數據。如 http://127.0.0.1:8080/debug/pprof/heap?gc=1&debug=1

爲啥?

Heap profile 其實調用的 `runtime.MemProfile 進行統計:

func writeHeapInternal(w io.Writer, debug int, defaultSampleType string) error {
 ......
 var p []runtime.MemProfileRecord
 n, ok := runtime.MemProfile(nil, true)
 for {
  p = make([]runtime.MemProfileRecord, n+50)
  n, ok = runtime.MemProfile(p, true)
  if ok {
   p = p[0:n]
   break
  }
 }
    ....
}

MemProfile 的方法簽名如下，它負責統計內存的分配情況：

func MemProfile(p []MemProfileRecord, inuseZero bool) (n int, ok bool)

注意它的文檔有一條：

The returned profile may be up to two garbage collection cycles old. This is to avoid skewing the profile toward allocations; because allocations happen in real time but frees are delayed until the garbage collector performs sweeping, the profile only accounts for allocations that have had a chance to be freed by the garbage collector.

翻譯過來：

返回的性能分析數據可能最多延遲兩個垃圾回收週期。這樣做是爲了避免對內存分配產生偏差; 因爲內存分配是實時發生的, 但釋放操作直到垃圾回收器進行清理時纔會延遲進行, 所以性能分析只會統計那些已經有機會被垃圾回收器回收的內存分配。

所以纔會重現一開始的問題。我們看到 end test 立即查看 heap profile, 還沒有進行垃圾回收，相關的內存統計數據還沒有計算出來，所以纔看到 160 MB 的內存，而不是 200MB 的內存。

system.GC會強制進行垃圾回收，並且會發布新的 heap profile，所以可以看到 200MB 的內存。

func GC() {
 ......
 // Now we're really done with sweeping, so we can publish the
 // stable heap profile. Only do this if we haven't already hit
 // another mark termination.
 mp := acquirem()
 cycle := work.cycles.Load()
 if cycle == n+1 || (gcphase == _GCmark && cycle == n+2) {
  mProf_PostSweep()
 }
 releasem(mp)
}

第一個知識點已經介紹完了，也解答了最初的問題。

現在讓我們來看第二個知識點。

Heap Profile 是採樣的？採啥樣？

heap profile 實際上在內存分配時做採樣統計的，默認情況下並不會記錄所有的內存分配。

這裏我們需要關注 runtime.MemProfileRate 這個變量。

// MemProfileRate controls the fraction of memory allocations
// that are recorded and reported in the memory profile.
// The profiler aims to sample an average of
// one allocation per MemProfileRate bytes allocated.
//
// To include every allocated block in the profile, set MemProfileRate to 1.
// To turn off profiling entirely, set MemProfileRate to 0.
//
// The tools that process the memory profiles assume that the
// profile rate is constant across the lifetime of the program
// and equal to the current value. Programs that change the
// memory profiling rate should do so just once, as early as
// possible in the execution of the program (for example,
// at the beginning of main).
var MemProfileRate int = 512 * 1024

翻譯過來：

MemProfileRate 控制了在內存分析中記錄和報告的內存分配的比例。分析器的目標是每分配 MemProfileRate 字節時, 採樣記錄一次分配。

如果要在分析中包含每一個分配的內存塊, 可以將 MemProfileRate 設置爲 1。如果要完全關閉內存分析, 可以將 MemProfileRate 設置爲 0。

處理內存分析數據的工具假設分析的採樣率在程序的整個生命週期中保持不變, 並等於當前設置的值。如果程序需要改變內存分析的採樣率, 應該只改變一次, 並且儘可能早地在程序執行的開始階段 (例如在 main 函數的開始部分) 進行設置。

如果我們把每次分配的大小改小一點，如下：

    ......
 var memoryLeaks [][]int32
 for i := 0; i < 1000; i++ {
  leak := make([]int32, 60*1024) // allocat 60*1K*4bytes = 240 KiB
  memoryLeaks = append(memoryLeaks, leak)
 }

    runtime.GC()
    ......

這個時候查看 heap profile，你會發現 heap profile 和runtime.MemStats統計的內存分配情況不一樣，因爲 runtime.MemStats 是實時統計的，而 heap profile 是採樣統計的。

可以看到 234 MiB 和 230.36 是不一致的。

如果在程序一開始加上 runtime.MemProfileRate = 1, heap profle 數據變成了 234MB, 有一致了。 

但是也需要注意，將 runtime.MemProfileRate 設置爲 1，對每一次內存都進行採樣統計，對性能的影響也相應的增大了，非必要不用更改這個值。

所以，我們默認看到 heap profile, 都是在默認值 512 * 1024 這個閾值下采樣統計的，和實際的 heap 上的內存分配可能會有些出入，但是對於我們分析內存泄露，影響不大。

參考資料

[1]

Hi, 使用多年的 go pprof 檢查內存泄漏的方法居然是錯的?! : https://colobu.com/2019/08/20/use-pprof-to-compare-go-memory-usage/

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/TlYXFXid5JVxUNAWsugnwQ