Go CPU profiler 內幕
Go 是那種自帶 profiler (分析器) 的語言之一。它的運行時包含強大的自成一派的各種 profiler。其它語言,比如 Ruby、Python 和 Node.js, 它們也包含 profiler 或者一些用來編寫 profiler 的 API,但是與 Go 的開箱即用的 profiler 相比,它們提供的 profiler 功能有限。如果你想多瞭解 Go 提供的這些可觀察工具的情況,我強烈推薦你閱讀 Felix Geisendörfer 的 The Busy Developer’s Guide to Go Profiling, Tracing and Observability[1]。
作爲一個好奇的工程師,我喜歡挖掘事物在底層上的工作方式,我一直想去學習 Go CPU profiler 底層 · 是怎麼工作的。這篇文章就是此次探索的結果。每當我閱讀 Go 運行時代碼時,我總是學到到一些新東西,這次也不例外。
基本知識
當前市面上存在兩種類型的 profiler:
-
tracing(跟蹤): 當預定義的事件發生時進行測量。例如,函數被調用,函數退出等等。
-
Sampling(採樣): 定期進行測量。
Go CPU profiler 是一個採樣分析器。當然 Go 還有一個執行跟蹤器(execution tracer),它是 tracing profiler, 跟蹤某些事件,例如請求鎖,GC 相關事件等等。
sampling profiler 通常由兩個基本部分組成:
-
採樣器 (sampler):定期調用回調,並且通常分析數據收集堆棧跟蹤 (stack trace)。不同的 profiler 使用不同的策略來觸發回調。
-
數據收集:這是 profiler 收集其數據的地方:它可能會消耗內存或調用計數,基本上是與堆棧跟蹤關聯的一些指標。
關於其它 profiler 如何工作的小調查
Linux perf 使用 PMU(Performance Monitor Unit) 計數器進行採樣。你可以指示 PMU 在某些事件發生 N 次後生成中斷,例如,每 1000 個 CPU 時鐘週期執行一次。 丹尼斯 · 巴赫瓦洛夫(Denis Bakhvalov)撰寫的一篇詳細文章 [2] 解釋瞭如何像 perf 和 VTune 工具使用 PMU 計數器來實現這一目標。一旦定期觸發數據收集回調函數,剩下的工作就是收集堆棧跟蹤並正確聚合它們。爲了完整起見,Linux perf 使用 perf_event_open(PERF_SAMPLE_STACK_USER,...) 收集堆棧信息。捕獲的堆棧跟蹤通過 mmap 環形緩衝區寫入用戶空間。
pyspy[3] 和 rbspy[4] 是著名的 Python 和 Ruby 的 sampling profiler。它們都作爲外部進程運行,並定期讀取目標應用程序內存以捕獲正在運行的線程的堆棧跟蹤。在 Linux 中,他們使用 process_vm_readv 方法收集數據,如果我沒有記錯的話,這個 API 在內存讀取期間會將目標應用程序暫停幾毫秒。然後,它們在讀取的內存中跟蹤指針,以查找當前正在運行的線程結構和堆棧跟蹤信息。正如人們可能猜到的那樣,這是一種容易出錯且複雜的方法,但效果非常好。如果我沒記錯的話,pyflame[5] 也使用類似的方法。
最近的 profiler,如 Parca[6](還有其它幾個)使用 eBPF[7]。eBPF 是一項最新的技術,允許在內核 VM 中運行用戶空間代碼。這是一項出色的技術,用於安全、網絡和可觀察性等許多領域。我強烈建議閱讀有關 eBPF 的一些信息,這是一個非常大的話題,遠遠超出了這篇文章的範圍。
如何定期觸發探查器?
Go CPU profiler 是一個採樣分析器。在 Linux 中,Go 運行時使用 setitimer/timer_create/timer_settime 來設置 SIGPROF 信號處理器。此處理器按 runtime.SetCPUProfileRate 設置的週期間隔觸發,默認情況下是 100Mz(10 毫秒)。順便說一句,在 Go 1.18 之前,Go CPU profiler 的採樣器存在一些嚴重的問題,你可以在這裏 [8] 看到這些問題的細節。我們記錯的話,settimer API 是 Linux 中每個線程觸發基於時間的信號的推薦方法: 從技術上講,它的工作原理就像你期望的進程信號處理機制一樣。但它並不是多核分析的良好機制。
讓我們看看如何手動啓用 Go CPU profiler:
f, err := os.Create("profile.pb.gz")
if err != nil {
...
}
if err := pprof.StartCPUProfile(f); err != nil {
...
}
defer pprof.StopCPUProfile()
一旦 pprof.StartCPUProfile 被調用,Go 運行時就可以按照指定的時間間隔產生 SIGPROF 信號。Linux 內核嚮應用程序中正在運行的線程之一發送 SIGPROF 信號。由於 Go 使用非阻塞 I/O,等待 I/O 的 goroutine 不會被統計爲 running 的 goroutine,Go CPU profiler 不會捕獲這類 goroutine 的數據。順便說一句:這是實現 fgprof[9] 的基本原因。 fgprof 使用 runtime.GoroutineProfile 獲取 on-CPU 和 off-CPU 的數據。
A picture is worth a thousand words; below is how Go runtime handles SIGPROF signal:
一圖勝千言。以下是 Go 運行時處理 SIGPROF 信號的方式:
profiler 如何收集數據?
一個一個隨機的運行的 goroutine 收到 SIGPROF 信號,它會被中斷並執行信號處理程序。中斷的 goroutine 的堆棧跟蹤在此信號處理程序的上下文中獲取到,然後與當前 profiler 標籤 [10] 一起保存到 lock-free[11] 日誌結構中(每個捕獲的堆棧跟蹤都可以與自定義標籤相關聯,您可以稍後對其進行過濾)。這個特殊的 lock-free 結構被命名爲 profBuf,它在 runtime/profbuf.go[12] 定義,並詳細解釋了它是如何工作的。它是一個單寫單讀 (single-writer,single-reader) 的 lock-free 的 ringbuffer,類似於此處介紹 [13] 的數據結構。Writer 是信號處理器,而 reader 是 profileWriter goroutine,profileWriter goroutine 定期的讀取此緩衝區並將結果聚合到最終的 hashmap。這個最終的 hashmap 被命名爲 profMap, 定義在 runtime/pprof/map.go[14]。
以下是把剛纔介紹的組合在一起的一個可視化圖:
可以看到,最終的結構與常規的 pprof.Profile 對象非常相似:它是一個 hashmap, 其中的鍵是堆棧跟蹤 + 標籤,值是在應用程序中觀察到此調用堆棧的次數。當 pprof.StopCPUProfile() 被調用時,分析就會停止,profileWriter goroutine 調用 build()[15]。這個函數負責寫 profMap 結構到 io.Writer,此 Writer 由 pprof.StartCPUProfile 初始調用的時候提供。基本上這就是最終的 pprof.Profile[16] 產生的過程。
profileWriter 的僞代碼可能對你理解這個過程更有幫助:
func profileWriter(w io.Writer) {
...
for {
time.Sleep(100 * time.Millisecond)
data, tags := readProfile()
if e := b.addCPUData(data, tags); e != nil {
...
}
if profilerStopped {
break
}
}
...
b.build() // -> generates final pprof.Profile
...
}
一旦我對設計有了高層次的瞭解,我就會問自己以下問題:爲什麼 Go 爲了實現一個獨特的 lock-free 結構而花費了那麼大精力只爲了保存臨時分析數據?爲什麼不定期將所有內容寫入 hashmap?
答案就在設計本身。
首先看的第一件事就是 SIGPROF 處理器就是禁用內存分派。此外,profiler 代碼不包含熱門和鎖,甚至堆棧的最大深度也是硬編碼的。截止 Go 1.19, 最大深度是 64[17]。所有這些細節都可以爲 profiler 提供更高效、更可預測的開銷。低且可預測的性能是生產就緒型 profiler 的關鍵。
開銷
根據設計,profiler 開銷是恆定的?嗯,這要視情況而定。讓我解釋一下原因:在單個 profiler 中斷中,會發生以下情況:
-
一個隨機運行的 goroutine 執行上下文切換來運行 SIGPROF 處理器,
-
執行堆棧遍歷,並且 Go 運行時將堆棧跟蹤保存到 lock-free ring buffer 中,
-
goroutine 恢復。
從理論上講,似乎上述所有內容都應該在恆定時間內運行,因爲沒有發生內存分配和鎖競爭。我記得所有的這是真的:以上所有事情都發生在大約 1 微秒(在典型的 CPU 上)。但是,在實踐中,情況變得更糟。如果您搜索 “Go CPU profiler 的開銷”,您將看到從 %0.5 到 %1-%5 的數字(沒有發現關於這個數字的公開提及,也沒有適當的證據)。這背後的原因主要與 CPU 的工作方式有關。現代 CPU 是複雜的怪獸。它們會積極地使用緩存。典型的單 CPU 內核具有三層緩存:L1、L2 和 L3。當特定的 CPU 密集型代碼正在運行時,這些緩存將得到充分利用。對於某些應用程序而言,高緩存利用率尤其如此,在這些應用程序中,小(可以放入緩存中的數據)和順序數據被大量讀取。
一個很好的例子是矩陣乘法:在矩陣乘法期間,CPU 大量訪問內存中順序存儲的獨立單元格。這些緩存友好型應用程序可能會爲採樣 profiler 產生嚴重的開銷。雖然很容易使用 prof 做一些基準測試來驗證這一說法,但這超出了這篇文章的範圍。
綜上所述,Go 運行時在保持 profiler 開銷儘可能可預測和儘可能低方面做得很好。如果你不相信我,你有所質疑,也許下面引用的一個討論對話 [18] 可以說服你:
在谷歌,我們持續分析 Go 生產服務,這樣做是安全的。
另一個來自 datadog 的持續 profiler 的代碼提交 [19] 也可以印證這一點:
在許多高容量內部工作負荷上測試此默認值後 (默認開啓 profiler),我們已確定此默認值對生產是安全的。
最後,基於上述理論,我們可以進行以下觀察結果:
在典型的 I/O 密集型應用程序上,profiler 的開銷將非常小。
這是因爲當有許多休眠 / 空閒的 goroutine 時,CPU 緩存丟棄沒有太大區別。在 Go CPU profiler 基準測試期間,我們一遍又一遍地觀察到這一點:在典型的 I/O 密集型應用程序上,開銷實際上爲零(或統計上微不足道)。但是,同樣,提供經驗證據超出了這篇文章的範圍,人們可以通過在 profiler 打開和關閉時,觀察 Go Web 應用程序的負載測試期間的吞吐量來做到這一點。
結論
我喜歡這種設計的一點是,它證明了你可以根據你對底層數據結構的訪問模式的理解程度來優化代碼。在這種情況下,Go 運行時使用 lock-free 結構,即使在大多數情況下這完全是矯枉過正。Go 運行時充滿了像這樣的聰明優化,我強烈建議你花時間深入研究你覺得有趣的部分。
我希望你喜歡它!
參考資料
-
https://github.com/DataDog/go-profiler-notes/blob/main/guide/README.md
-
https://easyperf.net/blog/2018/06/01/PMU-counters-and-profiling-basics
-
https://www.instana.com/blog/go-profiler-internals/
-
https://www.datadoghq.com/blog/engineering/profiling-improvements-in-go-1-18/
-
http://www.cse.cuhk.edu.hk/~pclee/www/pubs/ancs09poster.pdf
-
https://easyperf.net/blog/2018/06/01/PMU-counters-and-profiling-basics
原文: Inside the Go CPU profiler[20], 作者 Sümer Cip。我猜測 Felix Geisendörfer 肯定會進行評論,果不其然。
參考資料
[1]
The Busy Developer’s Guide to Go Profiling, Tracing and Observability: https://github.com/DataDog/go-profiler-notes/blob/main/guide/README.md
[2]
詳細文章: https://easyperf.net/blog/2018/06/01/PMU-counters-and-profiling-basics
[3]
pyspy: https://github.com/benfred/py-spy
[4]
rbspy: https://github.com/rbspy/rbspy
[5]
pyflame: https://github.com/uber-archive/pyflame
[6]
Parca: https://sumercip.com/posts/inside-the-go-cpu-profiler/parca.dev
[7]
eBPF: https://ebpf.io/
[8]
這裏: https://www.datadoghq.com/blog/engineering/profiling-improvements-in-go-1-18/
[9]
fgprof: https://github.com/felixge/fgprof
[10]
profiler 標籤: https://rakyll.org/profiler-labels/
[11]
lock-free: https://preshing.com/20120612/an-introduction-to-lock-free-programming/
[12]
runtime/profbuf.go: https://github.com/golang/go/blob/master/src/runtime/profbuf.go
[13]
介紹: http://www.cse.cuhk.edu.hk/~pclee/www/pubs/ancs09poster.pdf
[14]
runtime/pprof/map.go: https://github.com/golang/go/blob/master/src/runtime/pprof/map.go
[15]
build(): https://github.com/golang/go/blob/aa4299735b78189eeac1e2c4edafb9d014cc62d7/src/runtime/pprof/proto.go#L348
[16]
pprof.Profile: https://pkg.go.dev/runtime/pprof#Profile
[17]
64: https://github.com/golang/go/blob/54cf1b107d24e135990314b56b02264dba8620fc/src/runtime/cpuprof.go#L22
[18]
討論對話: https://groups.google.com/g/golang-nuts/c/e6lB8ENbIw8/m/azeTCGj7AgAJ
[19]
代碼提交: https://github.com/DataDog/dd-trace-go/commit/54604a13335b9c5e4ac18a898e4d5971b6b6fc8c
[20]
Inside the Go CPU profiler: https://sumercip.com/posts/inside-the-go-cpu-profiler/
本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源:https://mp.weixin.qq.com/s/rgdmO4qUv-wtfkAEow57Kg