gbd 分析core文件_Go 性能分析工具 pprof 入门
(給Go開發(fā)大全加星標(biāo))
來源：wudaijun
https://wudaijun.com/2018/04/go-pprof/
【導(dǎo)讀】pprof是golang用于性能分析的工具、可以生成圖形和文本報告。在實際項目中對高并發(fā)場景下的服務(wù)上線前必須經(jīng)過pprof驗證，本文介紹了pprof的用法。
一. pprof 數(shù)據(jù)采樣
pprof 采樣數(shù)據(jù)主要有三種獲取方式:
runtime/pprof: 手動調(diào)用runtime.StartCPUProfile或者runtime.StopCPUProfile等 API來生成和寫入采樣文件，靈活性高
net/http/pprof: 通過 http 服務(wù)獲取Profile采樣文件，簡單易用，適用于對應(yīng)用程序的整體監(jiān)控。通過 runtime/pprof 實現(xiàn)
go test: 通過?go test -bench . -cpuprofile prof.cpu生成采樣文件 適用對函數(shù)進(jìn)行針對性測試
1.1 net/http/pprof
在應(yīng)用程序中導(dǎo)入import _ "net/http/pprof"，并啟動 http server即可:
// net/http/pprof 已經(jīng)在 init()函數(shù)中通過 import 副作用完成默認(rèn) Handler 的注冊go func() { log.Println(http.ListenAndServe("localhost:6060", nil))}()之后可通過 http://localhost:6060/debug/pprof/CMD 獲取對應(yīng)的采樣數(shù)據(jù)。支持的 CMD 有:
goroutine: 獲取程序當(dāng)前所有 goroutine 的堆棧信息。
heap: 包含每個 goroutine 分配大小，分配堆棧等。每分配 runtime.MemProfileRate(默認(rèn)為512K) 個字節(jié)進(jìn)行一次數(shù)據(jù)采樣。
threadcreate: 獲取導(dǎo)致創(chuàng)建 OS 線程的 goroutine 堆棧
block: 獲取導(dǎo)致阻塞的 goroutine 堆棧(如 channel, mutex 等)，使用前需要先調(diào)用?runtime.SetBlockProfileRate
mutex: 獲取導(dǎo)致 mutex 爭用的 goroutine 堆棧，使用前需要先調(diào)用?runtime.SetMutexProfileFraction
以上五個 CMD 都通過runtime/pprof Profile 結(jié)構(gòu)體統(tǒng)一管理，以 Lookup 提供統(tǒng)一查詢接口，有相似的返回值(goroutine 堆棧)，它們都支持一個 debug URL參數(shù)，默認(rèn)為0，此時返回的采樣數(shù)據(jù)是不可人為解讀的函數(shù)地址列表，需要結(jié)合 pprof 工具才能還原函數(shù)名字。debug=1時，會將函數(shù)地址轉(zhuǎn)換為函數(shù)名，即脫離 pprof 在瀏覽器中直接查看。對 goroutine CMD來說，還支持 debug=2，此時將以 unrecovered panic 的格式打印堆棧，可讀性更高。如啟用net/http/pprof后，http://localhost:6060/debug/pprof/goroutine?debug=2?的響應(yīng)格式為:
goroutine 18 [chan receive, 8 minutes]:ngs/core/glog.logWorker(0x18b548a, 0x4, 0x7fff5fbffb0e, 0x0, 0x3, 0xc4200e31a0, 0xc4203627c4) /Users/wudaijun/go/src/ngs/core/glog/worker.go:43 +0x19ccreated by ngs/core/glog.newLogger /Users/wudaijun/go/src/ngs/core/glog/glog.go:51 +0xe4goroutine 6 [syscall, 8 minutes]:os/signal.signal_recv(0x0) /usr/local/Cellar/go/1.9.1/libexec/src/runtime/sigqueue.go:131 +0xa7os/signal.loop() /usr/local/Cellar/go/1.9.1/libexec/src/os/signal/signal_unix.go:22 +0x22created by os/signal.init.0 /usr/local/Cellar/go/1.9.1/libexec/src/os/signal/signal_unix.go:28 +0x41goroutine 50 [select, 8 minutes]:context.propagateCancel.func1(0x1cfcee0, 0xc42017a1e0, 0x1cf3820, 0xc42005b480) /usr/local/Cellar/go/1.9.1/libexec/src/context/context.go:260 +0x113created by context.propagateCancel /usr/local/Cellar/go/1.9.1/libexec/src/context/context.go:259 +0x1da...以上幾種 Profile 可在?http://localhost:6060/debug/pprof/?中看到，除此之外，go pprof 的 CMD 還包括:
cmdline: 獲取程序的命令行啟動參數(shù)
profile: 獲取指定時間內(nèi)(從請求時開始)的cpuprof，倒計時結(jié)束后自動返回。參數(shù): seconds, 默認(rèn)值為30。cpuprofile 每秒鐘采樣100次，收集當(dāng)前運行的 goroutine 堆棧信息。
symbol: 用于將地址列表轉(zhuǎn)換為函數(shù)名列表，地址通過’+’分隔，如 URL/debug/pprof?0x18d067f+0x17933e7
trace: 對應(yīng)用程序進(jìn)行執(zhí)行追蹤，參數(shù): seconds, 默認(rèn)值1s
這幾個 CMD 因為各種原因沒有整合到 Profile 結(jié)構(gòu)中去，但就使用上而言，是沒有區(qū)別的，URL格式是一致的，因此可以看做一個整體，從各個角度對系統(tǒng)進(jìn)行數(shù)據(jù)采樣和分析。
1.2 runtime/pprof
runtime/pprof提供各種相對底層的 API 用于生成采樣數(shù)據(jù)，一般應(yīng)用程序更推薦使用net/http/pprof，runtime/pprof?的 API 參考runtime/pprof或 http pprof 實現(xiàn)。
1.3 go test
通常用net/http/pprof或runtime/pprof對應(yīng)用進(jìn)行整體分析，找出熱點后，再用go test進(jìn)行基準(zhǔn)測試，進(jìn)一步確定熱點加以優(yōu)化并對比測試。
# 生成 test 二進(jìn)制文件， pprof 工具需要用到go test -c -o tmp.test # 執(zhí)行基準(zhǔn)測試 BenchAbc，并忽略任何單元測試，test flag前面需要加上'test.'前綴tmp.test -test.bench BenchAbc -test.run XXX test.cpuprofile cpu.prof # 與上面兩條命令等價，只不過沒有保留 test 二進(jìn)制文件go test -bench BenchAbc -run XXX -cpuprofile=cpu.prof .go test可以直接加-cpuprofile?-mutexprofilefraction等參數(shù)實現(xiàn)prof數(shù)據(jù)的采樣和生成，更多相關(guān)參數(shù)參考?go test -h。
二. pprof 數(shù)據(jù)分析
雖然?net/http/pprof提供的數(shù)據(jù)分析可以通過設(shè)置參數(shù)后直接在瀏覽器查看，但 pprof 采樣數(shù)據(jù)主要是用于 pprof 工具的，特別針對 cpuprof, memprof, blockprof等來說，我們需要直觀地得到整個調(diào)用關(guān)系鏈以及每次調(diào)用的詳細(xì)信息，這是需要通過go tool pprof命令來分析:
go tool pprof [binary] [binary.prof]# 如果使用的 net/http/pprof 可以直接接 URLgo tool pprof http://localhost:6060/debug/pprof/profilego pprof 采樣數(shù)據(jù)是非常豐富的，大部分情況下我們只會用到 CPU 和 內(nèi)存分析，因此這里介紹下 cpu, heap, block 和 mutex 四種 pprof 數(shù)據(jù)分析。
2.1 cpuprofile
以Profiling Go Programs中的示例代碼為例:
go build -o havlak1 havlak1.go ./havlak1 --cpuprofile=havlak1.prof# of loops: 76000 (including 1 artificial root node) go tool pprof havlak1 havlak1.profFile: havlak1Type: cpuTime: Apr 3, 2018 at 3:50pm (CST)Duration: 20.40s, Total samples = 23.30s (114.24%)Entering interactive mode (type "help" for commands, "o" for options)(pprof) top5Showing nodes accounting for 9.60s, 41.20% of 23.30s totalDropped 112 nodes (cum <= 0.12s)Showing top 5 nodes out of 90 flat flat% sum% cum cum% 2.59s 11.12% 11.12% 2.78s 11.93% runtime.mapaccess1_fast64 /usr/local/Cellar/go/1.9.1/libexec/src/runtime/hashmap_fast.go 2.26s 9.70% 20.82% 4.97s 21.33% runtime.scanobject /usr/local/Cellar/go/1.9.1/libexec/src/runtime/mgcmark.go 2.06s 8.84% 29.66% 13.79s 59.18% main.FindLoops /Users/wudaijun/Code/goprof/havlak/havlak1.go 1.39s 5.97% 35.62% 1.39s 5.97% runtime.heapBitsForObject /usr/local/Cellar/go/1.9.1/libexec/src/runtime/mbitmap.go 1.30s 5.58% 41.20% 4.14s 17.77% runtime.mapassign_fast64 /usr/local/Cellar/go/1.9.1/libexec/src/runtime/hashmap_fast.gotop5用于顯示消耗 CPU 前五的函數(shù)，每一行代表一個函數(shù)，每一列為一項指標(biāo):
flat: 采樣時，該函數(shù)正在運行的次數(shù)*采樣頻率(10ms)，即得到估算的函數(shù)運行”采樣時間”。這里不包括函數(shù)等待子函數(shù)返回。
flat%: flat / 總采樣時間值
sum%: 前面所有行的 flat% 的累加值，如第二行 sum% = 20.82% = 11.12% + 9.70%
cum: 采樣時，該函數(shù)出現(xiàn)在調(diào)用堆棧的采樣時間，包括函數(shù)等待子函數(shù)返回。因此 flat <= cum
cum%: cum / 總采樣時間值
PS: 老的pprof版本貌似顯示的是采樣次數(shù)，比如 flat 為采樣時該函數(shù)正在運行的次數(shù)，這個次數(shù)*采樣頻率即得到采樣時間。
go tool pprof?常用命令:
topN: 輸入 top 命令，默認(rèn)顯示 flat 前10的函數(shù)調(diào)用，可使用 -cum 以 cum 排序
list Func: 顯示函數(shù)名以及每行代碼的采樣分析
web: 生成 svg 熱點圖片，可在瀏覽器中打開，可使用 web Func 來過濾指定函數(shù)相關(guān)調(diào)用樹
通過top5命令可以看到，mapaccess1_fast64函數(shù)占用的CPU 采樣時間最多，通過?web mapaccess1_fast64?命令打開調(diào)用圖譜，查看該函數(shù)調(diào)用關(guān)系，可以看到主要在DFS 和 FindLoops 中調(diào)用的，然后再通過?list DFS查看函數(shù)代碼和關(guān)鍵調(diào)用，得到 map 結(jié)構(gòu)是瓶頸點，嘗試轉(zhuǎn)換為 slice 優(yōu)化，整個過程參考Profiling Go Programs。總的思路就是通過top?和web?找出關(guān)鍵函數(shù)，再通過list Func?查看函數(shù)代碼，找到關(guān)鍵代碼行并確認(rèn)優(yōu)化方案(輔以 go test Benchmark)。
2.2 memprofile
go build -o havlak3 havlak3.go ./havlak3 --memprofile=havlak3.mprof go tool pprof havlak3 havlak3.mprofFile: havlak3Type: inuse_spaceTime: Apr 3, 2018 at 3:44pm (CST)Entering interactive mode (type "help" for commands, "o" for options)(pprof) topShowing nodes accounting for 57.39MB, 100% of 57.39MB total flat flat% sum% cum cum% 39.60MB 69.00% 69.00% 39.60MB 69.00% main.FindLoops /Users/wudaijun/Code/goprof/havlak/havlak3.go 11.29MB 19.67% 88.67% 11.29MB 19.67% main.(*CFG).CreateNode /Users/wudaijun/Code/goprof/havlak/havlak3.go 6.50MB 11.33% 100% 17.79MB 31.00% main.NewBasicBlockEdge /Users/wudaijun/Code/goprof/havlak/havlak3.go 0 0% 100% 39.60MB 69.00% main.FindHavlakLoops /Users/wudaijun/Code/goprof/havlak/havlak3.go 0 0% 100% 17.79MB 31.00% main.buildBaseLoop /Users/wudaijun/Code/goprof/havlak/havlak3.gomemprofile 也就是 heap 采樣數(shù)據(jù)，go tool pprof 默認(rèn)顯示的是使用的內(nèi)存的大小，如果想要顯示使用的堆對象的個數(shù)，則通過go tool pprof --inuse_objects havlak3 havlak3.mprof，其它參數(shù)還有--alloc_objects和--alloc_space，分別是分配的堆內(nèi)存大小和對象個數(shù)。在本例中，FindLoops 函數(shù)分配了39.60M 堆內(nèi)存，占到69%，同樣，接下來是通過list FindLoops對函數(shù)代碼進(jìn)行 review，找出關(guān)鍵數(shù)據(jù)結(jié)構(gòu)，進(jìn)行優(yōu)化。
2.3 blockprofile
var mutex sync.Mutexfunc main() { // rate = 1 時, 統(tǒng)計所有的 block event, // rate <=0 時，則關(guān)閉block profiling // 參考 https://github.com/golang/go/blob/release-branch.go1.9/src/runtime/mprof.go#L397 runtime.SetBlockProfileRate(1 * 1000 * 1000) var wg sync.WaitGroup // rate > 1 時，為 ns 數(shù)，阻塞時間t>rate的event 一定會被統(tǒng)計 //小于rate則有t/rate 的幾率被統(tǒng)計 wg.Add(1) mutex.Lock() go worker(&wg) time.Sleep(2*time.Millisecond) mutex.Unlock() wg.Wait() writeProfTo("block", "block.bprof")}func worker(wg *sync.WaitGroup) { defer wg.Done() mutex.Lock() time.Sleep(1*time.Millisecond) mutex.Unlock()}func writeProfTo(name, fn string) { p := pprof.Lookup(name) if p == nil { fmt.Errorf("%s prof not found", name) return } f, err := os.Create(fn) if err != nil { fmt.Errorf("%v", err.Error()) return } defer f.Close() err = p.WriteTo(f, 0) if err != nil { fmt.Errorf("%v", err.Error()) return }}運行程序并 pprof:
go build -o Temp tmp.gogo tool pprof Temp block.bprof(pprof) topShowing nodes accounting for 3.37ms, 100% of 3.37ms total flat flat% sum% cum cum% 2.04ms 60.52% 60.52% 2.04ms 60.52% sync.(*Mutex).Lock /usr/local/Cellar/go/1.9.1/libexec/src/sync/mutex.go 1.33ms 39.48% 100% 1.33ms 39.48% sync.(*WaitGroup).Wait /usr/local/Cellar/go/1.9.1/libexec/src/sync/waitgroup.go 0 0% 100% 1.33ms 39.48% main.main /Users/wudaijun/go/src/ngs/test/tmp/tmp.go 0 0% 100% 2.04ms 60.52% main.worker /Users/wudaijun/go/src/ngs/test/tmp/tmp.go 0 0% 100% 3.37ms 100% runtime.goexit /usr/local/Cellar/go/1.9.1/libexec/src/runtime/asm_amd64.s 0 0% 100% 1.33ms 39.48% runtime.main /usr/local/Cellar/go/1.9.1/libexec/src/runtime/proc.go可以看到程序在 mutex.Lock 上阻塞了2.04ms(worker goroutine)， 在 WaitGroup.Wait 上等待了1.33ms(main goroutine)，從更上層來看，在 main 函數(shù)中一共阻塞了2.04ms，worker函數(shù)中阻塞了1.33ms(cum 列)，通過?web命令生成 svg 圖片在瀏覽器查看:
可以很直觀地看到整個阻塞調(diào)用鏈，對于耗時較多的阻塞調(diào)用加以優(yōu)化。
2.4 mutexprofile
仍然用2.3中的代碼，只需要改兩個地方，將?runtime.SetBlockProfileRate(1 * 1000 * 1000)?改為:
// 當(dāng) rate = 0 時，關(guān)閉 mutex prof (默認(rèn)值)// 當(dāng) rate = 1 時，表示記錄所有的 mutex event// 當(dāng) rate > 1 時，記錄 1/rate 的 mutex event(隨機(jī))runtime.SetMutexProfileFraction(1)再將writeProfTo("block", "block.bprof")改為writeProfTo("mutex", "mutex.mprof")即可，編譯運行，并打開 pprof 工具:
go?tool?pprof?bin/Temp?mutex.mprof(pprof) topShowing nodes accounting for 2.55ms, 100% of 2.55ms total flat flat% sum% cum cum% 2.55ms 100% 100% 2.55ms 100% sync.(*Mutex).Unlock /usr/local/Cellar/go/1.9.1/libexec/src/sync/mutex.go 0 0% 100% 2.55ms 100% main.main /Users/wudaijun/go/src/ngs/test/tmp/tmp.go 0 0% 100% 2.55ms 100% runtime.goexit /usr/local/Cellar/go/1.9.1/libexec/src/runtime/asm_amd64.s 0 0% 100% 2.55ms 100% runtime.main /usr/local/Cellar/go/1.9.1/libexec/src/runtime/proc.go查看 svg 圖:
三. 實踐 Tips
以下是一些從其它項目借鑒或者自己總結(jié)的實踐經(jīng)驗，它們只是建議，而不是準(zhǔn)則，實際項目中應(yīng)該以性能分析數(shù)據(jù)來作為優(yōu)化的參考，避免過早優(yōu)化。
對頻繁分配的小對象，使用?sync.Pool?對象池避免分配
自動化的 DeepCopy 是非常耗時的，其中涉及到反射，內(nèi)存分配，容器(如 map)擴(kuò)展等，大概比手動拷貝慢一個數(shù)量級
用 atomic.Load/StoreXXX，atomic.Value, sync.Map 等代替 Mutex。(優(yōu)先級遞減)
使用高效的第三方庫，如用fasthttp替代 net/http
在開發(fā)環(huán)境加上-race編譯選項進(jìn)行競態(tài)檢查
在開發(fā)環(huán)境開啟 net/http/pprof，方便實時 pprof
將所有外部IO(網(wǎng)絡(luò)IO，磁盤IO)做成異步
1、RedHat容器術(shù)語實用導(dǎo)論
2、圖解 Goroutine 與搶占機(jī)制
3、淺析 k8s 容器運行時演進(jìn)
如果覺得本文不錯，歡迎轉(zhuǎn)發(fā)推薦給更多人。
分享、點贊和在看
支持我們分享更多好文章，謝謝！
總結(jié)
以上是生活随笔為你收集整理的gbd 分析core文件_Go 性能分析工具 pprof 入门的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： el-popover可以设高度_家用餐厅
- 下一篇： elasticsearch java对象