11.5. 剖析

基準測試（Benchmark）對於衡量特定操作的性能是有幫助的，但是當我們試圖讓程序跑的更快的時候，我們通常並不知道從哪裡開始優化。每個碼農都應該知道Donald Knuth在1974年的“Structured Programming with go to Statements”上所說的格言。雖然經常被解讀為不重視性能的意思，但是從原文我們可以看到不同的含義：

毫無疑問，對效率的片面追求會導致各種濫用。程序員會浪費大量的時間在非關鍵程序的速度上，實際上這些嘗試提升效率的行為反倒可能產生很大的負面影響，特別是當調試和維護的時候。我們不應該過度糾結於細節的優化，應該說約97%的場景：過早的優化是萬惡之源。

當然我們也不應該放棄對那關鍵3%的優化。一個好的程序員不會因為這個比例小就裹足不前，他們會明智地觀察和識別哪些是關鍵的代碼；但是僅當關鍵代碼已經被確認的前提下才會進行優化。對於很多程序員來說，判斷哪部分是關鍵的性能瓶頸，是很容易犯經驗上的錯誤的，因此一般應該藉助測量工具來證明。

當我們想仔細觀察我們程序的運行速度的時候，最好的方法是性能剖析。剖析技術是基於程序執行期間一些自動抽樣，然後在收尾時進行推斷；最後產生的統計結果就稱為剖析數據。

Go語言支持多種類型的剖析性能分析，每一種關注不同的方面，但它們都涉及到每個採樣記錄的感興趣的一系列事件消息，每個事件都包含函數調用時函數調用堆棧的信息。內建的go test工具對幾種分析方式都提供了支持。

CPU剖析數據標識了最耗CPU時間的函數。在每個CPU上運行的線程在每隔幾毫秒都會遇到操作系統的中斷事件，每次中斷時都會記錄一個剖析數據然後恢復正常的運行。

堆剖析則標識了最耗內存的語句。剖析庫會記錄調用內部內存分配的操作，平均每512KB的內存申請會觸發一個剖析數據。

阻塞剖析則記錄阻塞goroutine最久的操作，例如系統調用、管道發送和接收，還有獲取鎖等。每當goroutine被這些操作阻塞時，剖析庫都會記錄相應的事件。

只需要開啟下面其中一個標誌參數就可以生成各種分析文件。當同時使用多個標誌參數時需要當心，因為一項分析操作可能會影響其他項的分析結果。

$ go test -cpuprofile=cpu.out
$ go test -blockprofile=block.out
$ go test -memprofile=mem.out

對於一些非測試程序也很容易進行剖析，具體的實現方式，與程序是短時間運行的小工具還是長時間運行的服務會有很大不同。剖析對於長期運行的程序尤其有用，因此可以通過調用Go的runtime API來啟用運行時剖析。

一旦我們已經收集到了用於分析的採樣數據，我們就可以使用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”一文。