Go 1.25 的飞行记录器

2024 年，Go 项目介绍了更强大的 Go 执行轨迹，并预告了新执行追踪器能够支持的功能，其中包括飞行记录。如今，这项功能已在 Go 1.25 中提供，成为 Go 诊断工具箱中的一件强大工具。

执行轨迹

先简单回顾一下 Go 执行轨迹。

Go 运行时可以输出一份日志，记录 Go 应用执行期间发生的许多事件。这份日志称为运行时执行轨迹。它包含大量信息，展示 goroutine 如何相互交互，以及如何与底层系统交互。这对排查延迟问题很有帮助：它既告诉我们 goroutine 何时在执行，也告诉我们一个同样关键的事实——它们何时没有执行。

runtime/trace 包提供了 API，通过调用 runtime/trace.Start 和 runtime/trace.Stop，收集指定时间窗口内的执行轨迹。对于测试、微基准测试或命令行工具，这种方式很好用。可以收集从头到尾的完整执行轨迹，也可以只收集关心的部分。

但对于 Go 常用来构建的长期运行 Web 服务，这还不够。Web 服务器可能连续运行几天甚至几周，记录整段执行过程会产生多到难以筛查的数据。通常，只是程序执行中的某个局部出了问题，例如请求超时或健康检查失败。等问题出现，再调用 Start 已经晚了。

一种办法是在整个服务集群中随机采样执行轨迹。这种方式能力很强，能在问题发展成故障前发现它们，但需要大量基础设施。大量轨迹数据必须保存、分流和处理，其中许多根本没有值得关注的信息。而当目标是查清某个具体问题时，这种办法就不适用了。

飞行记录

这就引出了飞行记录器。

程序往往知道什么时候出了问题，但根本原因可能发生在更早的时候。飞行记录器可以收集程序发现问题之前最后几秒的执行轨迹。

它照常收集执行轨迹，但不写入套接字或文件，而是在内存中缓冲最近几秒的数据。程序随时可以请求缓冲区的内容，准确截取发生问题的那段时间。飞行记录器就像一把手术刀，直接切入问题所在。

示例

下面用一个例子学习如何使用飞行记录器：诊断一个“猜数字”HTTP 服务器的性能问题。服务器提供 /guess-number 端点，接受一个整数，并告诉调用者有没有猜中。另有一个 goroutine，每分钟通过 HTTP 请求向另一个服务发送所有猜测数字的统计报告。

// bucket is a simple mutex-protected counter.
type bucket struct {
    mu      sync.Mutex
    guesses int
}

func main() {
    // Make one bucket for each valid number a client could guess.
    // The HTTP handler will look up the guessed number in buckets by
    // using the number as an index into the slice.
    buckets := make([]bucket, 100)

    // Every minute, we send a report of how many times each number was guessed.
    go func() {
        for range time.Tick(1 * time.Minute) {
            sendReport(buckets)
        }
    }()

    // Choose the number to be guessed.
    answer := rand.Intn(len(buckets))

    http.HandleFunc("/guess-number", func(w http.ResponseWriter, r *http.Request) {
        start := time.Now()

        // Fetch the number from the URL query variable "guess" and convert it
        // to an integer. Then, validate it.
        guess, err := strconv.Atoi(r.URL.Query().Get("guess"))
        if err != nil || !(0 <= guess && guess < len(buckets)) {
            http.Error(w, "invalid 'guess' value", http.StatusBadRequest)
            return
        }

        // Select the appropriate bucket and safely increment its value.
        b := &buckets[guess]
        b.mu.Lock()
        b.guesses++
        b.mu.Unlock()

        // Respond to the client with the guess and whether it was correct.
        fmt.Fprintf(w, "guess: %d, correct: %t", guess, guess == answer)

        log.Printf("HTTP request: endpoint=/guess-number guess=%d duration=%s", guess, time.Since(start))
    })
    log.Fatal(http.ListenAndServe(":8090", nil))
}

// sendReport posts the current state of buckets to a remote service.
func sendReport(buckets []bucket) {
    counts := make([]int, len(buckets))

    for index := range buckets {
        b := &buckets[index]
        b.mu.Lock()
        defer b.mu.Unlock()

        counts[index] = b.guesses
    }

    // Marshal the report data into a JSON payload.
    b, err := json.Marshal(counts)
    if err != nil {
        log.Printf("failed to marshal report data: error=%s", err)
        return
    }
    url := "http://localhost:8091/guess-number-report"
    if _, err := http.Post(url, "application/json", bytes.NewReader(b)); err != nil {
        log.Printf("failed to send report: %s", err)
    }
}

服务器的完整代码和一个简单客户端可在 Go Playground 查看。为了避免启动第三个进程，示例中的“客户端”也实现了接收报告的服务器；真实系统通常会把二者分开。

假设应用部署到生产环境后，用户反馈部分 /guess-number 调用比预期慢。检查日志会发现，有些响应时间超过 100 毫秒，而大多数调用只在微秒量级。原文展示了以下日志：

2025/09/19 16:52:02 HTTP request: endpoint=/guess-number guess=69 duration=625ns
2025/09/19 16:52:02 HTTP request: endpoint=/guess-number guess=62 duration=458ns
2025/09/19 16:52:02 HTTP request: endpoint=/guess-number guess=42 duration=1.417µs
2025/09/19 16:52:02 HTTP request: endpoint=/guess-number guess=86 duration=115.186167ms
2025/09/19 16:52:02 HTTP request: endpoint=/guess-number guess=0 duration=127.993375ms

继续之前，可以先花一点时间看看能否发现问题。

无论是否已经找出原因，都可以进一步从基本原理出发定位问题。要是能看到慢响应之前应用正在做什么，就会很有帮助。这正是飞行记录器的用途：看到第一次超过 100 毫秒的响应时，就捕获一份执行轨迹。

首先，在 main 中配置并启动飞行记录器：

// Set up the flight recorder
fr := trace.NewFlightRecorder(trace.FlightRecorderConfig{
    MinAge:   200 * time.Millisecond,
    MaxBytes: 1 << 20, // 1 MiB
})
fr.Start()

MinAge 配置轨迹数据能够可靠保留的时长。原作者建议把它设为事件时间窗口的约两倍。例如，排查 5 秒超时，就设为 10 秒。MaxBytes 配置缓冲轨迹的大小，避免内存使用失控。平均而言，每秒执行可能产生几 MB 轨迹数据；繁忙服务可能达到 10 MB/s。

接下来，添加一个辅助函数，捕获快照并写入文件：

var once sync.Once

// captureSnapshot captures a flight recorder snapshot.
func captureSnapshot(fr *trace.FlightRecorder) {
    // once.Do ensures that the provided function is executed only once.
    once.Do(func() {
        f, err := os.Create("snapshot.trace")
        if err != nil {
            log.Printf("opening snapshot file %s failed: %s", f.Name(), err)
            return
        }
        defer f.Close() // ignore error

        // WriteTo writes the flight recorder data to the provided io.Writer.
        _, err = fr.WriteTo(f)
        if err != nil {
            log.Printf("writing snapshot to file %s failed: %s", f.Name(), err)
            return
        }

        // Stop the flight recorder after the snapshot has been taken.
        fr.Stop()
        log.Printf("captured a flight recorder snapshot to %s", f.Name())
    })
}

最后，在记录已完成请求的日志之前，如果请求耗时超过 100 毫秒，就触发快照：

// Capture a snapshot if the response takes more than 100ms.
// Only the first call has any effect.
if fr.Enabled() && time.Since(start) > 100*time.Millisecond {
    go captureSnapshot(fr)
}

接入飞行记录器后的服务器完整代码也可查看。原作者随后再次运行服务器，不断发送请求，直到一次慢请求触发快照。

获得轨迹后，需要用工具查看它。Go 工具链通过 go tool trace 命令提供内置的执行轨迹分析工具。运行 go tool trace snapshot.trace 会启动本地 Web 服务器，然后在浏览器中打开显示的 URL；如果工具没有自动打开浏览器，就手动打开。

工具提供多种查看方式。这里选择“View trace by proc”，将轨迹可视化，了解当时发生了什么。

这个视图把轨迹呈现为事件时间线。页面顶部的“STATS”区域汇总应用状态，包括线程数、堆大小和 goroutine 数量。下面的“PROCS”区域展示 goroutine 的执行如何映射到 GOMAXPROCS（原文以应用创建的操作系统线程数量解释这个值），可以看到各个 goroutine 何时开始、运行以及停止执行。

原文视图右侧有一段很大的执行空白：大约 100 毫秒内，没有任何活动。选择 zoom 工具或按 3，就可以细看空白结束后的轨迹。

除了各个 goroutine 自身的活动，还可以通过“flow events”观察它们之间的交互。传入的流事件说明是什么让 goroutine 开始运行；传出的流边说明这个 goroutine 对其他 goroutine 产生了什么影响。显示全部流事件，通常能提供问题来源的线索。

在本例中，活动暂停结束后，许多 goroutine 都与同一个 goroutine 直接相连。点击这个 goroutine，事件表里有大量传出的流事件，与启用流视图时看到的情况一致。

它运行时发生了什么？轨迹保存的信息包括不同时刻的调用栈。查看这个 goroutine，会发现开始时的调用栈表明：它被调度运行之前，正在等待 HTTP 请求完成。而结束时的调用栈表明，sendReport 已经返回，它正在等待 ticker，以便在下一个计划时间发送报告。

在这段执行的开始与结束之间，有大量“outgoing flows”，说明它与其他 goroutine 发生了交互。点击其中一个 Outgoing flow 条目，会进入交互视图。这条流指向 sendReport 中的 Unlock：

for index := range buckets {
    b := &buckets[index]
    b.mu.Lock()
    defer b.mu.Unlock()

    counts[index] = b.guesses
}

sendReport 的本意是锁住每个 bucket，复制数值后立即释放锁。

问题就在这里：复制 bucket.guesses 的值后，并没有立即释放锁。由于释放锁使用了 defer 语句，释放动作要等到函数返回才会发生。锁不只持有到循环结束，还会一直持有到 HTTP 请求完成。这样细微的错误，在大型生产系统中可能很难查清。

幸运的是，执行追踪帮助原作者准确定位了问题。如果没有新的飞行记录模式，直接在长期运行的服务器中使用执行追踪器，很可能累积海量数据，需要运维人员存储、传输并逐一筛查。飞行记录器让我们能够回看已经发生的事情，只捕获出错的那段执行过程，迅速逼近原因。

它是 Go 开发者诊断运行中应用内部行为的最新工具之一。最近几个版本一直在改进追踪功能：Go 1.21 大幅降低追踪的运行时开销，Go 1.22 让轨迹格式更健壮，并支持分割，进而促成飞行记录器这样的功能。

gotraceui 等开源工具，以及即将提供的程序化执行轨迹解析能力，都是利用执行轨迹的更多方式。诊断页面列出了许多其他工具，可以在编写和改进 Go 应用时使用。

致谢

原作者感谢多年来积极参与诊断会议、贡献设计并提供反馈的社区成员：Felix Geisendörfer（@felixge.de）、Nick Ripley（@nsrip-dd）、Rhys Hiltner（@rhysh）、Dominik Honnef（@dominikh）、Bryan Boreham（@bboreham）和 PJ Malloy（@thepudds）。大家的讨论、反馈和工作，推动了更好的诊断工具的未来。

原作：Flight Recorder in Go 1.25，Carlos Amedee 与 Michael Knyszek，2025-09-26。正文依据 CC BY 4.0 转为中文，代码及日志保持原样；许可依据：Go 版权说明。文中运行和分析结果为原作者示例，本稿未执行这些程序。

技术校注：原示例保留了 os.Create 失败分支中对 f.Name() 的调用，失败时可能对 nil 文件调用方法；生产应用应修正。GOMAXPROCS 更准确的含义是可同时执行 Go 代码的操作系统线程数量上限，并非程序创建的全部线程数。原示例的 HTTP 资源关闭、超时与快照访问控制也应按实际场景补齐。

代码许可：Copyright 2009 The Go Authors. BSD 3-Clause，完整许可随稿保存在 LICENSE-BSD.txt。