實戰Go記憶體洩露

大彬發表於2019-05-18
Go記憶體洩露

最近解決了我們專案中的一個記憶體洩露問題，事實再次證明pprof是一個好工具，但掌握好工具的正確用法，才能發揮好工具的威力，不然就算你手裡有屠龍刀，也成不了天下第一，本文就是帶你用pprof定位記憶體洩露問題。

關於Go的記憶體洩露有這麼一句話不知道你聽過沒有：

10次記憶體洩露，有9次是goroutine洩露。

我所解決的問題，也是goroutine洩露導致的記憶體洩露，所以這篇文章主要介紹Go程式的goroutine洩露，掌握瞭如何定位和解決goroutine洩露，就掌握了記憶體洩露的大部分場景。

本文草稿最初資料都是生產壞境資料，為了防止敏感內容洩露，全部替換成了demo資料，demo的資料比生產環境資料簡單多了，更適合入門理解，有助於掌握pprof。

go pprof基本知識

定位goroutine洩露會使用到pprof，pprof是Go的效能工具，在開始介紹記憶體洩露前，先簡單介紹下pprof的基本使用，更詳細的使用給大家推薦了資料。

什麼是pprof

pprof是Go的效能分析工具，在程式執行過程中，可以記錄程式的執行資訊，可以是CPU使用情況、記憶體使用情況、goroutine執行情況等，當需要效能調優或者定位Bug時候，這些記錄的資訊是相當重要。

基本使用

使用pprof有多種方式，Go已經現成封裝好了1個：net/http/pprof，使用簡單的幾行命令，就可以開啟pprof，記錄執行資訊，並且提供了Web服務，能夠通過瀏覽器和命令列2種方式獲取執行資料。

看個最簡單的pprof的例子：

檔案：golang_step_by_step/pprof/pprof/demo.go

package main

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

func main() {
    // 開啟pprof，監聽請求
    ip := "0.0.0.0:6060"
    if err := http.ListenAndServe(ip, nil); err != nil {
        fmt.Printf("start pprof failed on %s\n", ip)
    }
}

提醒：本文所有程式碼部分可左右滑動

瀏覽器方式

image-20190516173924325

輸入網址ip:port/debug/pprof/開啟pprof主頁，從上到下依次是5類profile資訊：

  1. block：goroutine的阻塞資訊，本例就擷取自一個goroutine阻塞的demo，但block為0，沒掌握block的用法
  2. goroutine：所有goroutine的資訊，下面的full goroutine stack dump是輸出所有goroutine的呼叫棧，是goroutine的debug=2，後面會詳細介紹。
  3. heap：堆記憶體的資訊
  4. mutex：鎖的資訊
  5. threadcreate：執行緒資訊

這篇文章我們主要關注goroutine和heap，這兩個都會列印呼叫棧資訊，goroutine裡面還會包含goroutine的數量資訊，heap則是記憶體分配資訊，本文用不到的地方就不展示了，最後推薦幾篇文章大家去看。

命令列方式

當連線在伺服器終端上的時候，是沒有瀏覽器可以使用的，Go提供了命令列的方式，能夠獲取以上5類資訊，這種方式用起來更方便。

使用命令go tool pprof url可以獲取指定的profile檔案，此命令會發起http請求，然後下載資料到本地，之後進入互動式模式，就像gdb一樣，可以使用命令檢視執行資訊，以下是5類請求的方式：

# 下載cpu profile，預設從當前開始收集30s的cpu使用情況，需要等待30s
go tool pprof http://localhost:6060/debug/pprof/profile   # 30-second CPU profile
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=120     # wait 120s

# 下載heap profile
go tool pprof http://localhost:6060/debug/pprof/heap      # heap profile

# 下載goroutine profile
go tool pprof http://localhost:6060/debug/pprof/goroutine # goroutine profile

# 下載block profile
go tool pprof http://localhost:6060/debug/pprof/block     # goroutine blocking profile

# 下載mutex profile
go tool pprof http://localhost:6060/debug/pprof/mutex

上面的pprof/demo.go太簡單了，如果去獲取記憶體profile，幾乎獲取不到什麼，換一個Demo進行記憶體profile的展示：

檔案：golang_step_by_step/pprof/heap/demo2.go

// 展示記憶體增長和pprof，並不是洩露
package main

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

// 執行一段時間：fatal error: runtime: out of memory
func main() {
    // 開啟pprof
    go func() {
        ip := "0.0.0.0:6060"
        if err := http.ListenAndServe(ip, nil); err != nil {
            fmt.Printf("start pprof failed on %s\n", ip)
            os.Exit(1)
        }
    }()

    tick := time.Tick(time.Second / 100)
    var buf []byte
    for range tick {
        buf = append(buf, make([]byte, 1024*1024)...)
    }
}

上面這個demo會不斷的申請記憶體，把它編譯執行起來，然後執行：

$ go tool pprof http://localhost:6060/debug/pprof/heap

Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /home/ubuntu/pprof/pprof.demo.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz       //<--- 下載到的記憶體profile檔案
File: demo // 程式名稱
Build ID: a9069a125ee9c0df3713b2149ca859e8d4d11d5a
Type: inuse_space
Time: May 16, 2019 at 8:55pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
(pprof)
(pprof) help  // 使用help列印所有可用命令
  Commands:
    callgrind        Outputs a graph in callgrind format
    comments         Output all profile comments
    disasm           Output assembly listings annotated with samples
    dot              Outputs a graph in DOT format
    eog              Visualize graph through eog
    evince           Visualize graph through evince
    gif              Outputs a graph image in GIF format
    gv               Visualize graph through gv
    kcachegrind      Visualize report in KCachegrind
    list             Output annotated source for functions matching regexp
    pdf              Outputs a graph in PDF format
    peek             Output callers/callees of functions matching regexp
    png              Outputs a graph image in PNG format
    proto            Outputs the profile in compressed protobuf format
    ps               Outputs a graph in PS format
    raw              Outputs a text representation of the raw profile
    svg              Outputs a graph in SVG format
    tags             Outputs all tags in the profile
    text             Outputs top entries in text form
    top              Outputs top entries in text form
    topproto         Outputs top entries in compressed protobuf format
    traces           Outputs all profile samples in text form
    tree             Outputs a text rendering of call graph
    web              Visualize graph through web browser
    weblist          Display annotated source in a web browser
    o/options        List options and their current values
    quit/exit/^D     Exit pprof
    
    ....

以上資訊我們只關注2個地方：

  1. 下載得到的檔案：/home/ubuntu/pprof/pprof.demo.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz，這其中包含了程式名demo，profile型別alloc已分配的記憶體，inuse代表使用中的記憶體。
  2. help可以獲取幫助，最先會列出支援的命令，想掌握pprof，要多看看，多嘗試。

關於命令，本文只會用到3個，我認為也是最常用的：top、list、traces，分別介紹一下。

top

按指標大小列出前10個函式，比如記憶體是按記憶體佔用多少，CPU是按執行時間多少。

(pprof) top
Showing nodes accounting for 814.62MB, 100% of 814.62MB total
      flat  flat%   sum%        cum   cum%
  814.62MB   100%   100%   814.62MB   100%  main.main
         0     0%   100%   814.62MB   100%  runtime.main

top會列出5個統計資料：

  • flat: 本函式佔用的記憶體量。
  • flat%: 本函式記憶體佔使用中記憶體總量的百分比。
  • sum%: 前面每一行flat百分比的和，比如第2行雖然的100% 是 100% + 0%。
  • cum: 是累計量，加入main函式呼叫了函式f，函式f佔用的記憶體量，也會記進來。
  • cum%: 是累計量佔總量的百分比。

list

檢視某個函式的程式碼，以及該函式每行程式碼的指標資訊，如果函式名不明確，會進行模糊匹配，比如list main會列出main.main和runtime.main。

(pprof) list main.main  // 精確列出函式
Total: 814.62MB
ROUTINE ======================== main.main in /home/ubuntu/heap/demo2.go
  814.62MB   814.62MB (flat, cum)   100% of Total
         .          .     20:    }()
         .          .     21:
         .          .     22:    tick := time.Tick(time.Second / 100)
         .          .     23:    var buf []byte
         .          .     24:    for range tick {
  814.62MB   814.62MB     25:        buf = append(buf, make([]byte, 1024*1024)...)
         .          .     26:    }
         .          .     27:}
         .          .     28:
(pprof) list main  // 匹配所有函式名帶main的函式
Total: 814.62MB
ROUTINE ======================== main.main in /home/ubuntu/heap/demo2.go
  814.62MB   814.62MB (flat, cum)   100% of Total
         .          .     20:    }()
         .          .     21:
..... // 省略幾行
         .          .     28:
ROUTINE ======================== runtime.main in /usr/lib/go-1.10/src/runtime/proc.go
         0   814.62MB (flat, cum)   100% of Total
         .          .    193:        // A program compiled with -buildmode=c-archive or c-shared
..... // 省略幾行

可以看到在main.main中的第25行佔用了814.62MB記憶體，左右2個資料分別是flat和cum，含義和top中解釋的一樣。

traces

列印所有呼叫棧，以及呼叫棧的指標資訊。

(pprof) traces
File: demo2
Type: inuse_space
Time: May 16, 2019 at 7:08pm (CST)
-----------+-------------------------------------------------------
     bytes:  813.46MB
  813.46MB   main.main
             runtime.main
-----------+-------------------------------------------------------
     bytes:  650.77MB
         0   main.main
             runtime.main
....... // 省略幾十行

每個- - - - - 隔開的是一個呼叫棧，能看到runtime.main呼叫了main.main，並且main.main中佔用了813.46MB記憶體。

其他的profile操作和記憶體是類似的，這裡就不展示了。

這裡只是簡單介紹本文用到的pprof的功能，pprof功能很強大，也經常和benchmark結合起來，但這不是本文的重點，所以就不多介紹了，為大家推薦幾篇文章，一定要好好研讀、實踐：

  1. Go官方部落格關於pprof的介紹，很詳細，也包含樣例，可以實操：Profiling Go Programs。
  2. 跟煎魚也討論過pprof，煎魚的這篇文章也很適合入門： Golang 大殺器之效能剖析 PProf。

什麼是記憶體洩露

記憶體洩露指的是程式執行過程中已不再使用的記憶體，沒有被釋放掉，導致這些記憶體無法被使用，直到程式結束這些記憶體才被釋放的問題。

Go雖然有GC來回收不再使用的堆記憶體，減輕了開發人員對記憶體的管理負擔，但這並不意味著Go程式不再有記憶體洩露問題。在Go程式中，如果沒有Go語言的程式設計思維，也不遵守良好的程式設計實踐，就可能埋下隱患，造成記憶體洩露問題。

怎麼發現記憶體洩露

在Go中發現記憶體洩露有2種方法，一個是通用的監控工具，另一個是go pprof：

  1. 監控工具：固定週期對程式的記憶體佔用情況進行取樣，資料視覺化後，根據記憶體佔用走勢（持續上升），很容易發現是否發生記憶體洩露。
  2. go pprof：適合沒有監控工具的情況，使用Go提供的pprof工具判斷是否發生記憶體洩露。

這2種方式分別介紹一下。

監控工具檢視程式內在佔用情況

如果使用雲平臺部署Go程式，雲平臺都提供了記憶體檢視的工具，可以檢視OS的記憶體佔用情況和某個程式的記憶體佔用情況，比如阿里雲，我們在1個雲主機上只部署了1個Go服務，所以OS的記憶體佔用情況，基本是也反映了程式記憶體佔用情況，OS記憶體佔用情況如下，可以看到隨著時間的推進，記憶體的佔用率在不斷的提高，這是記憶體洩露的最明顯現象：

image-20190512111200988

如果沒有云平臺這種記憶體監控工具，可以製作一個簡單的記憶體記錄工具。

1、建立一個指令碼prog_mem.sh，獲取程式佔用的實體記憶體情況，指令碼內容如下：

#!/bin/bash
prog_name="your_programe_name"
prog_mem=$(pidstat  -r -u -h -C $prog_name |awk 'NR==4{print $12}')
time=$(date "+%Y-%m-%d %H:%M:%S")
echo $time"\tmemory(Byte)\t"$prog_mem >>~/record/prog_mem.log

2、然後使用crontab建立定時任務，每分鐘記錄1次。使用crontab -e編輯crontab配置，在最後增加1行：

*/1 * * * * ~/record/prog_mem.sh

指令碼輸出的內容儲存在prog_mem.log，只要大體瀏覽一下就可以發現記憶體的增長情況，判斷是否存在記憶體洩露。如果需要視覺化，可以直接黏貼prog_mem.log內容到Excel等表格工具，繪製記憶體佔用圖。

image-20190512172935195

go pprof發現存在記憶體問題

有情提醒：如果對pprof不瞭解，可以先看go pprof基本知識，這是下一節，看完再倒回來看。

如果你Google或者百度，Go程式記憶體洩露的文章，它總會告訴你使用pprof heap，能夠生成漂亮的呼叫路徑圖，火焰圖等等，然後你根據呼叫路徑就能定位記憶體洩露問題，我最初也是對此深信不疑，嘗試了若干天后，只是發現記憶體洩露跟某種場景有關，根本找不到記憶體洩露的根源，如果哪位朋友用heap就能定位記憶體洩露的線上問題，麻煩介紹下。

後來讀了Dave的《High Performance Go Workshop》，重新整理了對heap的認識，記憶體pprof的簡要內容如下：

image-20190512114048868

Dave講了以下幾點：

  1. 記憶體profiling記錄的是堆記憶體分配的情況，以及呼叫棧資訊，並不是程式完整的記憶體情況，猜測這也是在go pprof中稱為heap而不是memory的原因。
  2. 棧記憶體的分配是在呼叫棧結束後會被釋放的記憶體，所以並不在記憶體profile中。
  3. 記憶體profiling是基於抽樣的，預設是每1000次堆記憶體分配，執行1次profile記錄。
  4. 因為記憶體profiling是基於抽樣和它跟蹤的是已分配的記憶體，而不是使用中的記憶體，（比如有些記憶體已經分配，看似使用，但實際以及不使用的記憶體，比如記憶體洩露的那部分），所以不能使用記憶體profiling衡量程式總體的記憶體使用情況。
  5. Dave個人觀點：使用記憶體profiling不能夠發現記憶體洩露。

基於目前對heap的認知，我有2個觀點：

  1. heap能幫助我們發現記憶體問題，但不一定能發現記憶體洩露問題，這個看法與Dave是類似的。heap記錄了記憶體分配的情況，我們能通過heap觀察記憶體的變化，增長與減少，記憶體主要被哪些程式碼佔用了，程式存在記憶體問題，這隻能說明記憶體有使用不合理的地方，但並不能說明這是記憶體洩露。
  2. heap在幫助定位記憶體洩露原因上貢獻的力量微乎其微。如第一條所言，能通過heap找到佔用記憶體多的位置，但這個位置通常不一定是記憶體洩露，就算是記憶體洩露，也只是記憶體洩露的結果，並不是真正導致記憶體洩露的根源。

接下來，我介紹怎麼用heap發現問題，然後再解釋為什麼heap幾乎不能定位記憶體洩露的根因。

怎麼用heap發現記憶體問題

使用pprof的heap能夠獲取程式執行時的記憶體資訊，在程式平穩執行的情況下，每個一段時間使用heap獲取記憶體的profile，然後使用base能夠對比兩個profile檔案的差別，就像diff命令一樣顯示出增加和減少的變化，使用一個簡單的demo來說明heap和base的使用，依然使用demo2進行展示。

檔案：golang_step_by_step/pprof/heap/demo2.go

// 展示記憶體增長和pprof，並不是洩露
package main

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

// 執行一段時間：fatal error: runtime: out of memory
func main() {
    // 開啟pprof
    go func() {
        ip := "0.0.0.0:6060"
        if err := http.ListenAndServe(ip, nil); err != nil {
            fmt.Printf("start pprof failed on %s\n", ip)
            os.Exit(1)
        }
    }()

    tick := time.Tick(time.Second / 100)
    var buf []byte
    for range tick {
        buf = append(buf, make([]byte, 1024*1024)...)
    }
}

將上面程式碼執行起來，執行以下命令獲取profile檔案，Ctrl-D退出，1分鐘後再獲取1次。

go tool pprof http://localhost:6060/debug/pprof/heap

我已經獲取到了兩個profile檔案：

$ ls
pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz
pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz

使用base把001檔案作為基準，然後用002和001對比，先執行top看top的對比，然後執行list main列出main函式的記憶體對比，結果如下：

$ go tool pprof -base pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz pprof.demo2.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz

File: demo2
Type: inuse_space
Time: May 14, 2019 at 2:33pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
(pprof)
(pprof) top
Showing nodes accounting for 970.34MB, 32.30% of 3003.99MB total
      flat  flat%   sum%        cum   cum%
  970.34MB 32.30% 32.30%   970.34MB 32.30%  main.main   // 看這
         0     0% 32.30%   970.34MB 32.30%  runtime.main
(pprof)
(pprof)
(pprof) list main.main
Total: 2.93GB
ROUTINE ======================== main.main in /home/ubuntu/heap/demo2.go
  970.34MB   970.34MB (flat, cum) 32.30% of Total
         .          .     20:    }()
         .          .     21:
         .          .     22:    tick := time.Tick(time.Second / 100)
         .          .     23:    var buf []byte
         .          .     24:    for range tick {
  970.34MB   970.34MB     25:        buf = append(buf, make([]byte, 1024*1024)...) // 看這
         .          .     26:    }
         .          .     27:}
         .          .     28:

top列出了main.main和runtime.main，main.main就是我們編寫的main函式，runtime.main是runtime包中的main函式，也就是所有main函式的入口，這裡不多介紹了，有興趣可以看之前的排程器文章《Go排程器系列（2）巨集觀看排程器》。

top顯示main.main 第2次記憶體佔用，比第1次記憶體佔用多了970.34MB。

list main.main告訴了我們增長的記憶體都在這一行：

buf = append(buf, make([]byte, 1024*1024)...)

001和002 profile的檔案不進去看了，你本地測試下計算差值，絕對是剛才對比出的970.34MB。

heap“不能”定位記憶體洩露

heap能顯示記憶體的分配情況，以及哪行程式碼佔用了多少記憶體，我們能輕易的找到佔用記憶體最多的地方，如果這個地方的數值還在不斷怎大，基本可以認定這裡就是記憶體洩露的位置。

曾想按圖索驥，從記憶體洩露的位置，根據呼叫棧向上查詢，總能找到記憶體洩露的原因，這種方案看起來是不錯的，但實施起來卻找不到記憶體洩露的原因，結果是事半功倍。

原因在於一個Go程式，其中有大量的goroutine，這其中的呼叫關係也許有點複雜，也許記憶體洩露是在某個三方包裡。舉個例子，比如下面這幅圖，每個橢圓代表1個goroutine，其中的數字為編號，箭頭代表呼叫關係。heap profile顯示g111（最下方標紅節點）這個協程的程式碼出現了洩露，任何一個從g101到g111的呼叫路徑都可能造成了g111的記憶體洩露，有2類可能：

  1. 該goroutine只呼叫了少數幾次，但消耗了大量的記憶體，說明每個goroutine呼叫都消耗了不少記憶體，記憶體洩露的原因基本就在該協程內部。
  2. 該goroutine的呼叫次數非常多，雖然每個協程呼叫過程中消耗的記憶體不多，但該呼叫路徑上，協程數量巨大，造成消耗大量的記憶體，並且這些goroutine由於某種原因無法退出，佔用的記憶體不會釋放，記憶體洩露的原因在到g111呼叫路徑上某段程式碼實現有問題，造成建立了大量的g111。

第2種情況，就是goroutine洩露，這是通過heap無法發現的，所以heap在定位記憶體洩露這件事上，發揮的作用不大。

image-20190512144150064

goroutine洩露怎麼導致記憶體洩露

什麼是goroutine洩露

如果你啟動了1個goroutine，但並沒有符合預期的退出，直到程式結束，此goroutine才退出，這種情況就是goroutine洩露。

提前思考：什麼會導致goroutine無法退出/阻塞？

goroutine洩露怎麼導致記憶體洩露

每個goroutine佔用2KB記憶體，洩露1百萬goroutine至少洩露2KB * 1000000 = 2GB記憶體，為什麼說至少呢？

goroutine執行過程中還存在一些變數，如果這些變數指向堆記憶體中的記憶體，GC會認為這些記憶體仍在使用，不會對其進行回收，這些記憶體誰都無法使用，造成了記憶體洩露。

所以goroutine洩露有2種方式造成記憶體洩露：

  1. goroutine本身的棧所佔用的空間造成記憶體洩露。
  2. goroutine中的變數所佔用的堆記憶體導致堆記憶體洩露，這一部分是能通過heap profile體現出來的。

Dave在文章中也提到了，如果不知道何時停止一個goroutine，這個goroutine就是潛在的記憶體洩露：

7.1.1 Know when to stop a goroutine

If you don’t know the answer, that’s a potential memory leak as the goroutine will pin its stack’s memory on the heap, as well as any heap allocated variables reachable from the stack.

怎麼確定是goroutine洩露引發的記憶體洩露

掌握了前面的pprof命令列的基本用法，很快就可以確認是否是goroutine洩露導致記憶體洩露，如果你不記得了，馬上回去看一下go pprof基本知識。

判斷依據：在節點正常執行的情況下，隔一段時間獲取goroutine的數量，如果後面獲取的那次，某些goroutine比前一次多，如果多獲取幾次，是持續增長的，就極有可能是goroutine洩露。

goroutine導致記憶體洩露的demo：

檔案：golang_step_by_step/pprof/goroutine/leak_demo1.go

// goroutine洩露導致記憶體洩露
package main

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

func main() {
    // 開啟pprof
    go func() {
        ip := "0.0.0.0:6060"
        if err := http.ListenAndServe(ip, nil); err != nil {
            fmt.Printf("start pprof failed on %s\n", ip)
            os.Exit(1)
        }
    }()

    outCh := make(chan int)
    // 死程式碼，永不讀取
    go func() {
        if false {
            <-outCh
        }
        select {}
    }()

    // 每s起100個goroutine，goroutine會阻塞，不釋放記憶體
    tick := time.Tick(time.Second / 100)
    i := 0
    for range tick {
        i++
        fmt.Println(i)
        alloc1(outCh)
    }
}

func alloc1(outCh chan<- int) {
    go alloc2(outCh)
}

func alloc2(outCh chan<- int) {
    func() {
        defer fmt.Println("alloc-fm exit")
        // 分配記憶體，假用一下
        buf := make([]byte, 1024*1024*10)
        _ = len(buf)
        fmt.Println("alloc done")

        outCh <- 0 // 53行
    }()
}

編譯並執行以上程式碼，然後使用go tool pprof獲取gorourine的profile檔案。

go tool pprof http://localhost:6060/debug/pprof/goroutine

已經通過pprof命令獲取了2個goroutine的profile檔案:

$ ls
/home/ubuntu/pprof/pprof.leak_demo.goroutine.001.pb.gz
/home/ubuntu/pprof/pprof.leak_demo.goroutine.002.pb.gz

同heap一樣，我們可以使用base對比2個goroutine profile檔案：

$go tool pprof -base pprof.leak_demo.goroutine.001.pb.gz pprof.leak_demo.goroutine.002.pb.gz

File: leak_demo
Type: goroutine
Time: May 16, 2019 at 2:44pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
(pprof) top
Showing nodes accounting for 20312, 100% of 20312 total
      flat  flat%   sum%        cum   cum%
     20312   100%   100%      20312   100%  runtime.gopark
         0     0%   100%      20312   100%  main.alloc2
         0     0%   100%      20312   100%  main.alloc2.func1
         0     0%   100%      20312   100%  runtime.chansend
         0     0%   100%      20312   100%  runtime.chansend1
         0     0%   100%      20312   100%  runtime.goparkunlock
(pprof)

可以看到執行到runtime.gopark的goroutine數量增加了20312個。再通過002檔案，看一眼執行到gopark的goroutine數量，即掛起的goroutine數量：

go tool pprof pprof.leak_demo.goroutine.002.pb.gz
File: leak_demo
Type: goroutine
Time: May 16, 2019 at 2:47pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 24330, 100% of 24331 total
Dropped 32 nodes (cum <= 121)
      flat  flat%   sum%        cum   cum%
     24330   100%   100%      24330   100%  runtime.gopark
         0     0%   100%      24326   100%  main.alloc2
         0     0%   100%      24326   100%  main.alloc2.func1
         0     0%   100%      24326   100%  runtime.chansend
         0     0%   100%      24326   100%  runtime.chansend1
         0     0%   100%      24327   100%  runtime.goparkunlock

顯示有24330個goroutine被掛起，這不是goroutine洩露這是啥？已經能確定八九成goroutine洩露了。

是什麼導致如此多的goroutine被掛起而無法退出？接下來就看怎麼定位goroutine洩露。

定位goroutine洩露的2種方法

使用pprof有2種方式，一種是web網頁，一種是go tool pprof命令列互動，這兩種方法檢視goroutine都支援，但有輕微不同，也有各自的優缺點。

我們先看Web的方式，再看命令列互動的方式，這兩種都很好使用，結合起來用也不錯。

Web視覺化檢視

Web方式適合web伺服器的埠能訪問的情況，使用起來方便，有2種方式：

  1. 檢視某條呼叫路徑上，當前阻塞在此goroutine的數量
  2. 檢視所有goroutine的執行棧（呼叫路徑），可以顯示阻塞在此的時間

方式一

url請求中設定debug=1：

http://ip:port/debug/pprof/goroutine?debug=1

效果如下：

看起來密密麻麻的，其實簡單又十分有用，看上圖示出來的部分，手機上圖看起來可能不方便，那就放大圖片，或直接看下面各欄位的含義：

  1. goroutine profile: total 32023：32023是goroutine的總數量，
  2. 32015 @ 0x42e15a 0x42e20e 0x40534b 0x4050e5 ...：32015代表當前有32015個goroutine執行這個呼叫棧，並且停在相同位置，@後面的十六進位制，現在用不到這個資料，所以暫不深究了。
  3. 下面是當前goroutine的呼叫棧，列出了函式和所在檔案的行數，這個行數對定位很有幫助，如下：
32015 @ 0x42e15a 0x42e20e 0x40534b 0x4050e5 0x6d8559 0x6d831b 0x45abe1
#    0x6d8558    main.alloc2.func1+0xf8    /home/ubuntu/heap/leak_demo.go:53
#    0x6d831a    main.alloc2+0x2a    /home/ubuntu/heap/leak_demo.go:54

根據上面的提示，就能判斷32015個goroutine執行到leak_demo.go的53行：

func alloc2(outCh chan<- int) {
    func() {
        defer fmt.Println("alloc-fm exit")
        // 分配記憶體，假用一下
        buf := make([]byte, 1024*1024*10)
        _ = len(buf)
        fmt.Println("alloc done")

        outCh <- 0 // 53行
    }()
}

阻塞的原因是outCh這個寫操作無法完成，outCh是無緩衝的通道，並且由於以下程式碼是死程式碼，所以goroutine始終沒有從outCh讀資料，造成outCh阻塞，進而造成無數個alloc2的goroutine阻塞，形成記憶體洩露：

if false {
    <-outCh
}

方式二

url請求中設定debug=2：

http://ip:port/debug/pprof/goroutine?debug=2

第2種方式和第1種方式是互補的，它可以看到每個goroutine的資訊：

  1. goroutine 20 [chan send, 2 minutes]：20是goroutine id，[]中是當前goroutine的狀態，阻塞在寫channel，並且阻塞了2分鐘，長時間執行的系統，你能看到阻塞時間更長的情況。
  2. 同時，也可以看到呼叫棧，看當前執行停到哪了：leak_demo.go的53行，
goroutine 20 [chan send, 2 minutes]:
main.alloc2.func1(0xc42015e060)
    /home/ubuntu/heap/leak_demo.go:53 +0xf9  // 這
main.alloc2(0xc42015e060)
    /home/ubuntu/heap/leak_demo.go:54 +0x2b
created by main.alloc1
    /home/ubuntu/heap/leak_demo.go:42 +0x3f

命令列互動式方法

Web的方法是簡單粗暴，無需登入伺服器，瀏覽器開啟看看就行了。但就像前面提的，沒有瀏覽器可訪問時，命令列互動式才是最佳的方式，並且也是手到擒來，感覺比Web一樣方便。

命令列互動式只有1種獲取goroutine profile的方法，不像Web網頁分debug=1和debug=22中方式，並將profile檔案儲存到本地：

// 注意命令沒有`debug=1`，debug=1，加debug有些版本的go不支援
$ go tool pprof http://0.0.0.0:6060/debug/pprof/goroutine
Fetching profile over HTTP from http://localhost:6061/debug/pprof/goroutine
Saved profile in /home/ubuntu/pprof/pprof.leak_demo.goroutine.001.pb.gz  // profile檔案儲存位置
File: leak_demo
Type: goroutine
Time: May 16, 2019 at 2:44pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)

命令列只需要掌握3個命令就好了，上面介紹過了，詳細的倒回去看top, list, traces：

  1. top：顯示正執行到某個函式goroutine的數量
  2. traces：顯示所有goroutine的呼叫棧
  3. list：列出程式碼詳細的資訊。

我們依然使用leak_demo.go這個demo，

$  go tool pprof -base pprof.leak_demo.goroutine.001.pb.gz pprof.leak_demo.goroutine.002.pb.gz
File: leak_demo
Type: goroutine
Time: May 16, 2019 at 2:44pm (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
(pprof)
(pprof) top
Showing nodes accounting for 20312, 100% of 20312 total
      flat  flat%   sum%        cum   cum%
     20312   100%   100%      20312   100%  runtime.gopark
         0     0%   100%      20312   100%  main.alloc2
         0     0%   100%      20312   100%  main.alloc2.func1
         0     0%   100%      20312   100%  runtime.chansend
         0     0%   100%      20312   100%  runtime.chansend1
         0     0%   100%      20312   100%  runtime.goparkunlock
(pprof)
(pprof) traces
File: leak_demo
Type: goroutine
Time: May 16, 2019 at 2:44pm (CST)
-----------+-------------------------------------------------------
     20312   runtime.gopark
             runtime.goparkunlock
             runtime.chansend
             runtime.chansend1 // channel傳送
             main.alloc2.func1 // alloc2中的匿名函式
             main.alloc2
-----------+-------------------------------------------------------

top命令在怎麼確定是goroutine洩露引發的記憶體洩露介紹過了，直接看traces命令，traces能列出002中比001中多的那些goroutine的呼叫棧，這裡只有1個呼叫棧，有20312個goroutine都執行這個呼叫路徑，可以看到alloc2中的匿名函式alloc2.func1呼叫了寫channel的操作，然後阻塞掛起了goroutine，使用list列出alloc2.func1的程式碼，顯示有20312個goroutine阻塞在53行：

(pprof) list main.alloc2.func1
Total: 20312
ROUTINE ======================== main.alloc2.func1 in /home/ubuntu/heap/leak_demo.go
         0      20312 (flat, cum)   100% of Total
         .          .     48:        // 分配記憶體，假用一下
         .          .     49:        buf := make([]byte, 1024*1024*10)
         .          .     50:        _ = len(buf)
         .          .     51:        fmt.Println("alloc done")
         .          .     52:
         .      20312     53:        outCh <- 0  // 看這
         .          .     54:    }()
         .          .     55:}
         .          .     56:

友情提醒：使用list命令的前提是程式的原始碼在當前機器，不然可沒法列出原始碼。伺服器上，通常沒有原始碼，那我們咋辦呢？剛才介紹了Web檢視的方式，那裡會列出程式碼行數，我們可以使用wget下載網頁：

$ wget http://localhost:6060/debug/pprof/goroutine?debug=1

下載網頁後，使用編輯器開啟檔案，使用關鍵字main.alloc2.func1進行搜尋，找到與當前相同的呼叫棧，就可以看到該goroutine阻塞在哪一行了，不要忘記使用debug=2還可以看到阻塞了多久和原因，Web方式中已經介紹了，此處省略程式碼幾十行。

總結

文章略長，但全是乾貨，感謝閱讀到這。然讀到著了，跟定很想掌握pprof，建議實踐一把，現在和大家溫習一把本文的主要內容。

goroutine洩露的本質

goroutine洩露的本質是channel阻塞，無法繼續向下執行，導致此goroutine關聯的記憶體都無法釋放，進一步造成記憶體洩露。

goroutine洩露的發現和定位

利用好go pprof獲取goroutine profile檔案，然後利用3個命令top、traces、list定位記憶體洩露的原因。

goroutine洩露的場景

洩露的場景不僅限於以下兩類，但因channel相關的洩露是最多的。

  1. channel的讀或者寫：

    1. 無緩衝channel的阻塞通常是寫操作因為沒有讀而阻塞
    2. 有緩衝的channel因為緩衝區滿了，寫操作阻塞
    3. 期待從channel讀資料，結果沒有goroutine寫
  2. select操作，select裡也是channel操作，如果所有case上的操作阻塞，goroutine也無法繼續執行。

編碼goroutine洩露的建議

為避免goroutine洩露造成記憶體洩露，啟動goroutine前要思考清楚：

  1. goroutine如何退出？
  2. 是否會有阻塞造成無法退出？如果有，那麼這個路徑是否會建立大量的goroutine？

示例原始碼

本文所有示例原始碼，及歷史文章、程式碼都儲存在Github，閱讀原文可直接跳轉，Github：https://github.com/Shitaibin/golang_step_by_step/tree/master/pprof 。

推薦閱讀

這些既是參考資料也是推薦閱讀的文章，不容錯過。

【Go Blog關於pprof詳細介紹和Demo】 https://blog.golang.org/profi...

【Dave關於高效能Go程式的workshop】 https://dave.cheney.net/high-...

【煎魚pprof文章，很適合入門 Golang大殺器之效能剖析PProf】 https://segmentfault.com/a/11...

【SO上goroutine呼叫棧各欄位的介紹】https://stackoverflow.com/a/3...

【我的老文，有runtime.main的介紹，想學習排程器，可以看下系列文章 Go排程器系列（2）巨集觀看排程器】http://lessisbetter.site/2019...

  1. 如果這篇文章對你有幫助，不妨關注下我的Github，有文章會收到通知。
  2. 本文作者：大彬
  3. 如果喜歡本文，隨意轉載，但請保留此原文連結：http://lessisbetter.site/2019/05/18/go-goroutine-leak/

相關文章