pprof--: 一個帶有硬件監控的 Go Profiler

原文地址：https://eng.uber.com/pprof-go-profiler/

原文作者：Milind Chabbi

本文永久鏈接：https://github.com/gocn/translator/blob/master/2021/w20_pprof_go_profiler.md

譯者：tt

校對：Fivezh

追求更好的 Go Profiler 的動機

Golang 是數百萬 CPU 核心上運行的成千上萬 Uber 後端服務的命脈。瞭解 CPU 瓶頸對於減少服務延遲以及提高計算隊列效率至關重要。Uber 的規模要求我們對代碼和微體系結構做深入瞭解。

儘管與其他幾種語言相比，Go 語言內置的 profiler 聊勝於無，但事實上，Go 語言中的 CPU profiler 在基於 Linux 的系統（也可能在其他操作系統）上受到嚴重限制，並且缺乏很多東西 [1, 2, 3, 4] 來全面瞭解 CPU 瓶頸所需的詳細信息。

考慮到這些問題，我們着手構建了一個自定義的 Go 分析器，該分析器更適合我們的需求和 Uber 業務運營的規模。具體來說，我們將 Go 的默認 pprof profiler 集成豐富的硬件性能監控功能來對其進行增強。這一增強主要提供了以下好處：

  1. 獲取更精確的 Go 程序 profiles。

  2. 監視各種 CPU 事件的能力，例如高速緩存未命中，套接字間（NUMA）流量，CPU 分支錯誤預測，僅舉幾例。

  3. 能夠以非常高的採樣頻率（高達 10 微秒）監視 go 程序。

背景

分析是 Golang 的內置功能之一。Go Profiler 涵蓋了諸如 CPU 時間，內存分配等方面。本文涉及最常見和最熟悉的性能分析形式 - CPU 性能分析。有 3 種著名的方法可以從 Go 程序中獲取 CPU profile:

  1. 通過公開的 http 端口獲取 CPU profile

首先，通過在 Go 程序中包含以下代碼段，公開指定端口上的分析端點：

go func() {log.Println(http.ListenAndServe("localhost:6060", nil))}()

然後，從正在運行的 Go 程序的分析端點中獲取 profiles；例如，以下命令包含 5 秒鐘的 CPU profile，並將其存儲在 timer.prof 文件中。

$curl -o timer.prof server200:6060/debug/pprof/profile?seconds=5

在 Uber，我們十分依賴從成千上萬生產環境微服務中獲取 profile 的能力，並且我們擁有一套精巧的下游工具來對其進行後處理。

  1. 從 Go 基準測試中獲取 CPU profile Go 測試框架允許對程序進行基準測試，然後通過傳遞額外的 -cpuprofile 標誌以收集 CPU Profile 來對基準進行概要分析。
$go test -bench BenchmarkXYZ -cpuprofile cpuprof.out
  1. 從代碼檢測獲取 CPU profile 可以在感興趣的代碼區域周圍插入啓動 / 停止分析 API ，並提供 io.writer 將結果概要文件刷新到文件中，如下所示：
f, err := os.Create("cpuprof.prof")
defer f.Close()
pprof.StartCPUProfile(f)
  MyCodeToProfile()
pprof.StopCPUProfile()

所有這三個接口都生成一個 pprof 協議緩衝區文件，可以使用 go 工具 pprof 命令行或其他下游工具查看該文件。Go CPU profile 包括調用堆棧樣本的時間歸因。它們可以通過調用圖和火焰圖可視化。

準確度和精度

準確度和精度是一個好的測量工具的基本屬性。

如果概要分析數據與事實相近，則稱其爲準確的。例如，如果 API_A() 消耗了總執行時間的 25％，而分析器將其測量爲總執行時間的 24％，則測量的準確度爲 96％

如果多次測量之間的差異性很低，則分析數據被認爲是精確的。一組相同變量的測量精度通常表示爲樣本平均值的最小值和最大值，或者表示爲樣本的標準誤差或差異係數。

不幸的是，當前的 pprof CPU profile 這兩個條件都不符合。在 Go 運行時內部，CPU 分析使用操作系統計時器來定期（每秒約 100 次）中斷執行。在每個中斷（也稱爲樣本）上，它同時收集當時的調用堆棧。

不準確和原因

profile 的不準確性有兩個來源：採樣頻率和採樣偏差。

採樣頻率: 基於樣本的 profile 準確度與奈奎斯特採樣定理 (Nyquist Sampling Theorem) 緊緊相關. 爲了忠實地恢復輸入信號，採樣頻率應大於信號中包含的最高頻率的兩倍。如果微服務需要 10 毫秒來處理請求，則我們應該至少每 5 毫秒採樣一次，以對請求中發生的事情有所瞭解。但是，OS 定時器不能慢到每 10ms 進行一次採樣。事實上，爲了函數級別的準確採樣，我們需要微妙級別的粒度。

大量樣本可以使 profiles 更接近實際，並且可以通過增加測量窗口的長度來獲取更多樣本。如果需要更多的樣本來糾正小樣本問題，線性縮放測量時間以收集更多樣本是不切實際的。因此，迫切需要在測量窗口內收集更多樣本並獲得亞毫秒級執行的細粒度樣本。

採樣偏差: 如果樣本有偏差，則僅增加樣本量並不能提高準確性. Linux 中的 OS 計時器（初始）樣本有偏差，因爲來自一個 OS 線程（例如 T1 ）的計時器中斷可以由任意（不要與統一隨機變量混淆）線程（例如 T2）來處理。這意味着，T2 將處理中斷並用其調用堆棧錯誤得修飾樣本，這將產生偏差樣本。如果與 T1 相比，T2 處理的計時器中斷更多，那麼系統性的採樣偏差將會發生，這將導致 profile 的不準確。

不精確及其原因

導致大多數測量不精確的兩個主要原因：樣本量和測量滑移。

樣本量: 較少的樣本數量直接導致較大的標準誤差。OS 計時器的低分辨率導致測量窗口中的樣本減少，從而導致 pprof 配置文件的精度降低。相反，更高的樣品分辨率將提高精度。

測量滑移: 測量誤差的第二個來源是任何給定測量設備中固有的隨機誤差。配置爲在 N 毫秒後過期的 OS 計時器設備只能保證在 N 毫秒後的某個時間生成中斷，而不是精確地在 N 毫秒。這種隨機性導致測量中出現較大的 “滑移”。假設一個定時器設置爲每 10 毫秒觸發一次。當具有 4ms 分辨率的 OS 調度程序對其進行檢查時，它還有 1ms 的到期時間。這意味着計時器將在 4ms 之後觸發，而這將會比本該測量的時間慢 3ms。對於 10ms 的週期性定時器，這將導致高達 30％的不精確性。儘管可能無法完全消除隨機誤差，但高級的測量設備可以減少隨機誤差的影響。

示範

考慮以下這個 Go 程序: goroutine.go, 它具有 10 個完全相似的 goroutines main.f1-main.f10，其中每個函數佔用的 CPU 時間完全相同（即，佔總執行時間的 10％）。表 1 總結了在此程序上使用默認 pprof cpu 配置文件的結果，該配置文件在具有 Linux OS 的 12 核 Intel Skylake 架構服務器上運行

在表 1 中的 RUN 1，RUN 2 和 RUN 3 標頭列所表示的相同配置下，進行了 3 次測量。Expected（％）列顯示了每個例程中的預期相對時間。Flat（ms）列顯示 10 個例程中的每一個的絕對毫秒測量值，Flat（％）列顯示例程中相對於每次運行的總執行時間的相對時間。排序列按每次運行的每個功能的執行時間的降序排位。

考慮 RUN 1 中的數據。main.f1-main.f10 在賦予它們的時間上有很大的差異，而我們希望它們中的每一個都佔總時間的 10％。佔有時間最高的例程（main.f7 的 4210ms，23.31％）和最低的例程（main.f9 的 700ms，3.88％）的時間差距高達 6 倍。這證明了基於 pprof 計時器的配置文件的準確性很差（偏離基本事實）。

現在將注意力集中在 RUN 1，RUN2 和 RUN 3 的 3 次運行上。賦予任何例程的時間每次運行都不同。例程的排序在每次運行之間都發生顯着變化。在 RUN 1 中，顯示 main.f7 以排位 1 運行了 4210ms，而在 RUN 2 中，僅以排位 10 運行了 520ms。main.f1 例程的 3 次運行之間的差異係數爲 71％，所有函數的平均差異係數爲 28％。這表明基於 pprof 計時器的配置文件不精確。將此程序的運行時間增加 10 倍甚至 100 倍並不能解決此分析錯誤。

其他詳細信息出現在 [Golang 提案中] 中(https://go.googlesource.com/proposal/+/refs/changes/08/219508/2/design/36821-perf-counter-pprof.md).

超過代碼熱點

profiler 的第二個方面是，它提供了不僅僅是熱點的更多詳細信息，以幫助開發人員採取糾正措施。所有 profile 都顯示熱點，但是熱點充其量只是症狀，不能完全反映出潛在的問題。例如，如果 profiler 顯示程序在矩陣矩陣乘法中花費了 90％的時間，它不會告訴您程序是好是壞。矩陣乘法可能已經高度優化了！但是，如果分析器可以確定在矩陣矩陣乘法期間訪問的 50％的數據是從運行它的 NUMA 系統的遠程 DRAM 提取的，則它立即突出顯示程序中的數據局部性問題，因此也有機會優化。在基本的 profiler（包括默認的 Go profiler）中很難獲得此類詳細信息。

帶有硬件性能計數器的解決方案

爲了解決這些問題，我們開發了 pprof++，它增強了默認的 Go CPU 分析器以使用硬件性能監視功能。

  1. 增強準確度和精度: 現代的商用 CPU 配備了硬件性能監視單元（PMU）。可以將硬件性能計數器配置爲非常精細的測量粒度，從而提高配置精度。此外，PMU 的先進特性提供了在中斷時記錄 CPU 狀態的功能，從而可以重構程序的精確狀態，從而提高精度。最後，可以將來自硬件 PMU 的中斷配置爲傳遞給當前聚焦的特定線程，這避免了線程描述不正確的問題，從而提高了分析精度。

  2. 洞察多種 CPU 事件，以更好地診斷性能問題: 診斷複雜的性能問題時，僅憑時間是不夠的。例如，如果將大量時間賦予數據結構遍歷，那麼原因可能並不明顯。硬件性能監視揭示了 CPU 和內存子系統的許多內部功能，這些功能可以診斷性能問題的根本原因。例如，如果在再次訪問以前訪問的數據之前獲取了許多新數據，則從 CPU 高速緩存中逐出這些數據，如果要分析 CPU 高速緩存未命中，這將擁有可見性。同樣，如果 2 個相鄰的數據項被 2 個獨立的線程訪問，而它們恰好位於同一 CPU 高速緩存行上，則會導致 2 個 CPU 的專用高速緩存之間共享高速緩存行 ping-poning，通常稱爲錯誤共享，可以通過現代英特爾 CPU 中稱爲 HITM 的計數器進行診斷。

  3. 高頻測量: 由於 PMU 可以配置爲任意低的採樣閾值，因此可以以極高的頻率（大約 10 s 或 100 s 微秒）監視事件，這對於延遲敏感的服務很有必要，在這些服務中，單個請求僅持續數十毫秒。

PMU 在現代 CPU 中無處不在，被 Linux 之類的 OS 所暴露，並且可以通過編程控制它們，以在事件的閾值累積時傳遞中斷。例如，Intel 公佈了他們的性能監控事件針對其處理器系列的每個成員，Linux 通過 perf_event 子系統公開 PMU。. pprof++ 對 Go 運行時進行更改，訂閱這些硬件事件，並獲得定期中斷。這種機制通常稱爲基於硬件事件的採樣。事件的選擇使硬件性能監控變得豐富而可見。像 OS 計時器分析一樣，pprof++ 在每個 PMU 中斷上執行調用棧退卷，並將事件歸因於調用棧樣本。這使 pprof++ 配置文件可以突出顯示哪些函數和源代碼行會導致不同的體系結構瓶頸，例如 CPU 高速緩存未命中。

對於初學者而言，確定要監視的硬件性能事件可能會令人生畏。因此，我們簡化了流程並公開了以下最常見的事件。這些事件擁有一個可重寫的預設 分析階段。

pprof++ 的輸出是相同的，熟悉的 pprof 協議緩衝區 profile 文件，可以使用 pprof 工具將其視爲調用圖（圖 1）或火焰圖（圖 2），也可以饋送至其他下游 profile 處理工作流程。如果使用 PMU 週期事件獲取配置文件，則 pprof 調用圖和火焰圖將查明並量化哪些代碼區域（上下文）佔 CPU 週期的數量；如果使用 PMU cacheMisses 事件獲取 profile，則 pprof 調用圖和 Flame-graph 將查明並量化代碼區域（上下文）佔 CPU 上一級緩存未命中的數量，依此類推。

入手使用 pprof++

爲了利用 pprof++，請使用我們的自定義 Go 編譯器重新編譯您的 Go 程序，並添加 PMU 分析功能；詳見下方的可用性部分.。

背景部分介紹的三種使用方式與使用 pprof++ 基本一樣:

  1. 通過公開的 http 端口獲取 CPU profile

與 pprof 一樣，包括相同的代碼片段以公開性能分析端點；無需更改應用程序代碼。開發人員現在可以獲取多種配置文件。我們在 / debug /pprof /profile endpoin 中引入了 2 個新參數

event=<timer|cycles|instructions|cacheMisses|cacheReferences|branches|branchMisses|rHexValue>
period=<Int64Value>

這是一些使用例子:

a. 通過在 500 萬個 CPU 週期中對調用堆棧進行一次採樣來使用 CPU 週期收集 profile，並收集 25 秒鐘。

$ curl -o cycles.prof <host>:<port>/debug/pprof/profile?event=cycles\&period=5000000\&seconds=25

event = cycles 表示事件探查器採樣 CPU 週期。默認值是 pprof 中的 “定時器”。period=5000000 表示分析器每 5M 個 CPU 週期進行一次採樣。在 2.5GHz CPU 上，這將導致每秒約 500 個樣本。seconds=25 表示分析器測量應用程序 25 秒。默認值爲 30 秒。

b. 通過在 100 萬條退休指令中對調用堆棧進行一次採樣來使用 CPU 退休指令事件收集配置文件，並在 30 秒內收集配置文件（默認）。

$ curl -o ins.prof <host>:<port>/debug/pprof/profile?event=instructions\&period=1000000

c. 通過在 10K 高速緩存未命中中對調用堆棧進行一次採樣來收集使用最後一級高速緩存未命中的 profile，並收集 30 秒鐘。

$ curl -o cachemiss.prof <host>:<port>/debug/pprof/profile?event=cacheMisses\&period=10000

d. 收集 profile 以檢測由於 2 個不同 NUMA 套接字上的 2 個內核之間的正確或錯誤共享而導致的高速緩存行爭用。這可以通過 MEM_LOAD_L3_MISS_RETIRED.REMOTE_HITM 事件輕鬆完成，該事件在 skylake 體系結構上具有掩碼 0x4 和事件代碼 0xD3。因此，我們設置 event= r04d3。讓我們以每 10K 個此類事件中的調用堆棧樣本作爲示例。

$ curl -o remote_hitm.prof <host>:<port>/debug/pprof/profile?event=r04d3\&period=10000
  1. 從 Go 基準測試中獲取 CPU profile

我們在命令行中引入了兩個新參數：

cpuevent=<timer|cycles|instructions|cacheMisses|cacheReferences|branches|branchMisses|rHexValue>
cpuperiod=<Int64Value>

以下是一些用法示例：

a. 通過在每 100 萬個週期中採樣一次，從 BenchmarkXYZ 上的 CPU 週期計數器中收集配置文件，並將配置文件寫入 cycle.prof 文件。

$go test -bench BenchmarkXYZ -cpuprofile cycles.prof -cpuprofileevent cycles -cpuprofileperiod 1000000

b. 通過在每 10000 個錯誤預測的分支中採樣一個來收集 BenchmarkXYZ 中錯誤預測的分支的概要文件，並將概要文件寫入 mispredbranch.prof。

$go test -bench BenchmarkXYZ -cpuprofile mispredbranch.prof -cpuprofileevent branchMisses -cpuprofileperiod 100000

c. 確定代碼在 CPU 的一級指令高速緩存中引起頻繁丟失的位置。可以在事件爲 FRONTEND_RETIRED.L1I_MISS 的 Intel Skylake 計算機上對此事件進行配置文件，事件 FRONTEND_RETIRED.L1I_MISS 的掩碼爲 0x1，事件代碼爲 0xc6。讓我們在 10000 次未命中的情況下進行一次採樣。

$go test -bench BenchmarkXYZ -cpuprofile insL1miss.prof -cpuprofileevent r01c6 -cpuprofileperiod 10000
  1. 從代碼檢測獲取 CPU profile

pprof++ 向 runtime/pprof 包引入了新的 API。pprof.StartCPUProfileWithConfig（opt ProfilingOption，moreOpts…ProfilingOption）錯誤，其中 ProfilingOption 可以是以下之一

func OSTimer(w io.Writer) ProfilingOption
func CPUCycles(w io.Writer, period uint64) ProfilingOption
func CPUInstructions(w io.Writer, period uint64) ProfilingOption
func CPUCacheReferences(w io.Writer, period uint64) ProfilingOption
func CPUCacheMisses(w io.Writer, period uint64) ProfilingOption
func CPUBranchInstructions(w io.Writer, period uint64) ProfilingOption
func CPUBranchMisses(w io.Writer, period uint64) ProfilingOption
func CPURawEvent(w io.Writer, period uint64, hex uint64) ProfilingOption

現在，我們可以在感興趣的代碼區域周圍使用 StartCPUProfileWithConfig /StopCPUProfile 分析 API。

a. 每 100 萬個 CPU 週期使用一次 CPU 週期事件採樣來分析代碼區域。

f, _ := os.Create("cpuprof.prof") 
defer f.Close() 
pprof.StartCPUProfileWithConfig(CPUCycles(f, 1000000))  
MyCodeToProfile() 
pprof.StopCPUProfile()

我們允許高級用戶在一次運行中同時收集多個事件。此功能受環境變量 GO_PPROF_ENABLE_MULTIPLE_CPU_PROFILES = <true | false> 的保護。每個事件都需要自己的 io.writer。下面的示例顯示了同時收集 4 個配置文件：CPU 週期（每 10M 中的一個），退出的指令（每 1M 中的一個），最後一級的高速緩存未命中（每 10K 中的一個）以及在第二級 TLB 中丟失的退休的加載指令（一個） （1K 中的值）），可用於事件 MEM_INST_RETIRED.STLB_MISS_LOADS，掩碼 = 0x11，事件代碼 = 0xd0。

cyc, _ := os.Create("cycprof.prof")
defer cyc.Close()
ins, _ := os.Create("insprof.prof")
defer ins.Close()
cache, _ := os.Create("cacheprof.prof")
defer cache.Close()
tlb, _ := os.Create("tlb.prof")
defer brMiss.Close()
pprof.StartCPUProfileWithConfig(CPUCycles(cyc, 1000000), CPUInstructions(ins, 1000000), CPUCacheMisses(cache, 10000), CPURawEvent("r11d0", 1000))
MyCodeToProfile()
pprof.StopCPUProfile()

視頻演示

以下視頻演示了 pprof++ 的下載，初始設置和用法。

結論和可用性

任何編程語言都必須具有準確而精確的 profile，這些 profile 可以提供對程序執行的更深層次的可見性和可操作性。Uber 將 Go 廣泛用於其微服務，這導致我們將這些功能引入 Golang 的 Pprof 分析器中。儘管存在許多其他具有類似功能的第三方 profile，但 Go 運行時中 PMU profile 的集成提供了與衆多執行環境和下游後處理工具的無縫集成。

我們已經在 GitHub 上發佈了一個當前實現的 pprof++ 原型. 我們已經讓它在 Go 1.15.8 和 Go 1.16 的發佈列表內。

pprof ++ 當前僅在 Linux OS 上可用。爲了快速下載，我們提供了 Go 二進制文件的 x86_64（即 AMD64）版本：

  1. go1.15.8.linux-amd64.tar.gz

  2. go1.16.linux-amd64.tar.gz

src/net/http/pprof/examples/ 和 src/runtime/pprof/examples / 下有幾個使用 pprof++ 的示例程序。

**致謝 **

Pengfei Su, 現在是 UC Merced 的助理教授，他在 2019 年夏天在 Uber 編程系統小組實習時開發了初始原型。

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

猜你喜歡