實戰Go内存泄露

字號+ 編輯: 国内TP粉 修訂: 种花家 來源: Dave 2023-09-09 我要說兩句(0)

此爲中文翻譯稿,經過改動。

最近解決了我們項目中的一個内存泄露問題,事實再次证明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 mainimport (
    "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)
    }
}

提醒:本文所有代碼部分可左右滑動

瀏覽器方式

WX20210130-130309@2x.png

輸入網址ip:port/debug/pprof/打開pprof主頁,從上到下依次是5類profile信息:

block:goroutine的阻塞信息,本例就截取自一個goroutine阻塞的demo,但block爲0,沒掌握block的用法

goroutine:所有goroutine的信息,下面的full goroutine stack dump是輸出所有goroutine的調用棧,是goroutine的debug=2,後面會詳細介紹。

heap:堆内存的信息

mutex:鎖的信息

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 mainimport (
   "fmt"
   "net/http"
   _ "net/http/pprof"
   "os"
   "time"
)
// 運行一段時間:
fatal error: runtime: out of memoryfunc 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 Fetching profile over HTTP from http://localhost:6060/debug/pprof/heapSaved 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個地方:

下載得到的文档:/home/ubuntu/pprof/pprof.demo.alloc_objects.alloc_space.inuse_objects.inuse_space.001.pb.gz,這其中包含了程序名demo,profile類型alloc已分配的内存,inuse代表使用中的内存。

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内存佔用情況如下,可以看到隨著時間的推進,内存的佔用率在不斷的提高,這是内存泄露的最明顯現象:

WX20210130-130415@2x.png

如果沒有雲平台這種内存監控工具,可以制作一個簡單的内存記錄工具。

1、建立一個腳本prog_mem.sh,獲取進程佔用的物理内存情況,腳本内容如下:

#!/bin/bashprog_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等表格工具,繪制内存佔用圖。

WX20210130-130516@2x.png

go pprof發現存在内存問題

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

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

後來讀了Dave的《High Performance Go Workshop》,刷新了對heap的認識,内存pprof的簡要内容如下:

WX20210201-071712@2x.png

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 mainimport (
   "fmt"
   "net/http"
   _ "net/http/pprof"
   "os"
   "time"
)
// 運行一段時間:
fatal error: runtime: out of memoryfunc 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類可能:

該goroutine只調用了少數幾次,但消耗了大量的内存,說明每個goroutine調用都消耗了不少内存,内存泄露的原因基本就在該協程内部。

該goroutine的調用次數非常多,雖然每個協程調用過程中消耗的内存不多,但該調用路徑上,協程數量巨大,造成消耗大量的内存,並且這些goroutine由於某種原因無法退出,佔用的内存不會釋放,内存泄露的原因在到g111調用路徑上某段代碼實現有問題,造成創建了大量的g111。

第2種情況,就是goroutine泄露,這是通過heap無法發現的,所以heap在定位内存泄露這件事上,發揮的作用不大。

WX20210130-132722@2x.png

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 mainimport (
   "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

效果如下:

WX20210130-133316@2x.jpg

看起來密密麻麻的,其實簡單又十分有用,看上圖標出來的部分,手機上圖看起來可能不方便,那就放大圖片,或直接看下面各字段的含義:

goroutine profile: total 32023:32023是goroutine的總數量,

32015 @ 0x42e15a 0x42e20e 0x40534b 0x4050e5 ...:32015代表當前有32015個goroutine運行這個調用棧,並且停在相同位置,@後面的十六進制,現在用不到這個數據,所以暫不深究了。

下面是當前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

WX20210130-133624@2x.png

第2種方式和第1種方式是互補的,它可以看到每個goroutine的信息:

goroutine 20 [chan send, 2 minutes]:20是goroutine id,[]中是當前goroutine的狀態,阻塞在寫channel,並且阻塞了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 +0x2bcreated 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/goroutineSaved 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:

top:顯示正運行到某個函數goroutine的數量

traces:顯示所有goroutine的調用棧

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: 20312ROUTINE ======================== 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相關的泄露是最多的。

channel的讀或者寫:

無緩沖channel的阻塞通常是寫操作因爲沒有讀而阻塞

有緩沖的channel因爲緩沖區滿了,寫操作阻塞

期待從channel讀數據,結果沒有goroutine寫

select操作,select裡也是channel操作,如果所有case上的操作阻塞,goroutine也無法繼續執行。

編碼goroutine泄露的建議

爲避免goroutine泄露造成内存泄露,啓動goroutine前要思考清楚:

goroutine如何退出?

是否會有阻塞造成無法退出?如果有,那麽這個路徑是否會創建大量的goroutine?

示例源碼

本文所有示例源碼,及歷史文章、代碼都存儲在Github,閲讀原文可直接跳轉,Github:https://github.com/Shitaibin/golang_step_by_step/tree/master/pprof 。

閲完此文,您的感想如何?
  • 有用

    0

  • 沒用

    0

  • 開心

    0

  • 憤怒

    0

  • 可憐

    0

1.如文章侵犯了您的版權,請發郵件通知本站,該文章將在24小時内刪除;
2.本站標注原創的文章,轉發時煩請注明來源;
3.交流群: 2702237 13835667

相關課文
  • GO語言GORM如何更新字段

  • gorm如何創建記錄與模型定義需要注意什麽

  • gorm一般查詢與高級查詢

  • GORM時間戳跟蹤及CURD(增刪改查)

我要說說
網上賓友點評