飞行记录器：一个新的 Go 执行追踪器

2024年，我们向世界介绍了更强大的Go执行跟踪。在那篇博文中，我们预览了一些可以通过新执行跟踪器解锁的新功能，包括飞行记录。我们很高兴地宣布，飞行记录现已在Go 1.25中可用，它是Go诊断工具箱中一个强大的新工具。

执行跟踪

首先，快速回顾一下Go执行跟踪。

Go运行时可以被设置为记录Go应用程序执行期间发生的许多事件的日志。这个日志被称为运行时执行跟踪。Go执行跟踪包含大量关于goroutine如何相互交互以及与底层系统交互的信息。这使得它们在调试延迟问题时非常有用，因为它们既告诉你goroutine何时执行，更重要的是，何时不执行。

runtime/trace包提供了一个API，通过调用runtime/trace.Start和runtime/trace.Stop来收集给定时间窗口内的执行跟踪。如果你跟踪的代码只是一个测试、微基准测试或命令行工具，这种方法效果很好。你可以收集完整端到端执行的跟踪，或者只收集你关心的部分。

然而，在长时间运行的Web服务中，即Go所擅长的那类应用程序中，这还不够好。Web服务器可能会运行数天甚至数周，收集整个执行过程的跟踪会产生太多数据，难以筛选。通常程序执行的只有一部分出现问题，比如请求超时或健康检查失败。当这种情况发生时，调用Start已经太晚了！

解决这个问题的一种方法是从整个服务集群中随机采样执行跟踪。虽然这种方法很强大，可以帮助在问题成为故障之前发现它们，但它需要大量基础设施才能运行。大量的执行跟踪数据需要被存储、分类和处理，其中大部分可能根本不包含任何有趣的内容。而当你试图找出特定问题的根源时，这种方法根本无法启动。

飞行记录

这就引出了飞行记录器。

程序通常知道什么时候出了问题，但根本原因可能早已发生。飞行记录器让你可以收集程序检测到问题之前最后几秒钟执行的跟踪。

飞行记录器像正常一样收集执行跟踪，但不是将其写入套接字或文件，而是在内存中缓冲最后几秒钟的跟踪。在任何时候，程序都可以请求缓冲区的内容，并准确地快照出问题时间窗口。飞行记录器就像一把手术刀，直接切入问题区域。

示例

让我们通过一个例子来学习如何使用飞行记录器。具体来说，让我们用它来诊断一个实现"猜数字"游戏的HTTP服务器的性能问题。它暴露了一个/guess-number端点，接受一个整数并响应调用者，告知他们是否猜对了数字。

还有一个goroutine，每分钟一次，通过HTTP请求向另一个服务发送所有猜测数字的报告。

// bucket是一个简单的互斥锁保护的计数器。type bucket struct { mu sync.Mutex guesses int } func main() { // 为客户端可能猜测的每个有效数字创建一个bucket。 // HTTP处理程序将通过使用数字作为切片的索引在buckets中查找猜测的数字。 buckets := make([]bucket, 100) // 每分钟，我们发送一份关于每个数字被猜测次数的报告。 go func() { for range time.Tick(1 * time.Minute) { sendReport(buckets) } }() // 选择要被猜测的数字。 answer := rand.Intn(len(buckets)) http.HandleFunc("/guess-number", func(w http.ResponseWriter, r *http.Request) { start := time.Now() // 从URL查询变量"guess"中获取数字并将其转换为整数。然后，验证它。 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 } // 选择适当的bucket并安全地增加其值。 b := &buckets[guess] b.mu.Lock() b.guesses++ b.mu.Unlock() // 向客户端响应猜测结果和是否正确。 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将buckets的当前状态发布到远程服务。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 } // 将报告数据编组为JSON负载。 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) } }

这是服务器的完整代码：https://go.dev/play/p/rX1eyKtVglF，以及一个简单的客户端：https://go.dev/play/p/2PjQ-1ORPiw。为了避免第三个进程，"客户端"也实现了报告服务器，尽管在真实系统中这些会是分开的。

假设在生产环境部署应用程序后，我们收到用户投诉，称一些/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中，我们将配置并启动飞行记录器：

// 设置飞行记录器fr := trace.NewFlightRecorder(trace.FlightRecorderConfig{ MinAge: 200 * time.Millisecond, MaxBytes: 1 << 20, // 1 MiB }) fr.Start()

MinAge配置可靠保留跟踪数据的持续时间，我们建议将其设置为事件时间窗口的约2倍。例如，如果你正在调试5秒钟的超时，将其设置为10秒。MaxBytes配置缓冲跟踪的大小，以免占用过多内存。平均而言，每秒执行可能会产生几MB的跟踪数据，或者对于繁忙的服务来说是10 MB/s。

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

var once sync.Once // captureSnapshot捕获飞行记录器快照。func captureSnapshot(fr *trace.FlightRecorder) { // once.Do确保提供的函数只执行一次。 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() // 忽略错误 // WriteTo将飞行记录器数据写入提供的io.Writer。 _, err = fr.WriteTo(f) if err != nil { log.Printf("writing snapshot to file %s failed: %s", f.Name(), err) return } // 在快照被获取后停止飞行记录器。 fr.Stop() log.Printf("captured a flight recorder snapshot to %s", f.Name()) }) }

最后，在记录完成的请求之前，如果请求花费超过100毫秒，我们将触发快照：

// 如果响应时间超过100ms，则捕获快照。// 只有第一次调用有效。if fr.Enabled() && time.Since(start) > 100*time.Millisecond { go captureSnapshot(fr) }

这是服务器的完整代码，现在已经使用飞行记录器进行了检测：https://go.dev/play/p/3V33gfIpmjG

现在，我们再次运行服务器并发送请求，直到获得触发快照的慢请求。

一旦我们获得了跟踪，我们需要一个工具来帮助我们检查它。Go工具链通过go tool trace命令提供了内置的执行跟踪分析工具。运行go tool trace snapshot.trace启动该工具，它会启动一个本地Web服务器，然后在浏览器中打开显示的URL（如果工具没有自动打开浏览器）。

这个工具给我们提供了几种查看跟踪的方式，但让我们专注于可视化跟踪，以了解发生了什么。点击"View trace by proc"来执行此操作。

在这个视图中，跟踪以事件时间线的形式呈现。在页面顶部的"STATS"部分，我们可以看到应用程序状态的摘要，包括线程数、堆大小和goroutine计数。

在下面的"PROCS"部分，我们可以看到goroutine的执行如何映射到GOMAXPROCS（Go应用程序创建的操作系统线程数）。我们可以看到每个goroutine何时以及如何开始、运行和最终停止执行。

现在，让我们将注意力转向查看器右侧执行中的这个巨大空白。在一段时间内，大约100ms，什么都没有发生！

通过选择zoom工具（或按3），我们可以更详细地检查空白后的跟踪部分。

除了每个goroutine的活动外，我们还可以通过"流事件"看到goroutine如何交互。传入流事件表示使goroutine开始运行的原因。传出流边缘表示一个goroutine对另一个goroutine产生的影响。启用所有流事件的可视化通常提供暗示问题源头的线索。

在这种情况下，我们可以看到许多goroutine在活动暂停后直接连接到单个goroutine。

点击单个goroutine显示一个充满传出流事件的事件表，这与我们启用流视图时看到的情况相匹配。

当这个goroutine运行时发生了什么？存储在跟踪中的部分信息是不同时间点的堆栈跟踪视图。当我们查看goroutine时，可以看到开始堆栈跟踪显示它在goroutine被调度运行时正在等待HTTP请求完成。而结束堆栈跟踪显示sendReport函数已经返回，它正在等待定时器以便在下一个计划时间发送报告。

在这个goroutine运行的开始和结束之间，我们看到大量的"传出流"，它与其他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)。

你们所有人的讨论、反馈和工作对推动我们迈向更好的诊断未来至关重要。谢谢！

Carlos Amedee和Michael Knyszek

本文在The Go Blog上提供，采用CC BY 4.0 DEED许可证。

照片由Lukas Souza在Unsplash上提供