golang 記憶體分析/動態追蹤

21天精品區塊鏈課程免費學習，深入實戰行家帶路，助力開發人員輕鬆玩轉區塊鏈！>>>   

golang pprof

 

當你的golang程式在運行過程中消耗了超出你理解的記憶體時，你就需要搞明白，到底是 程式中哪些代碼導致了這些記憶體消耗。此時golang編譯好的程式對你來說是個黑盒，該 如何搞清其中的記憶體使用量呢？幸好golang已經內建了一些機制來協助我們進行分析和追 蹤。

此時，通常我們可以採用golang的pprof來協助我們分析golang進程的記憶體使用量。

pprof 執行個體

通常我們採用http api來將pprof資訊暴露出來以供分析，我們可以採用net/http/pprof 這個package。下面是一個簡單的樣本：

// pprof 的init函數會將pprof裡的一些handler註冊到http.DefaultServeMux上// 當不使用http.DefaultServeMux來提供http api時，可以查閱其init函數，自己註冊handlerimport _ "net/http/pprof"go func() {    http.ListenAndServe("0.0.0.0:8080", nil)}()

此時我們可以啟動進程，然後訪問http://localhost:8080/debug/pprof/可以看到一個簡單的 頁面，頁面上顯示: 注意: 以下的全部資料，包括go tool pprof 採集到的資料都依賴進程中的pprof採樣率，預設512kb進行 一次採樣，當我們認為資料不夠細緻時，可以調節採樣率runtime.MemProfileRate，但是採樣率越低，進 程運行速度越慢。

/debug/pprof/profiles:0         block136840    goroutine902       heap0         mutex40        threadcreatefull goroutine stack dump

上面簡單暴露出了幾個內建的Profile統計項。例如有136840個goroutine在運行，點擊相關連結 可以看到詳細資料。

當我們分析記憶體相關的問題時，可以點擊heap項，進入http://127.0.0.1:8080/debug/pprof/heap?debug=1 可以查看具體的顯示：

heap profile: 3190: 77516056 [54762: 612664248] @ heap/10485761: 29081600 [1: 29081600] @ 0x89368e 0x894cd9 0x8a5a9d 0x8a9b7c 0x8af578 0x8b4441 0x8b4c6d 0x8b8504 0x8b2bc3 0x45b1c1#    0x89368d    github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Put+0x59d#    0x894cd8    xxxxx/storage/internal/memtable.(*MemTable).Set+0x88#    0x8a5a9c    xxxxx/storage.(*snapshotter).AppendCommitLog+0x1cc#    0x8a9b7b    xxxxx/storage.(*store).Update+0x26b#    0x8af577    xxxxx/config.(*config).Update+0xa7#    0x8b4440    xxxxx/naming.(*naming).update+0x120#    0x8b4c6c    xxxxx/naming.(*naming).instanceTimeout+0x27c#    0x8b8503    xxxxx/naming.(*naming).(xxxxx/naming.instanceTimeout)-fm+0x63......# runtime.MemStats# Alloc = 2463648064# TotalAlloc = 31707239480# Sys = 4831318840# Lookups = 2690464# Mallocs = 274619648# Frees = 262711312# HeapAlloc = 2463648064# HeapSys = 3877830656# HeapIdle = 854990848# HeapInuse = 3022839808# HeapReleased = 0# HeapObjects = 11908336# Stack = 655949824 / 655949824# MSpan = 63329432 / 72040448# MCache = 38400 / 49152# BuckHashSys = 1706593# GCSys = 170819584# OtherSys = 52922583# NextGC = 3570699312# PauseNs = [1052815 217503 208124 233034 1146462 456882 1098525 530706 551702 419372 768322 596273 387826 455807 563621 587849 416204 599143 572823 488681 701731 656358 2476770 12141392 5827253 3508261 1715582 1295487 908563 788435 718700 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]# NumGC = 31# DebugGC = false

其中顯示的內容會比較多，但是主體分為2個部分: 第一個部分列印為通過runtime.MemProfile()擷取的runtime.MemProfileRecord記錄。 其含義為：

heap profile: 3190(inused objects): 77516056(inused bytes) [54762(alloc objects): 612664248(alloc bytes)] @ heap/1048576(2*MemProfileRate)1: 29081600 [1: 29081600] (前面4個數跟第一行的一樣，此行以後是每次記錄的，後面的地址是記錄中的棧指標)@ 0x89368e 0x894cd9 0x8a5a9d 0x8a9b7c 0x8af578 0x8b4441 0x8b4c6d 0x8b8504 0x8b2bc3 0x45b1c1#    0x89368d    github.com/syndtr/goleveldb/leveldb/memdb.(*DB).Put+0x59d 棧資訊

第二部分就比較好理解，列印的是通過runtime.ReadMemStats()讀取的runtime.MemStats資訊。 我們可以重點關注一下

• Sys 進程從系統獲得的記憶體空間，虛擬位址空間。
• HeapAlloc 進程堆記憶體配置使用的空間，通常是使用者new出來的堆對象，包含未被gc掉的。
• HeapSys 進程從系統獲得的堆記憶體，因為golang底層使用TCmalloc機制，會緩衝一部分堆記憶體，虛擬位址空間。
• PauseNs 記錄每次gc暫停時間(納秒)，最多記錄256個最新記錄。
• NumGC 記錄gc發生的次數。

相信，對pprof不瞭解的使用者看了以上內容，很難獲得更多的有用資訊。因此我們需要引用更多工具來協助 我們更加簡單的解讀pprof內容。

go tool

我們可以採用go tool pprof -inuse_space http://127.0.0.1:8080/debug/pprof/heap命令串連到進程中 查看正在使用的一些記憶體相關資訊，此時我們得到一個可以互動的命令列。

我們可以看資料top10來查看正在使用的對象較多的10個函數入口。通常用來檢測有沒有不符合預期的記憶體 對象引用。

(pprof) top101355.47MB of 1436.26MB total (94.38%)Dropped 371 nodes (cum <= 7.18MB)Showing top 10 nodes out of 61 (cum >= 23.50MB)      flat  flat%   sum%        cum   cum%  512.96MB 35.71% 35.71%   512.96MB 35.71%  net/http.newBufioWriterSize  503.93MB 35.09% 70.80%   503.93MB 35.09%  net/http.newBufioReader  113.04MB  7.87% 78.67%   113.04MB  7.87%  runtime.rawstringtmp   55.02MB  3.83% 82.50%    55.02MB  3.83%  runtime.malg   45.01MB  3.13% 85.64%    45.01MB  3.13%  xxxxx/storage.(*Node).clone   26.50MB  1.85% 87.48%    52.50MB  3.66%  context.WithCancel   25.50MB  1.78% 89.26%    83.58MB  5.82%  runtime.systemstack   25.01MB  1.74% 91.00%    58.51MB  4.07%  net/http.readRequest      25MB  1.74% 92.74%    29.03MB  2.02%  runtime.mapassign   23.50MB  1.64% 94.38%    23.50MB  1.64%  net/http.(*Server).newConn

然後我們在用go tool pprof -alloc_space http://127.0.0.1:8080/debug/pprof/heap命令連結程式來查看 記憶體對象分配的相關情況。然後輸入top來查看累積分配記憶體較多的一些函數調用:

(pprof) top523.38GB of 650.90GB total (80.41%)Dropped 342 nodes (cum <= 3.25GB)Showing top 10 nodes out of 106 (cum >= 28.02GB)      flat  flat%   sum%        cum   cum%  147.59GB 22.68% 22.68%   147.59GB 22.68%  runtime.rawstringtmp  129.23GB 19.85% 42.53%   129.24GB 19.86%  runtime.mapassign   48.23GB  7.41% 49.94%    48.23GB  7.41%  bytes.makeSlice   46.25GB  7.11% 57.05%    71.06GB 10.92%  encoding/json.Unmarshal   31.41GB  4.83% 61.87%   113.86GB 17.49%  net/http.readRequest   30.55GB  4.69% 66.57%   171.20GB 26.30%  net/http.(*conn).readRequest   22.95GB  3.53% 70.09%    22.95GB  3.53%  net/url.parse   22.70GB  3.49% 73.58%    22.70GB  3.49%  runtime.stringtoslicebyte   22.70GB  3.49% 77.07%    22.70GB  3.49%  runtime.makemap   21.75GB  3.34% 80.41%    28.02GB  4.31%  context.WithCancel

可以看出string-[]byte相互轉換、分配map、bytes.makeSlice、encoding/json.Unmarshal等調用累積分配的記憶體較多。 此時我們就可以review代碼，如何減少這些相關的調用，或者最佳化相關代碼邏輯。

當我們不明確這些調用時是被哪些函數引起的時，我們可以輸入top -cum來尋找，-cum的意思就是，將函數調用關係 中的資料進行累積，比如A函數調用的B函數，則B函數中的記憶體配置量也會累積到A上面，這樣就可以很容易的找出調用鏈。

(pprof) top20 -cum322890.40MB of 666518.53MB total (48.44%)Dropped 342 nodes (cum <= 3332.59MB)Showing top 20 nodes out of 106 (cum >= 122316.23MB)      flat  flat%   sum%        cum   cum%         0     0%     0% 643525.16MB 96.55%  runtime.goexit 2184.63MB  0.33%  0.33% 620745.26MB 93.13%  net/http.(*conn).serve         0     0%  0.33% 435300.50MB 65.31%  xxxxx/api/server.(*HTTPServer).ServeHTTP 5865.22MB  0.88%  1.21% 435300.50MB 65.31%  xxxxx/api/server/router.(*httpRouter).ServeHTTP         0     0%  1.21% 433121.39MB 64.98%  net/http.serverHandler.ServeHTTP         0     0%  1.21% 430456.29MB 64.58%  xxxxx/api/server/filter.(*chain).Next   43.50MB 0.0065%  1.21% 429469.71MB 64.43%  xxxxx/api/server/filter.TransURLTov1         0     0%  1.21% 346440.39MB 51.98%  xxxxx/api/server/filter.Role30x31283.56MB  4.69%  5.91% 175309.48MB 26.30%  net/http.(*conn).readRequest         0     0%  5.91% 153589.85MB 23.04%  github.com/julienschmidt/httprouter.(*Router).ServeHTTP         0     0%  5.91% 153589.85MB 23.04%  github.com/julienschmidt/httprouter.(*Router).ServeHTTP-fm         0     0%  5.91% 153540.85MB 23.04%  xxxxx/api/server/router.(*httpRouter).Register.func1       2MB 0.0003%  5.91% 153117.78MB 22.97%  xxxxx/api/server/filter.Validate151134.52MB 22.68% 28.58% 151135.02MB 22.68%  runtime.rawstringtmp         0     0% 28.58% 150714.90MB 22.61%  xxxxx/api/server/router/naming/v1.(*serviceRouter).(git.intra.weibo.com/platform/vintage/api/server/router/naming/v1.service)-fm         0     0% 28.58% 150714.90MB 22.61%  xxxxx/api/server/router/naming/v1.(*serviceRouter).service         0     0% 28.58% 141200.76MB 21.18%  net/http.Redirect132334.96MB 19.85% 48.44% 132342.95MB 19.86%  runtime.mapassign      42MB 0.0063% 48.44% 125834.16MB 18.88%  xxxxx/api/server/router/naming/v1.heartbeat         0     0% 48.44% 122316.23MB 18.35%  xxxxxx/config.(*config).Lookup

如上所示，我們就很容易的尋找到這些函數是被哪些函數調用的。

根據代碼的調用關係，filter.TransURLTov1會調用filter.Role30x，但是他們之間的cum%差值有12.45%，因此 我們可以得知filter.TransURLTov1內部自己直接分配的記憶體量達到了整個進程分配記憶體總量的12.45%，這可是一個 值得大大最佳化的地方。

然後我們可以輸入命令web，其會給我們的瀏覽器彈出一個.svg圖片，其會把這些累積關係畫成一個拓撲圖，提供給 我們。或者直接執行go tool pprof -alloc_space -cum -svg http://127.0.0.1:8080/debug/pprof/heap > heap.svg來生 成heap.svg圖片。

下面我們取一個圖片中的一個片段進行分析:

每一個方塊為pprof記錄的一個函數調用棧，指向方塊的箭頭上的數字是記錄的該棧累積分配的記憶體向，從方塊指出的 箭頭上的數字為該函數調用的其他函數累積分配的記憶體。他們之間的差值可以簡單理解為本函數除調用其他函數外，自 身分配的。方塊內部的數字也體現了這一點，其數字為:(自身分配的記憶體 of 該函數累積分配的記憶體)。

--inuse/alloc_space --inuse/alloc_objects區別

通常情況下：

• 用--inuse_space來剖析器常駐記憶體的佔用情況;
• 用--alloc_objects來分析記憶體的臨時分配情況，可以提高程式的運行速度。

go-torch

除了直接使用go tool pprof外，我們還可以使用更加直觀了火焰圖 。因此我們可以直接使用go-torch來產生golang程式的火焰圖，該工具也直接 依賴pprof/go tool pprof等。該工具的相關安裝請看該項目的介紹。該軟體的a4daa2b 以後版本才支援記憶體的profiling。

我們可以使用

go-torch -alloc_space http://127.0.0.1:8080/debug/pprof/heap --colors=memgo-torch -inuse_space http://127.0.0.1:8080/debug/pprof/heap --colors=mem

注意:-alloc_space/-inuse_space參數與-u/-b等參數有衝突，使用了-alloc_space/-inuse_space後請將pprof的 資源直接追加在參數後面，而不要使用-u/-b參數去指定，這與go-torch的參數解析問題有關，看過其源碼後既能明白。 同時還要注意，分析記憶體的URL一定是heap結尾的，因為預設路徑是profile的，其用來分析cpu相關問題。

通過上面2個命令，我們就可以得到alloc_space/inuse_space含義的2個火焰圖，例如 alloc_space.svg/inuse_space.svg。 我們可以使用瀏覽器觀察這2張圖，這張圖，就像一個山脈的截面圖，從下而上是每個函數的調用棧，因此山的高度跟函數 調用的深度正相關，而山的寬度跟使用/分配記憶體的數量成正比。我們只需要留意那些寬而平的山頂，這些部分通常是我們 需要最佳化的地方。

testing

當我們需要對go test中某些test/benchmark進行profiling時，我們可以使用類似的方法。例如我們可以先使用go test 內建的參數產生pprof資料，然後藉助go tool pprof/go-torch來分析。

1. 產生cpu、mem的pprof檔案

   go test -bench=BenchmarkStorageXXX -cpuprofile cpu.out -memprofile mem.out

2. 此時會產生一個二進位檔案和2個pprof資料檔案，例如

   storage.test cpu.out mem.out

3. 然後使用go-torch來分析，二進位檔案放前面

   #分析cpugo-torch storage.test cpu.out#分析記憶體go-torch --colors=mem -alloc_space storage.test mem.outgo-torch --colors=mem -inuse_space storage.test mem.out

最佳化建議

Debugging performance issues in Go programs 提供了一些常用的最佳化建議:

1 將多個小對象合并成一個大的對象

2 減少不必要的指標間接引用，多使用copy引用

例如使用bytes.Buffer代替*bytes.Buffer，因為使用指標時，會分配2個對象來完成引用。

3 局部變數逃逸時，將其彙總起來

這一點理論跟1相同，核心在於減少object的分配，減少gc的壓力。 例如，以下代碼

for k, v := range m {k, v := k, v   // copy for capturing by the goroutinego func() {// use k and v}()}

可以修改為:

for k, v := range m {x := struct{ k, v string }{k, v}   // copy for capturing by the goroutinego func() {// use x.k and x.v}()}

修改後，逃逸的對象變為了x，將k，v2個對象減少為1個對象。

4 []byte的預分配

當我們比較清楚的知道[]byte會到底使用多少位元組，我們就可以採用一個數組來預分配這段記憶體。 例如:

type X struct {    buf      []byte    bufArray [16]byte // Buf usually does not grow beyond 16 bytes.}func MakeX() *X {    x := &X{}    // Preinitialize buf with the backing array.    x.buf = x.bufArray[:0]    return x}

5 儘可能使用位元組數少的類型

當我們的一些const或者計數欄位不需要太大的位元組數時，我們通常可以將其聲明為int8類型。

6 減少不必要的指標引用

當一個對象不包含任何指標（注意：strings，slices，maps 和chans包含隱含的指標），時，對gc的掃描影響很小。 比如，1GB byte 的slice事實上只包含有限的幾個object，不會影響垃圾收集時間。 因此，我們可以儘可能的減少指標的引用。

7 使用sync.Pool來緩衝常用的對象

注意

go1.9、go1.9.2之間的版本go tool pprof引入了一個BUG，會導致上面的記憶體分析命令失敗。 下面給出一種修複辦法：

cd $GOROOT/src/cmd/vendor/github.com/googlerm pprofgit clone https://github.com/google/pprof.git #確保在版本`e82ee9addc1b6c8e1d667ed6de0194241e1e03b5`之後rm $GOROOT/pkg/darwin_amd64/cmd/vendor/github.com/google/pprofcd $GOROOT/src/cmd/pprofgo buildmv pprof $GOROOT/pkg/tool/darwin_amd64/pprof