Go 部落格
更強大的 Go 執行跟蹤
runtime/trace
包包含一個強大的工具,用於理解和排查 Go 程式。其中的功能允許在一段時間內生成每個 goroutine 執行的跟蹤。透過 `go tool trace` 命令(或優秀的開源 gotraceui 工具),您可以視覺化和探索這些跟蹤中的資料。
跟蹤的神奇之處在於,它可以輕鬆地揭示出其他方法難以發現的程式問題。例如,一個大量的 goroutine 阻塞在同一個通道上的併發瓶頸,在 CPU 剖析中可能很難發現,因為它沒有可採樣的執行。但在執行跟蹤中,*缺乏* 執行會驚人地清晰地顯示出來,阻塞的 goroutine 的堆疊跟蹤會迅速指向罪魁禍首。

Go 開發者甚至可以使用 tasks、regions 和 logs 來檢測自己的程式,這些可以用來將他們的高層關注點與底層執行細節關聯起來。
問題
不幸的是,執行跟蹤中豐富的資訊往往是難以獲得的。歷史上,跟蹤的四個主要問題一直阻礙著我們。
- 跟蹤的開銷很高。
- 跟蹤擴充套件性不佳,可能變得太大而無法分析。
- 要捕獲特定的不良行為,通常不清楚何時開始跟蹤。
- 由於缺乏用於解析和解釋執行跟蹤的公共包,只有最勇於嘗試的 Gopher 才能以程式設計方式分析跟蹤。
如果您近幾年來使用過跟蹤,您很可能被這些問題中的一個或多個所困擾。但我們很高興地宣佈,在過去兩個 Go 版本中,我們在所有這四個領域都取得了巨大進展。
低開銷跟蹤
在 Go 1.21 之前,許多應用程式的跟蹤執行時開銷在 10-20% 的 CPU 之間,這限制了跟蹤的用途,使其只能在特定情況下使用,而不是像 CPU 剖析那樣持續使用。事實證明,跟蹤的成本大部分來自於回溯。執行時產生的許多事件都附帶堆疊跟蹤,這對於實際識別 goroutine 在執行的關鍵時刻在做什麼非常有價值。
得益於 Felix Geisendörfer 和 Nick Ripley 在最佳化回溯效率方面所做的工作,執行跟蹤的執行時 CPU 開銷已大大降低,對於許多應用程式而言,降至 1-2%。您可以在 Felix 關於此主題的精彩部落格文章中閱讀有關所做工作的更多資訊。
可擴充套件的跟蹤
跟蹤格式及其事件被設計為相對高效地發出,但需要工具來解析並保留整個跟蹤的狀態。幾百兆位元組的跟蹤可能需要幾個千兆位元組的 RAM 才能進行分析!
不幸的是,這個問題是跟蹤生成方式的基本問題。為了保持低執行時開銷,所有事件都寫入等效於執行緒本地緩衝區。但這會使事件的出現順序錯亂,並將弄清楚實際發生情況的負擔推給了跟蹤工具。
使跟蹤可擴充套件同時保持低開銷的關鍵洞察是偶爾分割正在生成的跟蹤。每個分割點都表現得有點像一次性停用和重新啟用跟蹤。到目前為止的所有跟蹤資料將代表一個完整且自包含的跟蹤,而新的跟蹤資料將無縫地接續下去。
正如您可能想象的那樣,解決這個問題需要重新思考和重寫執行時中跟蹤實現的大部分基礎。我們很高興地說,這項工作已在 Go 1.22 中完成,並且現在已普遍可用。重寫帶來了許多不錯的改進,包括對 `go tool trace` 命令的一些改進。如果您好奇,可以在設計文件中找到所有詳細資訊。
(注意:`go tool trace` 仍然將完整跟蹤載入到記憶體中,但移除此限制對於 Go 1.22+ 程式生成的跟蹤現在是可行的。)
飛行記錄
假設您在一個 Web 服務上工作,一個 RPC 花費了很長時間。您無法在發現 RPC 已經花費很長時間時開始跟蹤,因為導致請求緩慢的根本原因已經發生並且沒有被記錄下來。
有一種技術可以幫助解決這個問題,稱為飛行記錄,您可能已經從其他程式設計環境中熟悉它了。飛行記錄的洞察是持續開啟跟蹤,並始終保留最新的跟蹤資料,以備不時之需。然後,一旦發生有趣的事情,程式就可以寫出它擁有的任何內容!
在跟蹤能夠被分割之前,這幾乎是不可行的。但由於低開銷使得持續跟蹤現在可行,並且執行時現在可以在需要時隨時分割跟蹤,因此實現飛行記錄變得很簡單。
因此,我們很高興地宣佈一項飛行記錄實驗,它在 `golang.org/x/exp/trace` 包中可用。
請嘗試一下!下面是一個示例,它設定了飛行記錄以捕獲一個長時間的 HTTP 請求,供您入門。
// Set up the flight recorder. fr := trace.NewFlightRecorder() fr.Start() // Set up and run an HTTP server. var once sync.Once http.HandleFunc("/my-endpoint", func(w http.ResponseWriter, r *http.Request) { start := time.Now() // Do the work... doWork(w, r) // We saw a long request. Take a snapshot! if time.Since(start) > 300*time.Millisecond { // Do it only once for simplicity, but you can take more than one. once.Do(func() { // Grab the snapshot. var b bytes.Buffer _, err = fr.WriteTo(&b) if err != nil { log.Print(err) return } // Write it to a file. if err := os.WriteFile("trace.out", b.Bytes(), 0o755); err != nil { log.Print(err) return } }) } }) log.Fatal(http.ListenAndServe(":8080", nil))
如果您有任何反饋,無論好壞,請分享到提案 issue!
跟蹤讀取器 API
隨著跟蹤實現重寫,還進行了清理其他跟蹤內部的工作,例如 `go tool trace`。這催生了一個嘗試建立足夠好的跟蹤讀取器 API 的舉措,以便共享並使跟蹤更易於訪問。
與飛行記錄器一樣,我們很高興地宣佈,我們還有一個實驗性的跟蹤讀取器 API,我們想與之分享。它與飛行記錄器在同一個包中,即 `golang.org/x/exp/trace`。
我們認為它足以開始在此基礎上進行構建,因此請嘗試一下!下面是一個示例,它測量阻塞以等待網路的 goroutine 阻塞事件的比例。
// Start reading from STDIN. r, err := trace.NewReader(os.Stdin) if err != nil { log.Fatal(err) } var blocked int var blockedOnNetwork int for { // Read the event. ev, err := r.ReadEvent() if err == io.EOF { break } else if err != nil { log.Fatal(err) } // Process it. if ev.Kind() == trace.EventStateTransition { st := ev.StateTransition() if st.Resource.Kind == trace.ResourceGoroutine { from, to := st.Goroutine() // Look for goroutines blocking, and count them. if from.Executing() && to == trace.GoWaiting { blocked++ if strings.Contains(st.Reason, "network") { blockedOnNetwork++ } } } } } // Print what we found. p := 100 * float64(blockedOnNetwork) / float64(blocked) fmt.Printf("%2.3f%% instances of goroutines blocking were to block on the network\n", p)
與飛行記錄器一樣,有一個提案 issue,這是留下反饋的好地方!
我們要特別感謝 Dominik Honnef,他早期進行了測試,提供了很棒的反饋,併為 API 貢獻了對舊跟蹤版本的支援。
謝謝!
這項工作得以完成,很大程度上得益於診斷工作組的幫助,該工作組一年多以前開始,是 Go 社群各利益相關者之間的合作,並向公眾開放。
我們想花點時間感謝那些在過去一年中定期參加診斷會議的社群成員:Felix Geisendörfer、Nick Ripley、Rhys Hiltner、Dominik Honnef、Bryan Boreham、thepudds。
你們的討論、反饋和工作對於我們今天所取得的成就至關重要。謝謝!
下一篇文章:2024 年上半年 Go 開發者調查結果
上一篇文章:對 slice 使用健壯的泛型函式
部落格索引