[TOC] > [參考](https://www.jianshu.com/p/927d800021f4) > [一看就懂系列之Golang的pprof](https://studygolang.com/articles/26918#reply0) ## 概述 性能分析執行時,需要去訪問待分析的程序,萊獲取分析數據 ## 安裝 ### 1. 安裝 graphviz 可視化 ``` //安裝圖形化界面 //win choco install -y graphviz //mac brew install graphviz //centos yum install graphviz ``` ### 2. 安裝 http/pprof ``` import _ "net/http/pprof" ``` demo ``` func main() { go func() { log.Println(http.ListenAndServe("0.0.0.0:6060", nil)) }() //業務代碼 } ``` 運行程序 `go run main.go` ### 3. 安裝 pprof web ui pprof web ui 已經集成 top, svg, list, disassemble, regex search, go-torch。最方便使用 ``` go get github.com/google/pprof ``` ## pprof web ui 使用 **啟動業務程序后** ### 查看web端報告 `http://127.0.0.1:6060/debug/pprof/` ### 快速生成 web ui 1. 方法一 [推薦] ``` pprof -seconds 60 -http 127.0.0.1:6061 http://127.0.0.1:6060/debug/pprof/profile ``` 2. 方法二 ``` go tool pprof http://localhost:6060/debug/pprof/profile?second=60 pprof -http 0.0.0.0:7070 binaryfile xxx.pb.gz(profile_file) //profile_file 為上條命令產生的文件,可在命令行中查看到 ``` ## 名詞分析 ### 6060/debug/pprof/ 界面  | 類型 | 描述 | | --- | --- | | allocs | **內**存分配情況的采樣信息 | | blocks | **阻塞**操作情況的采樣信息 | | cmdline | 顯示程序啟動**命令參數**及其參數 | | goroutine | 顯示當前所有**協程**的堆棧信息 | | heap | **堆**上的內存分配情況的采樣信息 | | mutex | **鎖**競爭情況的采樣信息 | | profile | **cpu**占用情況的采樣信息，點擊會下載文件 | | threadcreate | 系統**線程**創建情況的采樣信息 | | trace | 程序**運行跟蹤**信息 | ### top 指令分析  | 類型 | 描述 | 舉例 | | --- | --- | --- | | flat | 該函數占用CPU的耗時 | selectnbrecv占用CPU的耗時是12.29s | | flat% | [重點關注]該函數占用CPU的耗時的百分比 | selectnbrecv耗時：12.29s，cpu總耗時：29.14，12.29/29.14=42.18 | | sum% | top命令中排在它上面的函數以及本函數flat%之和 | chanrecv：42.18%+30.47% = 72.65% | | cum | 當前函數加上該函數調用之前的累計CPU耗時 | chanrecv：8.88+0.54=9.42 | | cum% | 當前函數加上該函數調用之前的累計CPU耗時的百分比 | 9.42/29.14=32.33% | ## 問題 > [參考網站](https://studygolang.com/articles/26918#reply0) ### 問題:cpu過高  1.`go tool pprof http://localhost:6060/debug/pprof/profile?second=60` 2. 輸入 `top` ``` (pprof) top flat flat% sum% cum cum% 49.75s 83.88% 83.88% 51.29s 86.48% runtime.cgocall 0.88s 1.48% 85.37% 1.04s 1.75% runtime.deferreturn ``` 3. 查找 `cgocall` 進行 ``` (pprof) list cgocall Total: 59.31s ROUTINE ======================== runtime.cgocall in C:\Go\src\runtime\cgocall.go 49.75s 51.29s (flat, cum) 86.48% of Total . . 102: . . 103: if raceenabled { . . 104: racereleasemerge(unsafe.Pointer(&racecgosync)) ``` ### 問題:內存占用過高 ``` > go tool pprof http://localhost:6060/debug/pprof/heap (pprof) top (pprof) list cgocall ``` ### 頻繁垃圾回收 ``` > gc 1 @2.104s 0%: 0.018+1.3+0.076 ms clock, 0.054+0.35/1.0/3.0+0.23 ms cpu, 4->4->3 MB, 5 MB goal, 4 P 1 表示第一次執行 @2.104s 表示程序執行的總時間 0% 垃圾回收時間占用的百分比，（不知道和誰比？難道是和上面的程序執行總時間，這樣比較感覺沒意義） 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 使用的處理器數量 > scvg0: inuse: 426, idle: 0, sys: 427, released: 0, consumed: 427 (MB) 426 使用多少M內存 0 剩下要清除的內存 427 系統映射的內存 0 釋放的系統內存 427 申請的系統內存 ``` 可以查看切片所占的內存,分析內存占用最大的代碼 ``` //linux GODEBUG=gctrace=1 ./xiyouji 2>&1|grep gc //window Set GODEBUG=gctrace=1 ./xiyouji | findstr gc > gc 1 @3.503s 0%: 0+0.99+0 ms clock, 0+0.99/0.99/1.9+0 ms cpu, 4->4->1 MB, 5 MB goal, 4 P > go tool pprof http://localhost:6060/debug/pprof/allocs (pprof) top flat flat% sum% cum cum% 688.56kB 54.71% 54.71% 688.56kB 54.71% bigant/servers/login.newTcpClient 570.04kB 45.29% 100% 570.04kB 45.29% bigant/servers/login.newConList 0 0% 100% 688.56kB 54.71% bigant/servers/login.(*App).HandleCient 0 0% 100% 570.04kB 45.29% bigant/servers/login.init 0 0% 100% 570.04kB 45.29% runtime.doInit 0 0% 100% 570.04kB 45.29% runtime.main (pprof) list newTcpClient ROUTINE ======================== bigant/servers/login.newTcpClient in D:\go\bignat-go\servers\login\client.go 688.56kB 688.56kB (flat, cum) 54.71% of Total . . 74: return &tcpClient{ . . 75: app: app, . . 76: conn: conn, . . 77: nid: uuid, . . 78: quit: make(chan struct{}, 1), 688.56kB 688.56kB 79: sendChan: make(chan servers.Trans, 1024), . . 80: recChan: make([]byte, 2048), . . 81: } ``` ### 協程泄露  ``` > go tool pprof http://localhost:6060/debug/pprof/goroutine (pprof) top Showing nodes accounting for 40, 100% of 40 total Showing top 10 nodes out of 70 flat flat% sum% cum cum% 38 95.00% 95.00% 38 95.00% runtime.gopark 1 2.50% 97.50% 1 2.50% runtime.notetsleepg 1 2.50% 100% 1 2.50% runtime/pprof.writeRuntimeProfile 0 0% 100% 1 2.50% bigant/lib/rpc.NewRpcServer //無異常,使用web 查看 (pprof) web ``` **提示** 通過多次使用`go tool pprof http://localhost:6060/debug/pprof/goroutine` 和`(pprof) web` 即可在UI中詳細看到哪個協程增加了 ### 鎖的爭用 ``` > go tool pprof localhost:6060/debug/pprof/mutex (prof) top ``` 錯誤實例  ### 阻塞操作 ``` > go tool pprof localhost:6060/debug/pprof/block ```   ### 問題:訪問 6060 顯示 404 在入口文件中**手動**指定函數 ``` func init() { http.Handle("/debug/pprof/", http.HandlerFunc(pprof.Index)) http.Handle("/debug/pprof/cmdline", http.HandlerFunc(pprof.Cmdline)) http.Handle("/debug/pprof/profile", http.HandlerFunc(pprof.Profile)) http.Handle("/debug/pprof/symbol", http.HandlerFunc(pprof.Symbol)) http.Handle("/debug/pprof/trace", http.HandlerFunc(pprof.Trace)) } func main() { go func() { log.Info(http.ListenAndServe("0.0.0.0:6060", nil)) }() app := login.NewApp() app.Run() } ```