gopl-zh.github.com/ch11/ch11-05.md
2016-01-21 22:27:39 +08:00

67 lines
5.9 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

## 11.5. 剖析
測量基準對於衡量特定操作的性能是有幫助的但是當我們視圖讓程序跑的更快的時候我們通常併不知道從哪里開始優化。每個碼農都應該知道Donald Knuth在1974年的“Structured Programming with go to Statements”上所説的格言。雖然經常被解讀爲不重視性能的意思但是從原文我們可以看到不同的含義
> 毫無疑問效率會導致各種濫用。程序員需要浪費大量的時間思考或者擔心被部分程序的速度所榦擾實際上這些嚐試提陞效率的行爲可能産生強烈的負面影響特别是當調試和維護的時候。我們不應該過度糾結於細節的優化應該説約97%的場景:過早的優化是萬惡之源。
>
> 我們當然不應該放棄那關鍵的3%的機會。一個好的程序員不會因爲這個理由而滿足,他們會明智地觀察和識别哪些是關鍵的代碼;但是隻有在關鍵代碼已經被確認的前提下才會進行優化。對於判斷哪些部分是關鍵代碼是經常容易犯經驗性錯誤的地方,因此程序員普通使用的測量工具,使得他們的直覺很不靠譜。
當我們想仔細觀察我們程序的運行速度的時候,最好的技術是如何識别關鍵代碼。自動化的剖析技術是基於程序執行期間一些抽樣數據,然後推斷後面的執行狀態;最終産生一個運行時間的統計數據文件。
Go語言支持多種類型的剖析性能分析每一種關註不同的方面但它們都涉及到每個采樣記録的感興趣的一繫列事件消息每個事件都包含函數調用時函數調用堆棧的信息。內建的`go test`工具對幾種分析方式都提供了支持。
CPU分析文件標識了函數執行時所需要的CPU時間。當前運行的繫統線程在每隔幾毫秒都會遇到操作繫統的中斷事件每次中斷時都會記録一個分析文件然後恢複正常的運行。
堆分析則記録了程序的內存使用情況。每個內存分配操作都會觸發內部平均內存分配例程每個512KB的內存申請都會觸發一個事件。
阻塞分析則記録了goroutine最大的阻塞操作例如繫統調用、管道發送和接收還有獲取鎖等。分析庫會記録每個goroutine被阻塞時的相關操作。
在測試環境下隻需要一個標誌參數就可以生成各種分析文件。當一次使用多個標誌參數時需要當心,因爲分析操作本身也可能會影像程序的運行。
```
$ go test -cpuprofile=cpu.out
$ go test -blockprofile=block.out
$ go test -memprofile=mem.out
```
對於一些非測試程序也很容易支持分析的特性具體的實現方式和程序是短時間運行的小工具還是長時間運行的服務會有很大不同因此Go的runtime運行時包提供了程序運行時控製分析特性的接口。
一旦我們已經收集到了用於分析的采樣數據我們就可以使用pprof來分析這些數據。這是Go工具箱自帶的一個工具但併不是一個日常工具它對應`go tool pprof`命令。該命令有許多特性和選項,但是最重要的有兩個,就是生成這個概要文件的可執行程序和對於的分析日誌文件。
爲了提高分析效率和減少空間分析日誌本身併不包含函數的名字它隻包含函數對應的地址。也就是説pprof需要和分析日誌對於的可執行程序。雖然`go test`命令通常會丟棄臨時用的測試程序但是在啟用分析的時候會將測試程序保存爲foo.test文件其中foo部分對於測試包的名字。
下面的命令演示了如何生成一個CPU分析文件。我們選擇`net/http`包的一個基準測試爲例。通常是基於一個已經確定了是關鍵代碼的部分進行基準測試。基準測試會默認包含單元測試,這里我們用-run=NONE參數禁止單元測試。
```
$ go test -run=NONE -bench=ClientServerParallelTLS64 \
-cpuprofile=cpu.log net/http
PASS
BenchmarkClientServerParallelTLS64-8 1000
3141325 ns/op 143010 B/op 1747 allocs/op
ok net/http 3.395s
$ go tool pprof -text -nodecount=10 ./http.test cpu.log
2570ms of 3590ms total (71.59%)
Dropped 129 nodes (cum <= 17.95ms)
Showing top 10 nodes out of 166 (cum >= 60ms)
flat flat% sum% cum cum%
1730ms 48.19% 48.19% 1750ms 48.75% crypto/elliptic.p256ReduceDegree
230ms 6.41% 54.60% 250ms 6.96% crypto/elliptic.p256Diff
120ms 3.34% 57.94% 120ms 3.34% math/big.addMulVVW
110ms 3.06% 61.00% 110ms 3.06% syscall.Syscall
90ms 2.51% 63.51% 1130ms 31.48% crypto/elliptic.p256Square
70ms 1.95% 65.46% 120ms 3.34% runtime.scanobject
60ms 1.67% 67.13% 830ms 23.12% crypto/elliptic.p256Mul
60ms 1.67% 68.80% 190ms 5.29% math/big.nat.montgomery
50ms 1.39% 70.19% 50ms 1.39% crypto/elliptic.p256ReduceCarry
50ms 1.39% 71.59% 60ms 1.67% crypto/elliptic.p256Sum
```
參數`-text`用於指定輸出格式在這里每行是一個函數根據使用CPU的時間長短來排序。其中`-nodecount=10`標誌參數限製了隻輸出前10行的結果。對於嚴重的性能問題這個文本格式基本可以幫助査明原因了。
這個概要文件告訴我們HTTPS基準測試中`crypto/elliptic.p256ReduceDegree`函數占用了將近一半的CPU資源。相比之下如果一個概要文件中主要是runtime包的內存分配的函數那麽減少內存消耗可能是一個值得嚐試的優化策略。
對於一些更微妙的問題你可能需要使用pprof的圖形顯示功能。這個需要安裝GraphViz工具可以從 http://www.graphviz.org 下載。參數`-web`用於生成一個有向圖文件包含了CPU的使用和最熱點的函數等信息。
這一節我們隻是簡單看了下Go語言的分析據工具。如果想了解更多可以閲讀Go官方博客的“Profiling Go Programs”一文。