效能除錯:分析並優化 Go 程式

weixin_34320159發表於2018-09-02
1940396-277c6b78cdc5a747.jpg
image

效能除錯:分析並優化 Go 程式

1 時間和記憶體消耗

可以用這個便捷指令碼 xtime 來測量:

#!/bin/sh
/usr/bin/time -f '%Uu %Ss %er %MkB %C' "$@"

在 Unix 命令列中像這樣使用 xtime goprogexec,這裡的 progexec 是一個 Go 可執行程式,這句命令列輸出類似:56.63u 0.26s 56.92r 1642640kB progexec,分別對應使用者時間,系統時間,實際時間和最大記憶體佔用。

2 用 go test 除錯

如果程式碼使用了 Go 中 testing 包的基準測試功能,我們可以用 gotest 標準的 -cpuprofile-memprofile 標誌向指定檔案寫入 CPU 或 記憶體使用情況報告。

使用方式:go test -x -v -cpuprofile=prof.out -file x_test.go

編譯執行 x_test.go 中的測試,並向 prof.out 檔案中寫入 cpu 效能分析資訊。

3 用 pprof 除錯

你可以在單機程式 progexec 中引入 runtime/pprof 包;這個包以 pprof 視覺化工具需要的格式寫入執行時報告資料。對於 CPU 效能分析來說你需要新增一些程式碼:

var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")

func main() {
    flag.Parse()
    if *cpuprofile != "" {
        f, err := os.Create(*cpuprofile)
        if err != nil {
            log.Fatal(err)
        }
        pprof.StartCPUProfile(f)
        defer pprof.StopCPUProfile()
    }

程式碼定義了一個名為 cpuprofile 的 flag,呼叫 Go flag 庫來解析命令列 flag,如果命令列設定了 cpuprofile flag,則開始 CPU 效能分析並把結果重定向到那個檔案。(os.Create 用拿到的名字建立了用來寫入分析資料的檔案)。這個分析程式最後需要在程式退出之前呼叫 StopCPUProfile 來重新整理掛起的寫操作到檔案中;我們用 defer 來保證這一切會在 main 返回時觸發。

現在用這個 flag 執行程式:progexec -cpuprofile=progexec.prof

然後可以像這樣用 gopprof 工具:gopprof progexec progexec.prof

gopprof 程式是 Google pprofC++ 分析器的一個輕微變種;關於此工具更多的資訊,參見https://github.com/gperftools/gperftools

如果開啟了 CPU 效能分析,Go 程式會以大約每秒 100 次的頻率阻塞,並記錄當前執行的 goroutine 棧上的程式計數器樣本。

此工具一些有趣的命令:

1)topN

用來展示分析結果中最開頭的 N 份樣本,例如:top5
它會展示在程式執行期間呼叫最頻繁的 5 個函式,輸出如下:

Total: 3099 samples
626 20.2% 20.2% 626 20.2% scanblock
309 10.0% 30.2% 2839 91.6% main.FindLoops

第 5 列表示函式的呼叫頻度。

2)webweb 函式名

該命令生成一份 SVG 格式的分析資料圖表,並在網路瀏覽器中開啟它(還有一個 gv 命令可以生成 PostScript 格式的資料,並在 GhostView 中開啟,這個命令需要安裝 graphviz)。函式被表示成不同的矩形(被呼叫越多,矩形越大),箭頭指示函式呼叫鏈。

3)list 函式名weblist 函式名

展示對應函式名的程式碼行列表,第 2 列表示當前行執行消耗的時間,這樣就很好地指出了執行過程中消耗最大的程式碼。

如果發現函式 runtime.mallocgc(分配記憶體並執行週期性的垃圾回收)呼叫頻繁,那麼是應該進行記憶體分析的時候了。找出垃圾回收頻繁執行的原因,和記憶體大量分配的根源。

為了做到這一點必須在合適的地方新增下面的程式碼:

var memprofile = flag.String("memprofile", "", "write memory profile to this file")
...

CallToFunctionWhichAllocatesLotsOfMemory()
if *memprofile != "" {
    f, err := os.Create(*memprofile)
    if err != nil {
        log.Fatal(err)
    }
    pprof.WriteHeapProfile(f)
    f.Close()
    return
}

用 -memprofile flag 執行這個程式:progexec -memprofile=progexec.mprof

然後你可以像這樣再次使用 gopprof 工具:gopprof progexec progexec.mprof

top5list 函式名 等命令同樣適用,只不過現在是以 Mb 為單位測量記憶體分配情況,這是 top 命令輸出的例子:

Total: 118.3 MB
    66.1 55.8% 55.8% 103.7 87.7% main.FindLoops
    30.5 25.8% 81.6% 30.5 25.8% main.*LSG·NewLoop
    ...

從第 1 列可以看出,最上面的函式佔用了最多的記憶體。

同樣有一個報告記憶體分配計數的有趣工具:

gopprof --inuse_objects progexec progexec.mprof

對於 web 應用來說,有標準的 HTTP 介面可以分析資料。在 HTTP 服務中新增

import _ "http/pprof"

會為 /debug/pprof/ 下的一些 URL 安裝處理器。然後你可以用一個唯一的引數——你服務中的分析資料的 URL 來執行 gopprof 命令——它會下載並執行線上分析。

gopprof http://localhost:6060/debug/pprof/profile # 30-second CPU profile
gopprof http://localhost:6060/debug/pprof/heap # heap profile
1940396-82ab8593fcbe7090.jpg
image

相關文章