做者:lni github.com/lnihtml
業內的共識是Go語言簡單易用且通常水平的工程師也能寫出較不錯的性能。而經過分享相關工具的使用,把較不錯的性能升格爲過硬的高性能,正是本文的目的。node
CPU性能分析git
Dragonboat早期版本里,在系統每秒處理100萬個寫請求的時候CPU基本就被浪費殆盡。過後分析得知,具體成因來自各個不一樣組件,有自身實現的問題、有踩anti-pattern的坑、也有runtime自己實現不合理之處。做爲實現者,面對相對較新的這樣一個自帶runtime的語言,很難直觀從代碼自己判斷CPU資源的使用狀況。github
此時,Go內建的CPU性能分析工具可直觀的對每行代碼的CPU耗時作出統計。在程序中,使用下述runtime/pprof包的方法能夠方便的控制CPU性能分析數據捕捉的啓動與中止,啓停間隔之間的CPU性能分析數據便被捕捉下來供後續分析使用:golang
func StartCPUProfile(w io.Writer) error func StopCPUProfile()
好比,StartCPUProfile被給予了一個指向名爲cpu.pprof的文件的io.Writer,那麼所捕獲的數據將被保存在cpu.pprof這一文件中。使用下述命令行命令,可使用Go內建的pprof工具打開已保存的性能分析數據文件以瀏覽所捕獲的性能細節:web
go tool pprof cpu.pprof
以Dragonboat早期版本的getCluster()方法爲例,打開了上述數據分析文件後,可以使用list命令列出該方法的具體性能數據。從本例的輸出可見,鎖操做是性能問題所在,它耗時巨大。性能優化
(pprof) list getCluster 20ms 618:func (nh *NodeHost) getCluster(clusterID uint64) (*node, bool) { 3.85s 619: nh.clusterMu.RLock() 640ms 620: v, ok := nh.clusterMu.clusters[clusterID] 1.37s 621: nh.clusterMu.RUnlock() 10ms 622: return v, ok . 623:}
在上述工具中,能夠經過下列命令列出程序耗時前20排名的函數與方法:併發
(pprof) top20 -cum
針對輸出列表所說起的函數與方法,逐一經過上述list命令,分析其具體CPU耗時的語句,能夠方便的定位發現系統中性能異常的部分。分佈式
稍進階的用法裏,經過查看系統runtime裏內存分配、棧處理、chan讀寫等等相關函數方法的CPU佔用,更可進一步瞭解runtime、內存使用與核心內建類型等的使用性能狀況。以Dragonboat在持續處理寫請求時候的內存使用爲例,下面的數據是用以分配一個指定字節數的對象mallocgc的CPU耗時,可見它並非瓶頸:svg
cum cum% 0.13s 1.95% runtime.mallocgc
使用net/http/pprof包,可經過web UI方式訪問相似性能分析數據,本文基於命令行模式,不對web UI方式作具體介紹,具體web UI模式的用法可參考這裏。
CPU profiling應該是最直接了當的性能分析與優化手段,Dragonboat應用本文所介紹的性能分析方法,內存內狀態機可在單插22核中檔志強上達到千萬以上每秒的寫性能,500萬每秒的P999寫延遲在5ms之內。具體優化結果請點這裏,也歡迎點star/fork支持。
堆分配分析
與CPU性能分析同樣,首先須要收集堆性能數據。在程序退出前,調用runtime/pprof包的WriteHeapProfile()方法,將堆性能數據保存至指定的文件,好比mem.pprof。
func WriteHeapProfile(w io.Writer) error
使用下列命令行程序打開該性能數據文件:
go tool pprof -alloc_space mem.pprof
而後使用list命令,能夠列出但願查詢的函數與方法的內存使用狀況。下列函數就是目前Dragonboat還沒有作分配優化的部分:
(pprof) list saveRaftState 0 843.29MB (flat, cum) 1.83% of Total . . 104: } . . 105: r.recordSnapshot(wb, ud) . . 106: r.setMaxIndex(wb, ud, ud.Snapshot.Index, ctx) . . 107: } . . 108: } . 840.79MB 109: r.saveEntries(updates, wb, ctx) . . 110: if wb.Count() > 0 { . 2.50MB 111: return r.kvs.CommitWriteBatch(wb) . . 112: } . . 113: return nil . . 114:}
上述命令行命令使用--alloc_space參數,用以顯示WriteHeapProfile()調用時全部已分配的含已釋放的堆空間數據,所支持的各模式以下:
-inuse_space 未釋放空間數 -inuse_objects 未釋放對象數 -alloc_space 全部分配空間數 -alloc_objects 全部分配對象數
未釋放數據指示當前堆內存使用狀況,可用來查找未按預期被釋放的對象或空間。全部分配空間與對象數據,則給出包括未釋放與已釋放的對象或空間數據,堆對象的分配與回收均有必定CPU代價,該數據間接提示由堆分配帶來的CPU性能開銷以及對分配器的壓力大小。
既然叫heap profile,它記錄呈現的是heap的分配狀況,這也就同時提供了一種發現逃逸分析問題的途徑。當某對象主觀認爲應該在stack上,可它卻出如今上述heap profile裏,這就表示程序自己、自我認知、Go編譯器的逃逸分析這三者之一確定有問題。
鎖衝突分析
衆所周知,頻繁的鎖衝突和高性能能夠說是水火不容。好消息是Go內建的鎖衝突分析支持能夠方便地發現這樣的鎖衝突。在程序中,能夠經過runtime.SetMutexProfileFraction()來設置採樣頻率,經過將其設爲一個高於0的值來開啓鎖衝突分析的數據收集。在程序結束前,經過runtime/pprof包的WriterTo方法將數據保存到指定文件:
runtime.SetMutexProfileFraction(int) pprof.Lookup("mutex").WriteTo(io.Writer, int)
所獲得的鎖衝突分析數據假設存爲mutex.pprof,它可用go tool pprof在命令行打開:
go tool pprof mutex.pprof
一樣使用list命令,能夠查看各個函數與方法的鎖衝突狀況。下圖是在Dragonboat中,使用鎖衝突分析之後,經過加大shard數量改善鎖衝突的實例。改善前:
(pprof) list nextKey . . 260:func (k *keyGenerator) nextKey() uint64 { . . 261: k.randMu.Lock() . . 262: v := k.rand.Uint64() . 5.33ms 263: k.randMu.Unlock() . . 264: return v . . 265:} . . 662:func (p *pendingProposal) nextKey(clientID uint64) uint64 { . 5.33ms 663: return p.keyg[clientID%p.ps].nextKey() . . 664:}
增多shard數以減小衝突後:
(pprof) list nextKey . . 260:func (k *keyGenerator) nextKey() uint64 { . . 261: k.randMu.Lock() . . 262: v := k.rand.Uint64() . 2.69ms 263: k.randMu.Unlock() . . 264: return v . . 265:} . . 662:func (p *pendingProposal) nextKey(clientID uint64) uint64 { . 2.69ms 663: return p.keyg[clientID%p.ps].nextKey() . . 664:}
火焰圖分析
有圈內專業人士認爲Raft論文是過去十年分佈式系統方向最重要論文,我的認爲,性能分析方面能獲此殊榮的是Brendan Gregg的火焰圖含其種類繁多的各變種(dtrace是14年前發佈的)。Go 1.11內建了對火焰圖的支持:
使用net/http/pprof包的web UI能夠方便的直接查看火焰圖
火焰圖提供了一種最直觀的CPU性能分析數據的呈現方式。下圖是Dragonboat曾遇到過的性能問題,在系統空閒的狀況下CPU佔用依舊較高。根據火焰圖提示,顯著的CPU資源被在反覆的調度切換時被浪費,這使得問題很快的定位到runtime自己。
須要指出,Brendan Gregg網站上給出的自行抓取採樣數據文件而後渲染出一個火焰圖svg的方法因爲其通用可擴展特性,能經過各類小技巧實現各類變種火焰圖,所以推薦採用Brendan Gregg網站給出的方法。本文標題圖片的火焰圖就是這樣一個例子,它是Dragonboat的內存訪問延遲分佈狀況,它顯示runtime部分(圖中最右側)內存性能作的很差,藍色表示延遲較高,暗示了將來基於runtime改進用戶程序性能獲得透明提高的空間依舊較大。
Benchmark性能分析
Go自帶官方的benchmark跑分庫,能夠對本身的軟件構建跑分測試,方便在不一樣環境對性能進行方便的分析。Dragonboat中,從內存分配的延遲與帶寬、Raft的單節點併發讀寫性能與Raft Log的落盤性能等等,均自帶跑分測試,屢次發現Go的Runtime變化帶來的性能惡化。
Benchmark的另外一大主要用途是能夠經過設置命令行開關,在不改變任何代碼的狀況下,方便地獲取前述的cpu.pprof、mem.pprof和mutex.pprof之類性能分析數據,供go tool pprof工具使用。
好比下述命令將運行名爲BenchmarkOne的這一跑分測試項,並分別將其運行過程的CPU、堆分配性能分析數據以及鎖衝突分析數據保存在cpu.pprof、mem.pprof與mutex.pprof中。
go test -v -run ^$ -bench=BenchmarkOne -cpuprofile cpu.pprof go test -v -run ^$ -bench=BenchmarkOne -memprofile mem.pprof go test -v -run ^$ -bench=BenchmarkOne -mutexprofile mutex.pprof
在一個大規模Go系統裏,建議對全部性能攸關部分抽象出其benchmark跑分測試用例,一來這是continuous integration在nightly build的時候應該測試、追蹤的,同時它提供本文所述的各種性能分析的無侵入式入口。
GC性能分析
Go的GC性能其實到最近也是一直被人無故攻擊的,一大緣由正是對不少用戶來講存在量化分析GC性能的盲點。事實上,GC性能的分析已經很方便。
使用runtime包的ReadMemStats()方法能夠得到系統MemStats數據,其中GCCPUFraction項是一個介於0-1.0之間的表明程序啓動至今write barrier之外GC佔用CPU時間的百分比數。Dragonboat該項始終在0.005(0.5%)左右。
GC的Stop-the-World停頓須要中止全部應用goroutine的運行,等於將整個應用暫時中止下來以供GC完成它的工做。這樣的停頓會直接影響請求響應延遲的離散度,對99.9%與99.99% percentile延遲性能影響較大。經過MemStats數據的PauseNs項,能夠獲取每一個GC週期的Stop-the-World停頓的上限。Dragonboat在Go 1.11和Go1.12的GC停頓圖以下,250微秒的停頓上限已很不錯:
最後,最粗暴但簡單有效的一點就是能夠在測試跑分的時候徹底關閉GC,以此對比性能上的提高,這一部分的性能差別正是被GC所消耗掉的。若是性能變化不大,那麼GC便顯然不是性能的瓶頸。在Dragonboat中,關閉GC已經基本沒法觀察到明顯的吞吐率上的提升。
總結
感謝閱讀本乾貨軟文,若是您尚未試用過開源的多組高性能Raft庫Dragonboat,歡迎您試用並給予反饋。
本文介紹了各個Go內建性能分析工具的用法,試圖以此勾劃出一個較大規模Go系統多方面性能分析與優化的方法。綜合而言:
篇幅關係,Go內建的trace支持本文沒有涉及,將在後續文章中單獨列出探討。