這是一個建立於 的文章，其中的資訊可能已經有所發展或是發生改變。## 概述你有沒有好奇過 Go 運行時是如何調度 goroutine 的？有沒有深入研究過為什麼有時候加了並發但是效能沒有提高？ Go 提供了執行跟蹤器，可以協助你診斷效能問題（如延遲、競爭或低並發等）、解決前面那些疑問。Go 從 1.5 版本開始有執行跟蹤器這麼一個工具，原理是：監聽 Go 運行時的一些特定的事件，如：1. goroutine的建立、開始和結束。2. 阻塞/解鎖goroutine的一些事件（系統調用，channel，鎖）3. 網路I/O相關事件4. 系統調用5. 記憶體回收追蹤器會原原本本地收集這些資訊，不做任何彙總或者抽樣操作。對於負載高的應用來說，就可能會產生一個比較大的檔案，該檔案後面可以通過 `go tool trace` 命令來進行解析。在執行追蹤器之前， Go 已經提供了 pprof 分析器可以用來分析記憶體和CPU，那麼問題來了，為什麼還要再添加這麼一個官方工具鏈？ CPU 分析器可以很清晰地查看到是哪個函數最佔用 CPU 時間，但是你沒辦法通過它知道是什麼原因導致 goroutine 不運行，也沒法知道底層如何在作業系統線程上調度 goroutine 的。而這些恰恰是追蹤器所擅長的。追蹤器的 [設計文檔](https://docs.google.com/document/u/1/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub) 詳盡地說明了引入追蹤器的原因以及工作原理。## 追蹤器”之旅“從一個簡單的”Hello world“例子開始。會使用到 `runtime/trace` 包，用於控制開始/停止寫追蹤資料；資料會被寫到標準錯誤輸出。```gopackage mainimport ("os""runtime/trace")func main() {trace.Start(os.Stderr)defer trace.Stop()// create new channel of type intch := make(chan int)// start new anonymous goroutinego func() {// send 42 to channelch <- 42}()// read from channel<-ch}```本例中，先建立了一個無緩衝 channel,然後初始化一個 goroutine 通過 channel 發送數字 42。主 goroutine 會一直阻塞直到另外的那個 goroutine 通過 channel 發送一個值過來。通過運行 `go run main.go 2> trace.out` 命令，將追蹤資訊輸出到 `trace.out` 檔案，可以用 `go tool trace trace.out` 命令讀取該檔案。> Go 1.8 版本之前，想要分析追蹤資料要求提供可執行二進位檔案和追蹤的資料這兩個東西；而對於 Go 1.8 版本之後編譯的程式，執行 `go tool trace` 就只用提供追蹤的資料，它包含了所有內容。運行過該命令後，會開啟一個瀏覽器視窗，顯示幾個選項。每個選項開啟後是追蹤器不同的視圖，包含程式執行的不同資訊。1. View trace（查看追蹤資訊）提供了一個最複雜、最強大的互動式可視化介面，顯示整個程式執行的時間軸。舉個例子，介面展示每個虛擬處理器上跑了什麼以及被阻塞等待重新跑的有哪些。後文中會更詳細的介紹這個可視化介面。注意這個介面只支援 chrome 瀏覽器。2. Goroutine analysis ( Goroutine 分析)顯示整個執行過程中每種類型的 Goroutine 的數量。選擇一種類型，就可以看到每個該類型的 Goroutine 的資訊。例如，每個 Goroutine 嘗試擷取一把互斥鎖等待了多久、或嘗試從網路讀取資料阻塞了多久，或等待調度用了多久等等。3. Network/Sync/Syscall blocking profile （網路/同步/系統調用 阻塞分析）這塊包含了一些圖表，展示 Goroutine 在每個以上這些資源上阻塞了多久。有點類似 pprof 的記憶體/ CPU 分析器提供的資料。是個分析鎖競爭的利器。4. Scheduler latency profiler （調度延遲分析器）提供了對調度層面資訊的計時統計資料，顯示調度過程哪塊最耗時。## 查看追蹤資訊點擊“ View trace”連結，跳出視窗展示整個程式執行情況。> 按下“？”鍵，會彈出瀏覽追蹤資訊的一些快速鍵的協助資訊標註了重要的幾個部分，都在下面做了介紹：1. Timeline （時間軸）顯示執行時的時間，時間單位可以通過導覽列進行調整。使用者可以通過鍵盤快速鍵（WASD鍵，就像遊戲裡的一樣）操縱時間軸。2. Heap (堆)顯示執行期間的記憶體配置情況，對於尋找記憶體泄露、每次運行記憶體回收能釋放多少記憶體非常有用。3. Goroutines顯示有多少 groroutine 正在運行，以及每個時間點有多少是可啟動並執行（等待被調度）。可運行 goroutine 數量過多可能意味著有調度競爭，例如，當程式建立了過多的 goroutine 會導致調度器忙不過來。4. OS Threads （作業系統線程）顯示佔用了多少作業系統線程以及系統調用阻塞了多少個線程。5. Virtual Processors （虛擬處理器）每一行顯示一個虛擬處理器。虛擬進程的數量受 GOMAXPROCS 環境變數控制（預設為機器核心數量）。6.Goroutines and events （goroutine和事件）展示每個虛擬處理器上的 goroutine 跑的內容/跑在哪裡。串連 goroutine 的線代表事件。在例圖中，我們可以看到： Goroutine “G1 runtime.main”產生出兩個不同的 Goroutine：G6 和 G5 （前者負責收集追蹤資訊，後者是使用“go”關鍵字產生的）。每個虛擬處理器的第二行可能會顯示額外的事件，例如系統調用和運行時事件。同時包括了 goroutine 為運行時做的一些工作（例如，協助垃圾收集）。顯示選擇一個 goroutine 時得到的資訊。包括如下資訊：* 其名稱（Title）* 起始時間（Start）* 期間（Wall Duration）* 開始時刻堆棧軌跡* 結束時刻堆棧軌跡* 該 goroutine 產生的事件我們可以看到：該 goroutine 產生兩個事件：產生用於追蹤的 goroutine 以及在channel上開始發送數字42的 goroutine。通過點擊一個特定的事件（圖中一條線或者通過點 goroutine 之後選事件），我們可以看到：* 事件開始時刻的堆棧軌跡* 事件的期間* 時間包含的 goroutine可以通過點擊這些 goroutine 導航到他們的追蹤資料。## 阻塞分析通過追蹤還可以得到網路/同步/系統調用阻塞分析的視圖。阻塞分析顯示的映像視圖與 pprof 記憶體/cpu 分析的視圖比較相似。區別在於，這裡不顯示每個函數分配了多少記憶體，而是顯示每個 goroutine 在特定資源上阻塞了多久。顯示對我們範例程式碼的“同步阻塞分析”。該圖說明主 goroutine 從 channel 接收資料阻塞時間花費 12.08 微秒。這種類型的圖對於多個 goroutine 競爭資源鎖，尋找鎖競爭情況非常有用。## 收集追蹤資料有三種收集追蹤資料的方式：1.應用 `runtime/trace` 包包含調用 `trace.Start` 和 `trace.Stop`，在 “Hello,Tracing” 例子中已經描述過。2.使用 `trace=<file>` 測試標誌這種方式對於要被測試的代碼或者測試本身收集追蹤資訊十分有用。3.使用 debug/pprof/trace 處理器是從正在運行 web 應用收集追蹤資料的最好方式。## 追蹤一個 web 應用為了能夠對 Go 寫的正在啟動並執行 web 應用收集追蹤資訊，需要添加 `/debug/pprof/trace` 處理器。下文範例程式碼說明對於 `http.DefaultServerMux` 如何做到這一點：通過簡單地引入 `net/http/pprof` 包。```gopackage mainimport ("net/http"_ "net/http/pprof")func main() {http.Handle("/hello", http.HandlerFunc(helloHandler))http.ListenAndServe("localhost:8181", http.DefaultServeMux)}func helloHandler(w http.ResponseWriter, r *http.Request) {w.Write([]byte("hello world!"))}```收集追蹤資訊，我們需要向端點發送請求，例如，`curl localhost:8181/debug/pprof/trace?seconds=10 > trace.out`。該請求會被阻塞 10 秒，追蹤資訊會被寫入 `trace.out` 檔案。這樣產生的追蹤資訊可以像之前一樣查看：通過 `go tool trace trace.out`。> 安全提醒：注意，不建議將 pprof 處理器暴露到 Internet 上。推薦將這些端點暴露到一個不同的 http.Server ，該 http.Server 綁定到迴環連接埠。[這篇部落格](http://mmcloughlin.com/posts/your-pprof-is-showing) 討論了存在的風險，同時提供如何恰當地暴露 pprof 處理器的範例程式碼。收集追蹤資料前，先對服務加一些負載，用到了 `wrk`：```$ wrk -c 100 -t 10 -d 60s http://localhost:8181/hello```該命令會在 60 秒內通過 10 個線程使用 100 個串連發起請求。跑`wrk`的同時，我們可以收集 5 s 的追蹤資料：`curl localhost:8181/debug/pprof/trace?seconds=5 > trace.out`。該命令會在本人 4 CPU 機器上產生一個 5 MB 的檔案（檔案大小會隨負載加大而快速增加）。同樣的，通過 go 工具 trace 命令開啟追蹤資料：`go tool trace trace.out`。由於工具要分析整個檔案，會比前例耗費更長時間。完成之後，頁面看起來稍微有點不一樣：```View trace (0s-2.546634537s)View trace (2.546634537s-5.00392737s)Goroutine analysisNetwork blocking profileSynchronization blocking profileSyscall blocking profileScheduler latency profile```為了確保瀏覽器能夠渲染所有資訊，工具已經將追蹤資料分為兩個連續的部分。負載更高的應用或者更長時間的追蹤資料可能會觸發工具將其分割為更多的部分。點擊“View trace (2.546634537s-5.00392737s)”我們可以看到有很多東西：該顯示 1169 ms ~ 1170 ms 之間開始、1174 ms 之後結束的一個 GC 操作。這段時間內，一個作業系統線程（PROC 1）啟動一個 goroutine 專門做 GC，其他的 goroutine 輔助 GC 操作（在 goroutine 行下展示，標示為 MARK ASSIST ）,截頻的末尾，我們可以看到大部分分配的記憶體已被 GC 釋放掉。另外一個特別有用的資訊是：處於“Runnable”狀態（選擇時顯示的是13）的 goroutine 數量，如果該數值隨時間變大，就意味著我們需要更多 CPU 來處理負載。## 總結追蹤器是調試並發問題（如鎖競爭和邏輯競爭）的一個強大工具。它不能夠解決一切問題：它不是追蹤哪塊代碼最耗費 CPU 時間、記憶體的最佳工具。用`go tool pprof`更適合這樣的情境。該工具對於理解程式不運行時每個 goroutine 在做什麼以及按照時間查看程式行為非常有用。收集追蹤資料會有一些開銷，同時可能會產生較大資料量的資料以供查看。不幸的是，官方文檔缺少一些實驗來讓我們實驗、理解追蹤器顯示的資訊。這也是個給官方文檔、社區（如部落格）做貢獻的[機會](https://github.com/golang/go/issues/16526)。André 是 [Globo.com](http://www.globo.com/) 的進階軟體工程師, 開發 [Tsuru](https://tsuru.io/)項目。 twitter 請@andresantostc, 或者 web 留言https://andrestc.com。## 參考1. [Go execution tracer (design doc)](https://docs.google.com/document/u/1/d/1FP5apqzBgr7ahCCgFO-yoVhk4YZrNIDNf9RybngBc14/pub)2. [Using the go tracer to speed fractal rendering](https://medium.com/justforfunc/using-the-go-execution-tracer-to-speed-up-fractal-rendering-c06bb3760507)3. [Go tool trace](https://making.pusher.com/go-tool-trace/)4. [Your pprof is showing](http://mmcloughlin.com/posts/your-pprof-is-showing)
via: https://blog.gopheracademy.com/advent-2017/go-execution-tracer/
作者：André Carvalho 譯者：dongfengkuayue 校對：polaris1119
本文由 GCTT 原創編譯，Go語言中文網 榮譽推出
本文由 GCTT 原創翻譯，Go語言中文網 首發。也想加入譯者行列，為開源做一些自己的貢獻嗎？歡迎加入 GCTT！
翻譯工作和譯文發表僅用於學習和交流目的，翻譯工作遵照 CC-BY-NC-SA 協議規定，如果我們的工作有侵犯到您的權益，請及時聯絡我們。
歡迎遵照 CC-BY-NC-SA 協議規定 轉載，敬請在本文中標註並保留原文/譯文連結和作者/譯者等資訊。
文章僅代表作者的知識和看法，如有不同觀點，請樓下排隊吐槽
1062 次點擊 ∙ 1 贊
