golang 如何排查和定位GC問題

    最近在作文本處理的時候遇到一個很奇怪的現象。串行執行腳本可能只須要幾秒鐘，可是若是想給每行開個協程併發處理的話，執行時間卻從幾十秒到幾十分鐘不等，關鍵是執行的過程當中cpu的佔用並不高。通過一系列的分析以後確認是gc致使的。因此想講一下排查gc問題的一些小技巧，以後也會給出一些case：

    一。如何查看程序運行過程當中的GC信息呢？

    設置gctrace的變量值爲1便可，這個既能夠設置成環境變量，也能夠選擇按以下方式執行：

GODEBUG=gctrace=1  go run main.go
//GODEBUG=gctrace=1 ./main

GODEBUG=gctrace=1 表明只針對這個進程開啓gc追蹤功能。程序輸出以下：

       

    對於上面每一行每一列的具體含義：

gc 1 @0.038s 1%: 0.55+0.12+0.081 ms clock, 2.2+0/0.42/1.1+0.32 ms cpu, 4->4->0 MB, 5 MB goal, 4 P。

1 表示第一次執行

@0.038s 表示程序執行的總時間

1% 垃圾回收時間佔用總的運行時間百分比

0.018+1.3+0.076 ms clock 垃圾回收的時間，分別爲STW（stop-the-world）清掃的時間, 併發標記和掃描的時間，STW標記的時間

0.054+0.35/1.0/3.0+0.23 ms cpu 垃圾回收佔用cpu時間

4->4->3 MB 堆的大小，gc後堆的大小，存活堆的大小

5 MB goal 總體堆的大小

4 P 使用的處理器數量

    打開了GCTRACE以後對於gc執行的時間點、執行次數以及耗時可能已經有了初步的瞭解，可是對什麼地方耗用大量內存並形成大量延遲可能並不清除。

二。如何定位gc問題所在？

    這一點主要使用pprof來實現。開啓pprof也特別簡單，用net/http/pprof包能夠快速實現。只須要在以前的代碼中加下面三行就能夠：

import (
    "net/http"
    _ "net/http/pprof"
)
go func() {
            log.Println(http.ListenAndServe("localhost:8081", nil))
}()

    在程序啓動以後，只須要在命令行或者瀏覽器輸入如下命令便可：

go tool pprof  http://127.0.0.1:8081/debug/pprof/heap       //查看堆的使用，即內存使用狀況
go tool pprof  http://127.0.0.1:8081/debug/pprof/profile    //查看cpu耗時，會詳細列出每一個函數的耗時
go tool pprof  http://127.0.0.1:8081/debug/pprof/goroutine  //當前在運行的goroutine狀況以及總數

    能夠看下profile的輸出信息， flat表明單個函數的運行時間，而cum則是累加的時間，也會包括這個函數下面的子函數的累加時間，因此main.main確定是100%：

        

    若是想看具體的圖示的話，可使用png命令將結果存成圖片看，好比：

        

    能夠看下生成圖片的樣子， 有具體的箭頭以及每一個函數佔用的時間或者內存：

     

 

基本目前筆者用到的工具就這兩個了，感受有收穫的讀者能夠本身實驗一下。接下來，我會不按期的分享一些遇到的GC問題的case，歡迎一塊兒交流哈。