Go 1-22 提供的更加強大的 Tracing 能力

本文是由 Go Team 的 Michael Knyszek 在 2024 年 3 月 14 日發表於 go official blog，原文地址：https://go.dev/blog/execution-traces-2024

runtime/trace package

runtime/trace[1] package 包含了理解並排查 Go 程序的強大工具。其功能可以生成每個 goroutine 在一段時間內的執行追蹤。通過使用 go tool trace[2] 命令（或優秀的開源 gotraceui[3] 工具），你可以可視化並探索這些追蹤中的數據。

Trace 的優勢在於它可以很容易展示出程序中難以以其他方式看到的問題。例如，許多 goroutine 阻塞在同一通道上的併發瓶頸可能在 CPU 分析中很難看到，因爲根本沒有執行可供採樣。但在執行追蹤中，許多堆棧可以清晰度顯示出來，並且阻塞的 goroutine 的堆棧跟蹤將迅速指向罪魁禍首。

Go 開發者甚至能夠使用 task[4]、regions[5] 和 logs[6] 來對他們自己的程序進行工具化，他們可以使用這些來將他們的高級關注點與低級執行細節相關聯。

存在的問題

不幸的是，執行追蹤中的豐富信息常常難以獲得。歷史上，追蹤存在四個主要問題。

  1. 追蹤有高開銷。

  2. 追蹤沒有很好地擴展，並且可能變得太大而無法分析。

  3. 通常不清楚何時開始追蹤以捕獲特定的不良行爲。

  4. 只有一部分 gopher 能夠程序化地分析追蹤，因爲缺乏通用的公共包來解析和解釋執行追蹤。

如果你在過去幾年中使用過追蹤，你很可能因爲這些問題中的一個或多個而感到沮喪。但我們很高興地分享，在過去兩個 Go 版本中，我們在所有這四個領域都取得了巨大進展。

低開銷追蹤

在 Go 1.21 之前，追蹤的運行時開銷對於許多應用程序來說在 10-20% 的 CPU 之間，這限制了追蹤的使用情況，而不是像 CPU 分析那樣的持續使用。事實證明，追蹤成本的很大一部分來自於回溯。運行時產生的許多事件都附有堆棧跟蹤，這對於實際識別 goroutine 在關鍵時刻正在做什麼非常有價值。

得益於 Felix Geisendörfer 和 Nick Ripley 在優化回溯效率方面的工作，執行追蹤的運行時 CPU 開銷已經大幅降低，對於許多應用程序降至 1-2%。你可以在 Felix 關於此主題的優秀博客文章 [7] 中閱讀更多關於這項工作的內容。

可擴展追蹤

追蹤格式及其事件的設計圍繞相對高效的發射，但需要工具來解析並保留整個追蹤的狀態。幾百 MB 的追蹤可能需要幾個 Gi B 的 RAM 來分析！

這個問題不幸地是追蹤生成方式的基本問題。爲了保持運行時開銷低，所有事件都被寫入相當於線程本地緩衝區的地方。但這意味着事件以非真實順序出現，追蹤工具需要弄清楚真正發生了什麼。

使追蹤在保持開銷低的同時擴展的關鍵見解是偶爾分割正在生成的追蹤。每個分割點的行爲有點像同時禁用和重新啓用一個 goroutine 中的追蹤。到目前爲止的所有追蹤數據將代表一個完整且自包含的追蹤，而新的追蹤數據將無縫地從它離開的地方繼續。

正如你所能想象的，修復這個問題需要重新思考和重寫運行時追蹤實現的許多基礎。我們很高興地說，這項工作已經在 Go 1.22 中落地，並且現在普遍可用。重寫帶來了許多不錯的改進，包括對 go tool trace 命令的一些改進。如果你好奇，所有細節都在設計文檔 [8] 中。

（注：go tool trace仍然將完整追蹤加載到內存中，但爲由 Go 1.22+ 程序生成的追蹤去除這個限制 [9] 現在是可行的。）

飛行記錄

假設你在處理一個 web 服務，一個 RPC 花費了很長時間。你不能在你知道 RPC 已經花費了很長時間的點開始追蹤，因爲慢請求的根本原因已經發生了，並沒有被記錄。

有一種稱爲飛行記錄的技術可以幫助解決這個問題，你可能已經從其他編程環境中熟悉了它。飛行記錄的見解是持續開啓追蹤，並始終保留最近的追蹤數據，以防萬一。然後，一旦發生有趣的事情，程序就可以簡單地寫入它所擁有的任何東西！

在追蹤可以分割之前，這幾乎是不可能的。但是，由於連續追蹤現在由於低開銷而變得可行，並且運行時現在可以在任何需要的時候分割追蹤，事實證明實現飛行記錄是直接的。

因此，我們很高興地宣佈一個飛行記錄器實驗，可在 golang.org/x/exp/trace[10] 包中使用。

請嘗試它！以下是設置飛行記錄器以捕獲長時間 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))

如果你有任何反饋，無論是積極的還是消極的，請分享到提案 issue 上！

Trace reader API

隨着追蹤實現的重寫，也進行了清理其他追蹤內部的工作，比如go tool trace。這催生了一個嘗試，創建一個足夠好的追蹤讀取器 API，以便共享，並可以使追蹤更加易於訪問。

就像飛行記錄器一樣，我們也很高興地宣佈我們還有一個實驗性的追蹤讀取器 API，我們想分享。它與飛行記錄器在同一個包中，golang.org/x/exp/trace。

我們認爲它足夠好，可以開始在其上構建東西，所以請嘗試它！以下是測量阻塞事件中 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 {
            from, to := st.Goroutine()

            // 查找阻塞的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)

我們想快速提到 Dominik Honnef，他早期嘗試了它，提供了很好的反饋，併爲 API 貢獻了對舊版本追蹤的支持。

參考資料

[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]

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

[6]

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

[7]

Felix blog: https://blog.felixge.de/reducing-gos-execution-tracer-overhead-with-frame-pointer-unwinding/

[8]

design docs: https://github.com/golang/proposal/blob/master/design/60773-execution-tracer-overhaul.md

[9]

issue 65315: https://go.dev/issue/65315

[10]

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

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

猜你喜歡