Go pprof和火焰圖

Profiling

在計算機性能調試領域里，profiling 就是對應用的畫像，這里畫像就是應用使用 CPU 和內存的情況。也就是說應用使用了多少 CPU 資源？都是哪些部分在使用？每個函數使用的比例是多少？有哪些函數在等待 CPU 資源？知道了這些，我們就能對應用進行規划，也能快速定位性能瓶頸。

在 go 語言中，主要關注的應用運行情況主要包括以下幾種：

• CPU profile：報告程序的 CPU 使用情況，按照一定頻率去采集應用程序在 CPU 和寄存器上面的數據
• Memory Profile（Heap Profile）：報告程序的內存使用情況
• Block Profiling：報告 goroutines 不在運行狀態的情況，可以用來分析和查找死鎖等性能瓶頸
• Goroutine Profiling：報告 goroutines 的使用情況，有哪些 goroutine，它們的調用關系是怎樣的

兩種收集方式

做 Profiling 第一步就是怎么獲取應用程序的運行情況數據。go 語言提供了 runtime/pprof 和 net/http/pprof 兩個庫，這部分我們講講它們的用法以及使用場景。

工具型應用

如果你的應用是一次性的，運行一段時間就結束。那么最好的辦法，就是在應用退出的時候把 profiling 的報告保存到文件中，進行分析。對於這種情況，可以使用 runtime/pprof 庫。

pprof 封裝了很好的接口供我們使用，比如要想進行 CPU Profiling，可以調用 pprof.StartCPUProfile() 方法，它會對當前應用程序進行 CPU profiling，並寫入到提供的參數中（w io.Writer），要停止調用 StopCPUProfile() 即可。

去除錯誤處理只需要三行內容，一般把部分內容寫在 main.go 文件中，應用程序啟動之后就開始執行：

f, err := os.Create(*cpuprofile)
...
pprof.StartCPUProfile(f)
defer pprof.StopCPUProfile()

應用執行結束后，就會生成一個文件，保存了我們的 CPU profiling 數據。

想要獲得內存的數據，直接使用 WriteHeapProfile 就行，不用 start 和 stop 這兩個步驟了：

f, err := os.Create(*memprofile)
pprof.WriteHeapProfile(f)
f.Close()

服務型應用

如果你的應用是一直運行的，比如 web 應用，那么可以使用 net/http/pprof 庫，它能夠在提供 HTTP 服務進行分析。

如果使用了默認的 http.DefaultServeMux（通常是代碼直接使用 http.ListenAndServe("0.0.0.0:8000", nil)），只需要添加一行：

import _ "net/http/pprof" 

如果你使用自定義的 Mux，則需要手動注冊一些路由規則：

r.HandleFunc("/debug/pprof/", pprof.Index) r.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline) r.HandleFunc("/debug/pprof/profile", pprof.Profile) r.HandleFunc("/debug/pprof/symbol", pprof.Symbol) r.HandleFunc("/debug/pprof/trace", pprof.Trace) 

不管哪種方式，你的 HTTP 服務都會多出 /debug/pprof endpoint，訪問它會得到類似下面的內容：

/debug/pprof/ profiles: 0 block 62 goroutine 444 heap 30 threadcreate full goroutine stack dump 

這個路徑下還有幾個子頁面：

• /debug/pprof/profile：訪問這個鏈接會自動進行 CPU profiling，持續 30s，並生成一個文件供下載
• /debug/pprof/heap： Memory Profiling 的路徑，訪問這個鏈接會得到一個內存 Profiling 結果的文件
• /debug/pprof/block：block Profiling 的路徑
• /debug/pprof/goroutines：運行的 goroutines 列表，以及調用關系

go tool pprof 命令：獲取和分析 Profiling 數據

能通過對應的庫獲取想要的 Profiling 數據之后（不管是文件還是 http），下一步就是要對這些數據進行保存和分析，我們可以使用 go tool pprof 命令行工具。

在后面我們會生成調用關系圖和火焰圖，需要安裝 graphviz 軟件包，在 ubuntu 系統可以使用下面的命令：

$ sudo apt-get install -y graphviz 

NOTE：獲取的 Profiling 數據是動態的，要想獲得有效的數據，請保證應用處於較大的負載（比如正在生成中運行的服務，或者通過其他工具模擬訪問壓力）。否則如果應用處於空閑狀態，得到的結果可能沒有任何意義。

CPU Profiling

go tool pprof 最簡單的使用方式為 go tool pprof [binary] [source]，binary 是應用的二進制文件，用來解析各種符號；source 表示 profile 數據的來源，可以是本地的文件，也可以是 http 地址。比如：

➜  go tool pprof ./hyperkube http://172.16.3.232:10251/debug/pprof/profile Fetching profile from http://172.16.3.232:10251/debug/pprof/profile Please wait... (30s) Saved profile in /home/cizixs/pprof/pprof.hyperkube.172.16.3.232:10251.samples.cpu.002.pb.gz Entering interactive mode (type "help" for commands) (pprof) 

這個命令會進行 CPU profiling 分析，等待一段時間（默認是 30s，如果在 url 最后加上 ?seconds=60 參數可以調整采集數據的時間為 60s）之后，我們就進入了一個交互式命令行，可以對解析的結果進行查看和導出。可以通過 help 來查看支持的自命令有哪些。

一個有用的命令是 topN，它列出最耗時間的地方：

(pprof) top10
130ms of 360ms total (36.11%) Showing top 10 nodes out of 180 (cum >= 10ms) flat flat% sum% cum cum% 20ms 5.56% 5.56% 100ms 27.78% encoding/json.(*decodeState).object 20ms 5.56% 11.11% 20ms 5.56% runtime.(*mspan).refillAllocCache 20ms 5.56% 16.67% 20ms 5.56% runtime.futex 10ms 2.78% 19.44% 10ms 2.78% encoding/json.(*decodeState).literalStore 10ms 2.78% 22.22% 10ms 2.78% encoding/json.(*decodeState).scanWhile 10ms 2.78% 25.00% 40ms 11.11% encoding/json.checkValid 10ms 2.78% 27.78% 10ms 2.78% encoding/json.simpleLetterEqualFold 10ms 2.78% 30.56% 10ms 2.78% encoding/json.stateBeginValue 10ms 2.78% 33.33% 10ms 2.78% encoding/json.stateEndValue 10ms 2.78% 36.11% 10ms 2.78% encoding/json.stateInString 

每一行表示一個函數的信息。前兩列表示函數在 CPU 上運行的時間以及百分比；第三列是當前所有函數累加使用 CPU 的比例；第四列和第五列代表這個函數以及子函數運行所占用的時間和比例（也被稱為累加值 cumulative），應該大於等於前兩列的值；最后一列就是函數的名字。如果應用程序有性能問題，上面這些信息應該能告訴我們時間都花費在哪些函數的執行上了。

pprof 不僅能打印出最耗時的地方(top)，還能列出函數代碼以及對應的取樣數據(list)、匯編代碼以及對應的取樣數據(disasm)，而且能以各種樣式進行輸出，比如 svg、gv、callgrind、png、gif等等。

其中一個非常便利的是 web 命令，在交互模式下輸入 web，就能自動生成一個 svg 文件，並跳轉到瀏覽器打開，生成了一個函數調用圖。

這個調用圖包含了更多的信息，而且可視化的圖像能讓我們更清楚地理解整個應用程序的全貌。圖中每個方框對應一個函數，方框越大代表執行的時間越久（包括它調用的子函數執行時間，但並不是正比的關系）；方框之間的箭頭代表着調用關系，箭頭上的數字代表被調用函數的執行時間。

因為原圖比較大，這里只截取了其中一部分，但是能明顯看到 encoding/json.(*decodeState).object 是這里耗時比較多的地方，而且能看到它調用了哪些函數，分別函數多少。這些更詳細的信息對於定位和調優性能是非常有幫助的！

要想更細致分析，就要精確到代碼級別了，看看每行代碼的耗時，直接定位到出現性能問題的那行代碼。pprof 也能做到，list 命令后面跟着一個正則表達式，就能查看匹配函數的代碼以及每行代碼的耗時：

(pprof) list podFitsOnNode
Total: 120ms ROUTINE ======================== k8s.io/kubernetes/plugin/pkg/scheduler.podFitsOnNode in /home/cizixs/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/plugin/pkg/scheduler/generic_scheduler.go 0 20ms (flat, cum) 16.67% of Total . . 230: . . 231:// Checks whether node with a given name and NodeInfo satisfies all predicateFuncs. . . 232:func podFitsOnNode(pod *api.Pod, meta interface{}, info *schedulercache.NodeInfo, predicateFuncs map[string]algorithm.FitPredicate) (bool, []algorithm.PredicateFailureReason, error) { . . 233: var failedPredicates []algorithm.PredicateFailureReason . . 234: for _, predicate := range predicateFuncs { . 20ms 235: fit, reasons, err := predicate(pod, meta, info) . . 236: if err != nil { . . 237: err := fmt.Errorf("SchedulerPredicates failed due to %v, which is unexpected.", err) . . 238: return false, []algorithm.PredicateFailureReason{}, err . . 239: } . . 240: if !fit { 

如果想要了解對應的匯編代碼，可以使用 disadm <regex> 命令。這兩個命令雖然強大，但是在命令行中查看代碼並不是很方面，所以你可以使用 weblist 命令，用法和兩者一樣，但它會在瀏覽器打開一個頁面，能夠同時顯示源代碼和匯編代碼。

NOTE：更詳細的 pprof 使用方法可以參考 pprof --help 或者 pprof 文檔。

Memory Profiling

要想獲得內存使用 Profiling 信息，只需要把數據源修改一下就行（對於 http 方式來說就是修改 url 的地址，從 /debug/pprof/profile 改成 /debug/pprof/heap）：

➜  go tool pprof ./hyperkube http://172.16.3.232:10251/debug/pprof/heap Fetching profile from http://172.16.3.232:10251/debug/pprof/heap Saved profile in /home/cizixs/pprof/pprof.hyperkube.172.16.3.232:10251.inuse_objects.inuse_space.002.pb.gz Entering interactive mode (type "help" for commands) (pprof) 

和 CPU Profiling 使用一樣，使用 top N 可以打印出使用內存最多的函數列表：

(pprof) top
11712.11kB of 14785.10kB total (79.22%) Dropped 580 nodes (cum <= 73.92kB) Showing top 10 nodes out of 146 (cum >= 512.31kB) flat flat% sum% cum cum% 2072.09kB 14.01% 14.01% 2072.09kB 14.01% k8s.io/kubernetes/vendor/github.com/beorn7/perks/quantile.NewTargeted 2049.25kB 13.86% 27.87% 2049.25kB 13.86% k8s.io/kubernetes/pkg/api/v1.(*ResourceRequirements).Unmarshal 1572.28kB 10.63% 38.51% 1572.28kB 10.63% k8s.io/kubernetes/vendor/github.com/beorn7/perks/quantile.(*stream).merge 1571.34kB 10.63% 49.14% 1571.34kB 10.63% regexp.(*bitState).reset 1184.27kB 8.01% 57.15% 1184.27kB 8.01% bytes.makeSlice 1024.16kB 6.93% 64.07% 1024.16kB 6.93% k8s.io/kubernetes/pkg/api/v1.(*ObjectMeta).Unmarshal 613.99kB 4.15% 68.23% 2150.63kB 14.55% k8s.io/kubernetes/pkg/api/v1.(*PersistentVolumeClaimList).Unmarshal 591.75kB 4.00% 72.23% 1103.79kB 7.47% reflect.Value.call 520.67kB 3.52% 75.75% 520.67kB 3.52% k8s.io/kubernetes/vendor/github.com/gogo/protobuf/proto.RegisterType 512.31kB 3.47% 79.22% 512.31kB 3.47% k8s.io/kubernetes/pkg/api/v1.(*PersistentVolumeClaimStatus).Unmarshal 

每一列的含義也是類似的，只不過從 CPU 使用時間變成了內存使用大小，就不多解釋了。

類似的，web 命令也能生成 svg 圖片在瀏覽器中打開，從中可以看到函數調用關系，以及每個函數的內存使用多少。

需要注意的是，默認情況下，統計的是內存使用大小，如果執行命令的時候加上 --inuse_objects可以查看每個函數分配的對象數；--alloc-space 查看分配的內存空間大小。

這里還要提兩個比較有用的方法，如果應用比較復雜，生成的調用圖特別大，看起來很亂，有兩個辦法可以優化：

• 使用 web funcName 的方式，只打印和某個函數相關的內容
• 運行 go tool pprof 命令時加上 --nodefration=0.05 參數，表示如果調用的子函數使用的 CPU、memory 不超過 5%，就忽略它，不要顯示在圖片中

pprof 已經支持動態的 web 瀏覽方式：https://github.com/google/pprof/commit/f83a3d89c18c445178f794d525bf3013ef7b3330

go-torch 和火焰圖

火焰圖（Flame Graph）是 Bredan Gregg 創建的一種性能分析圖表，因為它的樣子近似 🔥而得名。上面的 profiling 結果也轉換成火焰圖，如果對火焰圖比較了解可以手動來操作，不過這里我們要介紹一個工具：go-torch。這是 uber 開源的一個工具，可以直接讀取 golang profiling 數據，並生成一個火焰圖的 svg 文件。

火焰圖 svg 文件可以通過瀏覽器打開，它對於調用圖的最優點是它是動態的：可以通過點擊每個方塊來 zoom in 分析它上面的內容。

火焰圖的調用順序從下到上，每個方塊代表一個函數，它上面一層表示這個函數會調用哪些函數，方塊的大小代表了占用 CPU 使用的長短。火焰圖的配色並沒有特殊的意義，默認的紅、黃配色是為了更像火焰而已。

go-torch 工具的使用非常簡單，沒有任何參數的話，它會嘗試從 http://localhost:8080/debug/pprof/profile 獲取 profiling 數據。它有三個常用的參數可以調整：

• -u --url：要訪問的 URL，這里只是主機和端口部分
• -s --suffix：pprof profile 的路徑，默認為 /debug/pprof/profile
• --seconds：要執行 profiling 的時間長度，默認為 30s

要生成火焰圖，需要事先安裝 FlameGraph工具，這個工具的安裝很簡單，只要把對應的可執行文件放到 $PATH 目錄下就行，在window下不可用。

和測試工具的集成

go test 命令有兩個參數和 pprof 相關，它們分別指定生成的 CPU 和 Memory profiling 保存的文件：

• -cpuprofile：cpu profiling 數據要保存的文件地址
• -memprofile：memory profiling 數據要報文的文件地址

比如下面執行測試的同時，也會執行 CPU profiling，並把結果保存在 cpu.prof 文件中：

$ go test -bench . -cpuprofile=cpu.prof 

執行結束之后，就會生成 main.test 和 cpu.prof 文件。要想使用 go tool pprof，需要指定的二進制文件就是 main.test。

 

 

需要注意的是，Profiling 一般和性能測試一起使用，只有應用在負載高的情況下 Profiling 才有意義。通常會高並發測試接口，然后來執行。

現在已經可以不用 go-torch 來生成火焰圖了，安裝 pprof，如下命令：

go tool pprof 也可以生成cpu graph圖，但沒有火焰圖，而且界面比較挫，pprof則可以生成火焰圖

 

go get -u github.com/google/pprof

 

 

pprof -http 127.0.0.1:9090 http://127.0.0.1:8080/debug/pprof/profile

 

http://127.0.0.1:8080/debug/pprof/profile，這個是代碼里監控pprof的

代碼如下：

package main

import (
    "fmt"
    "net/http"

    _ "net/http/pprof"
)

func health(w http.ResponseWriter, r *http.Request) {
    fmt.Fprintf(w, "[%s] Tequila is up", config.GetDeploymentEnv())
}

func main() {
    router := api.GetRouter()
    router.HandleFunc("/", health).Methods("GET")

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

    base.Main(":80", router)
}