Go 性能分析工具從入門到精通

概述

Go 語言自帶的 pprof 是一種性能分析工具，用於幫助開發者分析和優化程序的性能，它可以提供關於 CPU 耗時、內存分配、網絡 IO、系統調用、阻塞等待等方面的詳細信息。

快速開始

我們來通過一個小例子直觀的感受下 pprof 的使用方法，本文所有示例代碼運行環境是 go1.20 darwin/arm64。

示例程序

package main

import (
 "bytes"
 "log"
 "math/rand"
 "net/http"
 _ "net/http/pprof" // 開啓 pprof
 "time"
)

// 換成一個隨機字符串並返回對應的緩衝區
func genRandomBytes() *bytes.Buffer {
 var buff bytes.Buffer
 for i := 1; i < 10000; i++ {
  buff.Write([]byte{'0' + byte(rand.Intn(10))})
 }
 return &buff
}

func main() {
 go func() {
  for {
   // 循環調用生成字符串方法，模擬 CPU 負載
   for i := 0; i < 1000; i++ {
    _ = genRandomBytes()
   }
   time.Sleep(time.Second)
  }
 }()

 // 程序綁定到 6060 端口
 // pprof 結果也必須通過該接口獲取
 log.Fatal(http.ListenAndServe("127.0.0.1:6060", nil))
}

查看程序 pprof 結果

1. 啓動程序

$ go build main.go && ./main

2. 瀏覽器訪問

通過瀏覽器打開下面的鏈接，可以看到 pprof 的實時採樣數據。

http://127.0.0.1:6060/debug/pprof/

正常情況下，我們可以看到如下頁面:

3. 獲取某個指標的採樣數據

例如我們想要拿到 CPU 的採樣數據，可以點擊圖中的 profile 鏈接，此時會進入默認的 30 秒採樣階段 (瀏覽器表現爲不停轉圈)，30 秒之後，瀏覽器會彈出下載窗口， 提示你是否要保存名稱爲 profile 的採樣文件。

這裏我們通過 CURL 的方式來直接下載，讀者可以利用等待 CURL 的時間大致瞭解一下頁面上的幾個採樣類型。

# 下載 CPU 樣本數據，並保存到 cpu.pprof 文件中

$ curl -sS "http://127.0.0.1:6060/debug/pprof/profile?seconds=30" -o cpu.pprof

4. 分析採樣數據

Go 語言自帶的命令行工具集中的 go tool pprof 可以對樣本數據進行分析。

# 對 cpu.pprof 文件進行分析

$ go tool pprof main cpu.pprof

輸入上述命令後，進入 pprof 的專用命令行中:

...
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) 等待用戶輸入

5. 命令行工具操作方法

此時我們可以輸入 help, 看一下相關的操作提示 (Tips: 我們無需死記硬背命令行參數，使用 pprof 的時候輸入 help 尋找對應的參數即可):

# 輸入 top 後，命令行輸出結果如下

  Commands:
    ...

    top              Outputs top entries in text form
    topproto         Outputs top entries in compressed protobuf format
    traces           Outputs all profile samples in text form
    tree             Outputs a text rendering of call graph
    web              Visualize graph through web browser

    ...

  Options:

...

這裏以 top 參數爲例，輸出採樣數據 CPU 使用 top 5 的調用:

(pprof) top 5

# 輸出結果如下

Showing nodes accounting for 4090ms, 75.74% of 5400ms total
Dropped 56 nodes (cum <= 27ms)
Showing top 5 nodes out of 53
      flat  flat%   sum%        cum   cum%
    1290ms 23.89% 23.89%     2920ms 54.07%  math/rand.(*lockedSource).Int63
    1260ms 23.33% 47.22%     1260ms 23.33%  sync.(*Mutex).Unlock (inline)
     740ms 13.70% 60.93%     3710ms 68.70%  math/rand.(*Rand).Int31n
     490ms  9.07% 70.00%      870ms 16.11%  bytes.(*Buffer).Write
     310ms  5.74% 75.74%      310ms  5.74%  math/rand.(*rngSource).Uint64 (inline)

通過上面的輸出結果，可以很清晰地看到消耗最多 CPU 資源的 5 個調用方法。

這裏需要注意的是第三列的 sum% 的字段，表示的是前 N 行的 flat% 列的數值總和，例如第三行的的 60.93% 就表示:

第一行 + 第二行 + 第三行 = 23.89% + 23.33% + 13.70% = 60.93%

# 通過 cum 列排序
(pprof) top 5 -cum

...

列屬性

下面對每列表示的數據做一個簡單的概述:

flat 和 cum 的區別在於: flat 只統計函數自身的 CPU 使用時間，不包括調用其他函數的時間，而 cum 則包括了函數自身的時間和調用其他函數的時間。

其他用法

剛纔的示例過程是先使用 CURL 下載採樣數據，然後使用 pprof 命令工具進行分析，可以將這兩個步驟合併到一個步驟中。

$ go tool pprof "http://127.0.0.1:6060/debug/pprof/profile?seconds=30"

上述命令會在採樣結果保存完成後，自動進入 pprof 的專用命令行中。

採樣數據列表

hCSFim

主要參數

內存分析字段說明

通過瀏覽器直接訪問 http://127.0.0.1:6060/debug/pprof/heap?debug=1, 然後加載頁面底部，可以看到內存相關的數據，我們選擇一些常用的指標進行說明。

# 示例內存分析數據
# 對應的標準庫中的對象爲 runtime.MemStats{}

# runtime.MemStats
# Alloc = 1382056
# TotalAlloc = 2855089694704
# Sys = 19334408
# Lookups = 0
# Mallocs = 871957108
# Frees = 871955873
# HeapAlloc = 1382056
# HeapSys = 11993088
# HeapIdle = 9977856
# HeapInuse = 2015232
# HeapReleased = 7012352
# HeapObjects = 1235
# Stack = 589824 / 589824
...

O6QW2j

內存關鍵指標

排查內存相關問題時，除了關注內存使用和閒置相關參數外，還要關注 GC 頻率、GC 時間等參數。

讀者可以在 pprof 頁面上點擊不同的鏈接來查看不同的採樣數據，需要注意的是: profile 和 trace 兩個指標默認的採樣時間是 30 秒，其他指標都是即時的 (每次刷新顯示不同的數據)。

graphiv

pprof 可以生成樣本數據分析圖 (如 CPU 火焰圖) 達到更好的可觀測性，但是生成的圖需要使用 graphiv 進行渲染，如果要運行 pprof 的機器還未安裝 graphviz, 可以參考 官網的安裝教程 [1] 進行安裝。

啓動 Web UI

雖然 pprof 提供的命令行操作方式已經非常方便，但是如果我們希望使用更加直觀的 UI 方式來展現採樣分析結果，可以使用 Web UI 功能。Web UI 提供了和 pprof 命令行同樣的功能，但是可觀測性更強。

1. 通過 -http 參數

$ go tool pprof -http=127.0.0.1:6061 "http://127.0.0.1:6060/debug/pprof/profile?seconds=30"

# 輸出如下
Fetching profile over HTTP from http://127.0.0.1:6060/debug/pprof/profile?seconds=30
Saved profile in /home/stars/pprof/pprof.main.samples.cpu.004.pb.gz
Serving web UI on http://127.0.0.1:6061
...

上述命令會在採樣結果保存完成後，新啓動一個 Web Server (端口爲 6061)，自動打開瀏覽器並跳轉到 http://127.0.0.1:6061/ui/。

2. 通過 web 參數

輸入 go tool pprof main cpu.pprof 進入到 pprof 的專用命令行中，然後輸入參數 web。

Entering interactive mode (type "help" for commands, "o" for options)
(pprof) web

# 輸出如下
...
+ Start "/tmp/pprof001.svg"
...

上述命令會生成一個 SVG 文件，然後自動在瀏覽器打開，但是打開的頁面中只有一個圖片，沒有其他功能 (所以後文中都採用剛纔的第一種方法作爲 Web UI 打開方式)。

Web UI 功能概覽

針對單個採樣結果的分析，Web UI 提供了非常強大的功能，下面通過示例圖來演示。

所有的功能菜單都在導航欄，直接選擇對應的數據即可。

top 函數

功能和 pprof 命令行中的 top 一樣，顯示採樣 top N 的數據:

火焰圖

基於 Brendan Gregg 大佬發明的火焰圖，根據圖中的顏色深淺，調用鍊形狀的長短，幾乎可以瞬間定位到出現問題的方法。

功能和 pprof 命令行中的 top 一樣，顯示採樣 top N 的數據:

peek

可以看到採樣分析數據和對應的代碼。

source

可以看到採樣分析數據和對應的代碼函數相關信息。

其他菜單

限於篇幅，其他菜單功能這裏就不一一展示了，讀者可以在 Web UI 頁面自行研究。

trace 採樣

寫到這裏，pprof 數據採樣分析差不多就介紹完了，然後這裏再簡單介紹一下 trace 數據採樣分析，兩者的區別在於:

和基於毫秒頻率的 pprof 定時數據採樣相比，基於事件的 trace 精確到了納秒，因此對系統的性能影響還是非常大的。 一般情況下不需要使用 trace 來定位性能問題，除非是需要獲取運行時的程序數據，例如 goroutine 調度、阻塞、GC 等。

採樣命令參數

可以直接將路徑中的 path 參數指定爲 trace, 即可開始 trace 採樣。

# trace 採樣數據，時間 30 秒
$ curl -sS "http://127.0.0.1:6060/debug/pprof/trace?seconds=30" -o trace.out

採樣數據完成後，可以通過 go tool trace 命令打開採樣文件:

$ go tool trace trace.out

# 輸入如下:

2023/07/29 11:44:53 Parsing trace...
2023/07/29 11:44:53 Splitting trace...
2023/07/29 11:44:53 Opening browser. Trace viewer is listening on http://127.0.0.1:64552

輸入上述命令之後，會啓動一個 Web Server (端口號隨機), 並且自動在瀏覽器中打開頁面:

trace Web UI

trace Web UI 和 pprof Web UI 提供的功能類似，只不過各功能點的鏈接分散在了頁面中，而不是集中到頂部的導航區域。

點擊頁面的 View trace 鏈接，可以顯示 goroutine、內存分析、操作系統線程調用的相關信息。

輸入 shift + / 組合鍵，可以彈出 “使用幫助” 窗口:

例如我們可以按 w 鍵縮小時間單位粒度，按 s 鍵放大時間單位粒度。

點擊頁面的 Goroutine analysis 鏈接，可以顯示每個 goroutine 的編號、調用時長、GMP 調度、網絡 IO、阻塞、GC 等方面的數據。

點擊 Profiles 區域的鏈接，可以查看程序的網絡 IO、同步、系統調用、GMP 調度等方面的數據。

限於篇幅，頁面中其他鏈接功能這裏就不一一展示了，讀者可以在 Web UI 頁面自行研究。

比較優化前和優化後

我們可以在優化代碼之前先生成一個 pprof 採樣文件，在完成代碼優化之後再生成一個 pprof 採樣文件，通過比較兩者的差異結果來證明我們的優化工作是否有效。 需要注意的是，優化前後必須使用相同的運行環境，保證採樣數據的可比性。

# 優化前採樣
$ curl -sS "http://127.0.0.1:6060/debug/pprof/profile?seconds=30" -o cpu_before.pprof

# 優化後採樣
$ curl -sS "http://127.0.0.1:6060/debug/pprof/profile?seconds=30" -o cpu_after.pprof

# 比較差異 (Web UI)
$ go tool pprof -http=127.0.0.1:6062 --base cpu_before.pprof cpu_after.pprof

上述命令會新啓動一個 Web Server (端口爲 6062)，自動打開瀏覽器並跳轉到 http://127.0.0.1:6062/ui/, 通過 UI 我們可以很直觀地看到兩個採樣數據的差異。

非 Web 服務使用 pprof

在非 Web 服務中 (如後臺服務) 使用 pprof 時，可以使用標準庫中的 runtime/pprof 包, 前文示例中的 net/http/pprof 包本質也是對 runtime/pprof 包的一層 Web 封裝。

示例代碼

package main

import (
 "log"
 "math/rand"
 "os"
 "runtime/pprof"
 "sort"
)

func main() {
 // 設置採樣數據保存文件
 file := "/tmp/runtime_cpu.pprof"
 f, _ := os.OpenFile(file, os.O_CREATE|os.O_RDWR, 0644)

 defer func() {
  err := f.Close()
  if err != nil {
   log.Fatalln(err)
  }
 }()

 // 開始 CPU 採樣
 err := pprof.StartCPUProfile(f)
 if err != nil {
  panic(err)
 }
 defer pprof.StopCPUProfile()

 // 每次生成 10000 個隨機數字進行排序
 for i := 0; i < 1024; i++ {
  nums := genRandomNumbers(10000)
  sort.Slice(nums, func(i, j int) bool {
   return nums[i] < nums[j]
  })
 }
}

// 生成隨機數切片
func genRandomNumbers(n int) []int {
 nums := make([]int, n)
 for i := 1; i < n; i++ {
  nums[i] = rand.Int()
 }
 return nums
}

直接運行:

$ go run main.go

程序執行結束後，會生成一個 CPU 的採樣文件: /tmp/runtime_cpu.pprof, 我們繼續使用 Web UI 打開:

$ go tool pprof -http=:6062 /tmp/runtime_cpu.pprof

打開後的頁面如圖所示，功能點在前文 Web UI 小節已經講過了，這裏不再贅述。

採樣其他指標數據

除了採樣 CPU 的數據，也可以通過指定參數來採樣其他數據，因爲標準庫的採樣方法使用起來有些繁瑣，我們這裏使用開源的 profile[2] 作爲演示。

在剛纔的例子代碼基礎上稍作修改，將 CPU 採樣改爲內存採樣，代碼如下:

package main

import (
 "github.com/pkg/profile"
 "math/rand"
 "sort"
)

func main() {
 // 開始內存採樣
 defer profile.Start(profile.MemProfile, profile.MemProfileRate(1)).Stop()

 // 每次生成 10000 個隨機數字進行排序
 for i := 0; i < 1024; i++ {
  nums := genRandomNumbers(10000)
  sort.Slice(nums, func(i, j int) bool {
   return nums[i] < nums[j]
  })
 }
}

// 生成隨機數切片
func genRandomNumbers(n int) []int {
 nums := make([]int, n)
 for i := 1; i < n; i++ {
  nums[i] = rand.Int()
 }
 return nums
}

直接運行:

$ go run main.go

輸出結果如下 (具體路徑取決於操作系統):

2023/07/29 11:54:55 profile: memory profiling enabled (rate 1), /tmp/profile3144997289/mem.pprof
2023/07/29 11:54:56 profile: memory profiling disabled, /tmp/profile3144997289/mem.pprof

使用 Web UI 打開內存採樣文件，數據頁面展示如下，讀者可以對比一下和 CPU 採樣數據頁面的差異。

$ go tool pprof -http=:6062 /tmp/profile3144997289/mem.pprof

採樣其他指標數據

參考官方的示例代碼。

package main

import (
 "flag"
 "github.com/pkg/profile"
)

func main() {
 // use the flags package to selectively enable profiling.
 mode := flag.String("profile.mode", "", "enable profiling mode, one of [cpu, mem, mutex, block]")
 flag.Parse()
 switch *mode {
 case "cpu":
  defer profile.Start(profile.CPUProfile).Stop()
 case "mem":
  defer profile.Start(profile.MemProfile).Stop()
 case "mutex":
  defer profile.Start(profile.MutexProfile).Stop()
 case "block":
  defer profile.Start(profile.BlockProfile).Stop()
 default:
  // do nothing
 }
}

通過單元測試採樣

除了 Web 和後臺服務中可以採樣，在單元測試中也可以採樣:

# CPU 採樣
$ go test -v -bench="XXX$" -run='XXX$' -cpuprofile=cpu.pprof .

# 內存 採樣
$ go test -v -bench="XXX$" -run='XXX$' -cpuprofile=cpu.pprof .

# trace 採樣
$ go test -v -bench="XXX$" -run='XXX$' -trace=trace.out

限於篇幅，數據採樣過程和分析過程這裏不再演示，感興趣的讀者直接參照前文的示例進行試驗。

最佳實踐

總結

本文主要講述了 Go 語言自帶的性能分析套件 pprof 和 trace, 再加上以前的這兩篇文章 GODEBUG 環境變量詳解 [6],Go Delve 調試必知必會 [7], 可以將這幾項工具組合成一把 Go 語言程序調試的 “瑞士軍刀”。

Reference

擴展閱讀

鏈接

[1] 官網的安裝教程: https://graphviz.org/download/

[2] profile: https://github.com/pkg/profile

[3] 這篇文章中提到的: https://dbwu.tech/posts/golang_goroutine_leak/

[4] Gin pprof: https://github.com/gin-contrib/pprof

[5] 這個示例程序: https://stackoverflow.com/a/19591389/12203967

[6] GODEBUG 環境變量詳解: https://dbwu.tech/posts/golang_godebug/

[7] Go Delve 調試必知必會: https://dbwu.tech/posts/golang_delve/

[8] pprof: https://go.dev/blog/pprof

[9] google/pprof: https://github.com/google/pprof/blob/main/doc/README.md

[10] profile: https://github.com/pkg/profile

[11] Go 語言高性能 Tips: https://dbwu.tech/posts/golang_performance_tips/

[12] fgprof: https://github.com/felixge/fgprof

[13] off cpu analysis: https://www.brendangregg.com/offcpuanalysis.html

[14] pprof++: A Go Profiler with Hardware Performance Monitoring: https://www.uber.com/en-HK/blog/pprof-go-profiler/

[15] GopherCon 2018 - Allocator Wrestling: https://about.sourcegraph.com/blog/go/gophercon-2018-allocator-wrestling

[16] Program Profiling: https://www.practical-go-lessons.com/chap-36-program-profiling

[17] Go 語言 - 計算密集型服務 性能優化: https://segmentfault.com/a/1190000041602269

[18] Go 語言 - IO 密集型服務 性能優化: https://segmentfault.com/a/1190000041637173

[19] Go 系統性能繞坑工具與方法 - 基於實例的帶逛: https://zhuanlan.zhihu.com/p/60042567

[20] go-execution-tracer: https://blog.gopheracademy.com/advent-2017/go-execution-tracer/

[21] go-perfbook: https://github.com/dgryski/go-perfbook

[22] 最常用的調試 golang 的 bug 以及性能問題的實踐方法: https://www.yuque.com/aceld/golang/ga6pb1#d6b3f4b1

[23] 快速定位線上性能問題：Profiling 在微服務應用下的落地實踐: https://www.infoq.cn/article/eqazvi015lokje9ejmlk

[24] pprof-web: https://github.com/zjc17/pprof-web/

[25] fgprof: https://github.com/felixge/fgprof

[26] profilinggo: https://github.com/samonzeweb/profilinggo

[27] Cloud Profiler: https://cloud.google.com/profiler

[28] 對 Go 程序進行可靠的性能測試: https://changkun.de/research/talks/gobench.pdf

[29] 尋找性能瓶頸: https://xargin.com/go-perf-optimization/#%E5%AF%BB%E6%89%BE%E6%80%A7%E8%83%BD%E7%93%B6%E9%A2%88

[30] 無人值守的自動 dump(二): https://xargin.com/autodumper-for-go-ii/

[31] self-aware Golang profile dumper: https://github.com/mosn/holmes

本文由 Readfog 進行 AMP 轉碼，版權歸原作者所有。
來源：https://mp.weixin.qq.com/s/uC1EHFusa3l7uqOn80vfMg

猜你喜歡