Go 1.22 - 更加强大的 Go 执行跟踪

在这里插入图片描述

原文：Michael Knyszek - 2024.03.14

runtime/trace 包含了一款强大的工具，用于理解和排查 Go 程序。这个功能可以生成一段时间内每个 goroutine 的执行追踪。然后，你可以使用 go tool trace 命令（或者优秀的开源工具 gotraceui）来可视化和探索这些追踪数据。

追踪的魔力在于，它可以轻易地揭示出程序中那些难以通过其他方式看到的信息。例如，一个并发瓶颈可能是很多 goroutine 在同一个 channel 上阻塞，这在 CPU profile 中可能很难被看到，因为没有执行样本可以采样。但在执行追踪中，执行的缺失或不足 将以惊人的清晰度展现出来，被阻塞的 goroutine 的堆栈追踪将迅速指向问题根源。

在这里插入图片描述

Go 开发者甚至能够使用任务、区域和日志来对自己的程序进行插桩，以便将更高的关注点与底层执行细节进行关联。

问题

不幸的是，执行追踪中的丰富信息往往无法触及。历史上，四个主要问题阻碍了追踪的使用。

追踪的开销很大。
追踪的扩展性不强，可能会变得过大而无法分析。
往往不清楚何时开始追踪以捕获特定的不良行为。
鉴于缺乏用于解析和解释执行追踪的公共包，只有最具冒险精神的 gopher 才能编程分析追踪。

如果你在过去几年中使用过追踪，可能已经被这些问题中的一个或多个所困扰。但我们很高兴地分享，在过去的两个 Go 版本中，我们在这四个领域都取得了大的进步。

低开销的追踪

在 Go 1.21 之前，许多应用的追踪运行时开销大约在 10-20% 的 CPU 之间，这限制了追踪的使用情况，不能像 CPU profiling 那样持续使用。事实证明，追踪的大部分成本都归结于 traceback。运行时产生的许多事件都附带有堆栈追踪，这些对于实际识别 goroutine 在关键执行时刻的行为是非常有价值的。

感谢 Felix Geisendörfer 和 Nick Ripley 在优化 traceback 效率方面的工作，执行追踪的运行时 CPU 开销已经大幅降低，对于许多应用来说，现在只有 1-2%。你可以在 Felix 的精彩博客文章中关于这项工作的内容。

可扩展的追踪

追踪格式及其事件的设计主要考虑到了相对高效的数据生成和输出（emission），但需要工具来解析和保留整个追踪的状态。几百 MiB 的追踪可能需要几 GiB 的 RAM 来分析！

不幸的是，这个问题对于跟踪的生成方式至关重要。为了保持运行时开销低，所有事件都被写入等同于线程局部缓冲区的地方。但这意味着事件出现的顺序并非其真实顺序，追踪工具需要负责弄清楚究竟发生了什么。

使追踪在保持开销低的同时具有可扩展性的关键是，不定期地切分正在生成的追踪。每个切分点都会表现得有点像同时禁用和重新启用追踪。到目前为止的所有追踪数据都会代表一个完整且自包含的追踪，而新的追踪数据将无缝地接续前者。

你可能想象到，修复这个问题需要在运行时重新思考和重写追踪实现的很多基础部分。我们很高兴地说，这项工作在 Go 1.22 中完成，并且现在已经普遍可用。许多很好的改进随着重写一起出现，包括对 go tool trace 命令的一些改进。如果你感到好奇，所有的细节都在设计文档中。

（注意：go tool trace 仍然将完整的追踪加载到内存中，但现在已经可以移除这个限制，用于 Go 1.22+ 程序生成的追踪。）

Flight recording

假设你正在开发一个网络服务，一个 RPC 花费了很长时间。你不能在已经知道 RPC 花费了一段时间的点开始追踪，因为慢请求的根本原因已经发生并且没有被记录下来。

有一种可以帮助解决这个问题的技术，叫做 Flight recording，你可能已经在其他编程环境中熟悉了。Flight recording 的关键理念是，持续进行追踪，并始终保留最新的追踪数据，以便随时使用。然后，一旦发生了有趣的事情，程序就可以直接写出它所拥有的所有内容！

在追踪可以被切分之前，这基本上是无法实现的。但是，由于开销较低，连续跟踪现在是可行的，以及运行时现在可以在需要的时候随时切分追踪，结果，实现 Flight recording 非常简单。

因此，我们很高兴宣布一个 Flight recorder 实验特性，可在 golang.org/x/exp/trace 包中找到。

请试试看！下面是一个示例，设置了 Flight recorder 以捕获长时间的 HTTP 请求，以帮助你入门。

// 设置 Flight recorder 。
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))

如果你有任何反馈，无论是积极的还是消极的，都请分享到 proposal issue 中！

追踪 reader API

伴随着追踪实现的重写，我们也努力清理了其他的追踪内部工具，如 go tool trace。这促使我们尝试创建一个足够优秀，以至于可以分享的追踪 reader API，这个 API 能够让追踪数据更易于访问。

就像 Flight recorder 一样，我们很高兴宣布我们也有一个实验性的追踪 reader API，我们希望分享出来。它在与 Flight recorder 相同的包 golang.org/x/exp/trace 中可用。

我们认为它足够好以开始在其之上构建东西，所以请试试看！下面是一个示例，它测量了阻塞等待网络的 goroutine 阻塞事件的比例。

// 从 STDIN 开始读取。
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()

            // 寻找阻塞的 goroutines，并计数。
            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)