更強大的 Go 執行跟蹤能力

runtime/trace 包 [1] 包含了一個強大的工具, 可用於理解和調試 Go 程序。該功能允許我們在一段時間內對每個 goroutine 的執行進行跟蹤。使用 go tool trace 命令 [2](或優秀的開源工具 gotraceui[3]), 我們就可以可視化和探索這些跟蹤數據。

跟蹤的魔力在於, 它可以輕鬆揭示程序中一些通過其他方式很難發現的問題。例如, 大量 goroutine 在同一個 channel 上阻塞導致的併發瓶頸, 在 CPU 分析中可能很難發現, 因爲沒有執行 (execution) 需要採樣。但在執行跟蹤中, 執行的缺失將被清晰地呈現, 而阻塞 goroutine 的堆棧跟蹤會快速指出問題所在。

Go 開發者甚至可以在自己的程序中使用 Task[4]、Region[5] 和 Log[6] 進行檢測, 從而將他們關注的高級問題與低級執行細節聯繫起來。

問題

不幸的是, 執行跟蹤中豐富的信息往往難以獲取。歷史上, 以下四個主要問題一直阻礙着跟蹤的使用:

如果你在過去幾年使用過跟蹤, 可能會因上述一個或多個問題而感到沮喪。但我們很高興地分享, 在最近兩個 Go 版本中, 我們在這四個領域都取得了重大進展。

低開銷跟蹤

在 Go 1.21 之前, 對許多應用程序而言, 跟蹤的運行時開銷約在 10-20% 的 CPU 範圍內, 這限制了跟蹤只能被選擇性使用, 而不能像CPU profiling那樣持續使用。事實證明, 跟蹤的大部分成本歸結於 traceback(跟蹤回溯，在計算機編程中，它通常指的是程序運行時發生錯誤或異常時，系統生成的調用棧信息，用於幫助開發者定位問題的源頭。)。運行時產生的許多事件都附帶了堆棧跟蹤, 這對於實際識別關鍵執行時刻 goroutine 的行爲是非常有價值的。

感謝 Felix Geisendörfer 和 Nick Ripley 在優化 traceback 效率方面所做的工作, 執行跟蹤的運行時 CPU 開銷已經顯著降低, 對許多應用程序而言, 降至 1-2%。你可以在 Felix 關於這個主題的精彩博文 [7] 中閱讀更多相關工作的細節。

可擴展的跟蹤

跟蹤格式及其事件的設計側重於相對高效的發送, 但需要工具來解析並維護整個跟蹤的狀態。分析數百 MB 的跟蹤可能需要幾 GB 的內存!

這個問題從根本上說是由於跟蹤生成的方式造成的。爲了保持運行時開銷低, 所有事件都被寫入類似線程本地緩衝區。但這意味着事件出現的順序與真實發生的順序不一致, 跟蹤工具需要負擔重任來弄清楚真正發生的情況。

在保持低開銷的同時使跟蹤可擴展的關鍵在於, 偶爾分割正在生成的跟蹤。每個分割點的行爲有點像同時禁用和重新啓用跟蹤。到目前爲止的所有跟蹤數據代表一個完整且獨立的跟蹤, 而新的跟蹤數據將無縫地從中斷處繼續。

你可能已經想到, 解決這個問題需要反思和重寫運行時中跟蹤實現的大量基礎部分 [8]。我們很高興地說, 這項工作在 Go 1.22 中完成並現已正式推出。重寫帶來了許多良好的改進 [9], 包括對 go tool trace 命令的一些改進。如果你有興趣, 所有詳細內容都在設計文檔 [10] 中。

(注: go tool trace 仍會將整個跟蹤加載到內存中, 但對於由 Go 1.22 + 程序生成的跟蹤, 移除此限制 [11] 現已變爲可行。)

飛行記錄

假設你在開發一個 web 服務, 一個 RPC 花費了非常長的時間。當你意識到 RPC 已經運行很久時, 你無法在那時開始跟蹤, 因爲導致請求變慢的根本原因已經發生並且沒有被記錄下來。

有一種稱爲飛行記錄 (flight recording) 的技術可以幫助解決這個問題, 你可能已經在其他編程環境中接觸過了。飛行記錄的思路是持續開啓跟蹤, 並一直保留最新的跟蹤數據, 以防萬一。然後, 一旦發生有趣的事情, 程序就可以直接寫出它所擁有的數據!

在可以分割跟蹤之前, 這基本上是行不通的。但由於低開銷使得連續跟蹤變得可行, 而且現在運行時可以隨時分割跟蹤, 因此實現飛行記錄變得很直接。

因此, 我們很高興地宣佈在 golang.org/x/exp/trace[12] 包中提供了一個飛行記錄器實驗。

請嘗試使用它! 下面是一個設置飛行記錄器來捕獲長時間 HTTP 請求的示例, 可以幫助你入門。

    // 設置飛行記錄器
    fr := trace.NewFlightRecorder()
    fr.Start()

    // 設置和運行HTTP服務器
    var once sync.Once
    http.HandleFunc("/my-endpoint", func(w http.ResponseWriter, r *http.Request) {
        start := time.Now()

        // 幹些事情
        doWork(w, r)

        // 盼到了長耗時請求，來個快照
        if time.Since(start) > 300*time.Millisecond {
            // 這裏我們爲了簡化只做一次，實際上你可以做多次
            once.Do(func() {
                // 抓取快照
                var b bytes.Buffer
                _, err = fr.WriteTo(&b)
                if err != nil {
                    log.Print(err)
                    return
                }
                // 把快照寫入文件
                if err := os.WriteFile("trace.out", b.Bytes(), 0o755); err != nil {
                    log.Print(err)
                    return
                }
            })
        }
    })
    log.Fatal(http.ListenAndServe(":8080", nil))

果您有任何反饋，無論是正面的還是負面的，請分享到提案問題 [13] 中！

跟蹤讀取器 API

隨着對跟蹤實現的重寫, 我們也努力清理了其他的跟蹤內部組件, 比如 go tool trace。這催生了一次嘗試, 目標是創建一個足夠好的可共享跟蹤讀取器 API, 使跟蹤更易於訪問。

就像飛行記錄器一樣, 我們很高興地宣佈, 我們也有一個實驗性的跟蹤讀取器 API, 希望能與大家分享。它與飛行記錄器位於同一個包中, 即 golang.org/x/exp/trace[14]。

我們認爲它已經足夠好, 可以在此基礎上構建東西了, 所以請務必試用! 下面是一個示例, 它測量了由於等待網絡而阻塞的 goroutine 阻塞事件的比例。

    // 開始從標準輸入讀取跟蹤數據。
    r, err := trace.NewReader(os.Stdin)
    if err != nil {
        log.Fatal(err)
    }

    var blocked int
    var blockedOnNetwork int
    for {
        // 讀取事件
        ev, err := r.ReadEvent()
        if err == io.EOF {
            break
        } else if err != nil {
            log.Fatal(err)
        }

        // 處理它
        if ev.Kind() == trace.EventStateTransition {
            st := ev.StateTransition()
            if st.Resource.Kind == trace.ResourceGoroutine {
                id := st.Resource.Goroutine()
                from, to := st.GoroutineTransition()

                // 查找阻塞的goroutine, 統計計數
                if from.Executing() && to == trace.GoWaiting {
                    blocked++
                    if strings.Contains(st.Reason, "network") {
                        blockedOnNetwork++
                    }
                }
            }
        }
    }
    // 打印我們所需
    p := 100 * float64(blockedOnNetwork) / float64(blocked)
    fmt.Printf("%2.3f%% instances of goroutines blocking were to block on the network\n", p)

就像飛行記錄器一樣, 有一個提案問題 [15] 可以作爲留下反饋的好地方!

我們想特別提及 Dominik Honnef, 他很早就試用了這個 API, 提供了寶貴的反饋, 併爲 API 貢獻了對舊版本跟蹤的支持。

感謝!

這項工作能夠完成, 在很大程度上要感謝一年多前成立的診斷工作組 [16] 的幫助, 該小組由來自 Go 社區各界的利益相關者組成, 並向公衆開放。

我們要藉此機會感謝在過去一年中定期參加診斷會議的社區成員: Felix Geisendörfer、Nick Ripley、Rhys Hiltner、Dominik Honnef、Bryan Boreham 和 thepudds。

你們所做的討論、反饋和工作是我們走到今天這一步的關鍵推動力。再次感謝!

Go 官方博客:More powerful Go execution traces[17] by Michael Knyszek.

Reference

[1]

runtime/trace 包: https://go.dev/pkg/runtime/trace

[2]

go tool trace 命令: https://go.dev/pkg/cmd/trace

[3]

gotraceui: https://gotraceui.dev/

[4]

Task: https://go.dev/pkg/runtime/trace#Task

[5]

Region: https://go.dev/pkg/runtime/trace#WithRegion

[6]

Log: https://go.dev/pkg/runtime/trace#Log

[7]

精彩博文: https://blog.felixge.de/reducing-gos-execution-tracer-overhead-with-frame-pointer-unwinding/

[8]

反思和重寫運行時中跟蹤實現的大量基礎部分: https://go.dev/issue/60773

[9]

重寫帶來了許多良好的改進: https://go.dev/doc/go1.22#runtime/trace

[10]

設計文檔: https://github.com/golang/proposal/blob/master/design/60773-execution-tracer-overhaul.md

[11]

移除此限制: https://go.dev/issue/65315

[12]

golang.org/x/exp/trace: https://go.dev/pkg/golang.org/x/exp/trace#FlightRecorder

[13]

提案問題: https://go.dev/issue/63185

[14]

golang.org/x/exp/trace: https://go.dev/pkg/golang.org/x/exp/trace#Reader

[15]

提案問題: https://go.dev/issue/62627

[16]

診斷工作組: https://go.dev/issue/57175

[17]

More powerful Go execution traces: https://go.dev/blog/execution-traces-2024

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

猜你喜歡