Go Heap Profile 怎么了？

Go heap profile 是常常用來檢查內(nèi)存泄露和內(nèi)存占用大問題的問題的手段，而且非常常用。

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

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

問題: heap profile 不能正確反應(yīng)當(dāng)前分配的內(nèi)存?

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

package main

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

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

 go func() {
  // 每秒打印內(nèi)存分配情況
  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")

 // 創(chuàng)建一個 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) // 延遲一秒觀察內(nèi)存分配情況
 }
 // 期望至少分配了 200 MiB 內(nèi)存
 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]) // 避免垃圾回收和優(yōu)化

}

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

這個程序首先創(chuàng)建一個監(jiān)聽 8080 端口的 web 服務(wù)，主要利用它訪問 http heap profile，所以你看導(dǎo)入了 _ "net/http/pprof" 包。

然后創(chuàng)建了了一個切片，切片包含 10 個元素，每個元素又是一個 []int32 的切片。每個元素占用 20 MiB 的大小 (int32 是 4 個字節(jié)，5*1024*1024 是 5 M, 所以是 4*5 MiB=20 Mib)。

所以我們期望 10 個循環(huán)創(chuàng)建完畢后，至少此程序會占用 200 MiB 內(nèi)存，另外在加一些棧、網(wǎng)絡(luò)、運(yùn)行時等一些額外的內(nèi)存的話，略微會比 200MiB 大一些。

運(yùn)行這個程序，我們看程序每秒的內(nèi)存占用統(tǒng)計：

可以看到使用 runtime.MemStats 統(tǒng)計的內(nèi)存分配情況還是比較準(zhǔn)的， 200MiB，符合預(yù)期。

當(dāng)你看到 end test 時，表明 200MiB 已經(jīng)分配，你可以運(yùn)行下面的命令打開 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 的內(nèi)存？少了 40 MB。和期望的不符。

這 160 MB 內(nèi)存的確是在創(chuàng)建元素的時候分配的：

可那 40 MB 呢？如果 Heap Profile 數(shù)據(jù)不準(zhǔn)，可就動搖了我們一直以來分析內(nèi)存泄露的技術(shù)基礎(chǔ)？

那肯定不會是 Go 實現(xiàn)的問題，否則這個問題早就被暴露和修復(fù)了。

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

把 40 MiB 的分配的內(nèi)存找回來

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

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

這個時候瀏覽器中顯示出了 200 MB 的內(nèi)存分配，符合預(yù)期了：

神奇啊，等待一段時間之后，heap profile 就顯示正常了。難道過了一會才分配的內(nèi)存？那不可能。因為命令行中 runtime.MemStats 已經(jīng)顯示結(jié)束測試前內(nèi)存已經(jīng)分配好了。

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

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

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

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

沒關(guān)系，訪問 heap profile 我們加上 gc=1 的參數(shù)即可 (大于 0 的數(shù)都可以)：

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

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

“

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

為啥?

Heap profile 其實調(diào)用的 `runtime.MemProfile 進(jìn)行統(tǒng)計:

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 的方法簽名如下，它負(fù)責(zé)統(tǒng)計內(nèi)存的分配情況：

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.

翻譯過來：

“

返回的性能分析數(shù)據(jù)可能最多延遲兩個垃圾回收周期。這樣做是為了避免對內(nèi)存分配產(chǎn)生偏差;因為內(nèi)存分配是實時發(fā)生的,但釋放操作直到垃圾回收器進(jìn)行清理時才會延遲進(jìn)行,所以性能分析只會統(tǒng)計那些已經(jīng)有機(jī)會被垃圾回收器回收的內(nèi)存分配。

所以才會重現(xiàn)一開始的問題。我們看到 end test 立即查看 heap profile, 還沒有進(jìn)行垃圾回收，相關(guān)的內(nèi)存統(tǒng)計數(shù)據(jù)還沒有計算出來，所以才看到 160 MB 的內(nèi)存，而不是 200MB 的內(nèi)存。

system.GC會強(qiáng)制進(jìn)行垃圾回收，并且會發(fā)布新的 heap profile，所以可以看到 200MB 的內(nèi)存。

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)
}

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

現(xiàn)在讓我們來看第二個知識點。

Heap Profile 是采樣的？采啥樣？

heap profile 實際上在內(nèi)存分配時做采樣統(tǒng)計的，默認(rèn)情況下并不會記錄所有的內(nèi)存分配。

這里我們需要關(guān)注 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 控制了在內(nèi)存分析中記錄和報告的內(nèi)存分配的比例。分析器的目標(biāo)是每分配 MemProfileRate 字節(jié)時,采樣記錄一次分配。

如果要在分析中包含每一個分配的內(nèi)存塊,可以將 MemProfileRate 設(shè)置為 1。如果要完全關(guān)閉內(nèi)存分析,可以將 MemProfileRate 設(shè)置為 0。

處理內(nèi)存分析數(shù)據(jù)的工具假設(shè)分析的采樣率在程序的整個生命周期中保持不變,并等于當(dāng)前設(shè)置的值。如果程序需要改變內(nèi)存分析的采樣率,應(yīng)該只改變一次,并且盡可能早地在程序執(zhí)行的開始階段(例如在 main 函數(shù)的開始部分)進(jìn)行設(shè)置。

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

    ......
 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，你會發(fā)現(xiàn) heap profile 和runtime.MemStats統(tǒng)計的內(nèi)存分配情況不一樣，因為 runtime.MemStats 是實時統(tǒng)計的，而 heap profile 是采樣統(tǒng)計的。

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

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

但是也需要注意，將 runtime.MemProfileRate 設(shè)置為 1，對每一次內(nèi)存都進(jìn)行采樣統(tǒng)計，對性能的影響也相應(yīng)的增大了，非必要不用更改這個值。

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

想要了解Go更多內(nèi)容，歡迎掃描下方??關(guān)注公眾號，掃描 [實戰(zhàn)群]二維碼  ,即可進(jìn)群和我們交流~