execution trace中等待时间过长怎么办

Go execution trace 里出现一段很长的等待空档时，先不要把它直接归因到某个慢函数。正确顺序是：打开时间线确认 goroutine 和处理器的状态，再判断它是在等锁、通道、网络或定时器，还是根本没有可运行的工作，最后用 Flow Events、运行时事件和配套 profile 追到原因。

官方资料：https://go.dev/doc/diagnostics

runtime/trace 文档：https://pkg.go.dev/runtime/trace

先确认长等待属于 trace 能解决的问题

Go 官方把 execution tracer 定位为运行时事件观察工具：它能把调度、系统调用、垃圾回收、堆大小等信息放进时间线，用来发现延迟和利用率问题。它尤其适合回答“这个请求为什么在这段时间没有继续推进”，但不擅长单独回答“哪个函数消耗了最多 CPU”。后一个问题应该交给 CPU profile 或其他 profiling 工具。

因此，长等待的第一步不是立刻改 GOMAXPROCS 或把 goroutine 数量调大，而是把空档分成三个方向：某个 goroutine 在等资源、很多 goroutine 已经 Runnable 但没有及时运行、或者运行时事件/系统调用让推进被推迟。下面这张静态说明图对应的就是这个分流思路。

用 go tool trace 先看全局时间线

如果 trace 来自测试或基准测试，可以直接在采集时指定输出文件。命令中的 -trace 会把测试期间的 execution trace 写到文件；它不是让程序永久开启 tracing。

# 采集一个短窗口，避免把无关运行过程全部放进 trace
go test -run '^$' -bench '^BenchmarkRequest$' -benchtime=3s -trace trace.out ./internal/handler

# 用 Go 自带的 trace viewer 打开文件，命令会启动本地分析服务
go tool trace trace.out

在 viewer 中先看入口页的统计信息，再进入按 proc 或 goroutine 查看时间线。官方 viewer 会显示 Goroutines、Heap、Threads 等统计，并把 GC、Network、Timers、Syscalls 放在运行时间线附近。大文件可能被拆成多个等数据量区间，遇到这种情况要先选覆盖问题发生时刻的区间，不要把不同区间的空白直接拼在一起理解。

实际排查时建议按这个顺序缩放：

1. 先确认长空档发生在请求或任务的哪个时间范围。
2. 再看同一时间是否有大量 goroutine 进入 Waiting，或者有很多 goroutine 处于 Runnable。
3. 最后展开空档前后的事件，观察谁让目标 goroutine 停下、谁让它重新运行。

区分“等待资源”和“没有可运行工作”

这两个现象都可能在总时间线上表现为空白，但修复方向完全不同。等待资源时，通常能找到一个具体 goroutine 处于等待状态，并能从事件或栈中看到锁、通道、网络 I/O、定时器等原因；没有可运行工作时，处理器附近的 Runnable 数量可能很低甚至为空，空档不一定由某个资源持有者造成。

尤其要避免一个常见误判：处理器时间线上的空白，不等于“有一个锁把所有 goroutine 卡住了”。如果没有 Runnable 的工作，处理器本来就可能暂时空闲；反过来，如果 Runnable 数量很高，某个 goroutine 的等待只是局部现象。下面的对比图把资源持有者、唤醒流和空队列放在一起，便于对照阅读。

用 Flow Events 找到是谁让它继续或停止

时间线只能告诉你“这里发生了等待”，Flow Events 更接近“这次运行是被什么事件推动的”。打开 flow 关系后，先从目标 goroutine 的等待点向前找，再看它被唤醒后连接到哪个 goroutine、通道操作、网络事件或用户任务。这个动作比只看函数名更容易发现跨 goroutine 的因果关系。

在事件详情里重点记录三件事：等待开始时的栈、唤醒结束时的栈、以及连接两端的事件类型。若等待点落在锁或通道附近，继续回到业务代码确认是否把慢 I/O、序列化或远程调用放在临界区里；若等待点是网络或 syscall，则先确认超时和上游响应是否有明确边界。

package traceexample

import (
    "context"
    "runtime/trace"
)

func handle(ctx context.Context, load func() error) error {
    // 用 Task 表示跨 goroutine 的一次业务操作，便于在 trace 中按任务聚合延迟。
    ctx, task := trace.NewTask(ctx, "request")
    defer task.End() // 无论成功还是返回错误，都结束这次任务的时间范围。

    var err error
    // Region 标记当前 goroutine 内的一段关键工作，名字保持少量且稳定。
    trace.WithRegion(ctx, "load-data", func() {
        // 这里的实际业务调用可能阻塞在网络、锁或磁盘；用 trace 看它处于哪种等待。
        err = load()
    })
    return err
}

Task 适合跨多个 goroutine 的逻辑操作，Region 适合标记单个 goroutine 内的一段关键代码。标记要围绕真实业务动作，而不是给每一行代码都加名字；类型过多会让聚合结果失去可读性。图中“任务 / 区域”是解释这些标记如何帮助缩小范围的静态关系，不表示某次程序已经运行出该结果。

长等待时应该切换到哪些配套工具

当 trace 已经告诉你等待的类别，就不要继续把所有问题都塞回 trace：

• CPU 消耗高：使用 CPU profile，看热点函数和调用路径；trace 主要负责补充这些热点如何影响调度和延迟。
• 锁或通道阻塞：使用 block profile；如果明确是锁竞争，再看 mutex profile。Go 官方文档也提醒，阻塞 profiling 会影响 scheduler trace，采集时要按问题隔离工具。
• GC 事件明显：查看 GC 相关时间线和分配压力，结合 heap/CPU 数据判断是分配过多、对象存活过久还是业务批次过大。
• 线上服务偶发超时：短时间的 trace.Start/trace.Stop 可能已经错过问题；Go 1.25 的 runtime/trace 提供 FlightRecorder，可保留最近一段 trace，在检测到慢请求后抓取窗口。

长时间运行的服务不适合无期限地保存完整 trace。若问题发生后才知道要采集，可以让 flight recorder 保留最近几秒，在慢请求或健康检查失败时触发快照；这样保存的是问题前后的窄窗口，后续再用 go tool trace snapshot.trace 分析。

按证据修复，而不是先调大并发

当根因被缩小后，修复动作要和证据对应：

1. 等待锁：缩短临界区，避免在持锁期间做网络、磁盘或大对象编码，把读写职责拆开。
2. 等待通道：检查生产者和消费者的退出、缓冲容量与取消路径，确保超时能让 goroutine 结束等待。
3. 等待网络或 syscall：为调用设置合理的 context deadline，区分上游慢、连接池不足和本机系统调用延迟。
4. Runnable 堆积：先确认 CPU 是否饱和和并发是否过高，再调整任务粒度、worker 数量或 GOMAXPROCS，不要只凭一段空档下结论。
5. GC 影响明显：减少短时分配和不必要的临时对象，按 trace 中的时间窗口重新测量，而不是仅看全局平均值。

修改后重新采集一个足以覆盖慢请求的短 trace，并比较同一任务的等待区间、唤醒路径与配套 profile。一次成功的排查不是“空白消失”就结束，而是能说清等待从哪来、哪个组件负责唤醒，以及修复是否缩短了对应的延迟链。

常见问题

execution trace 中空白越长，说明 CPU 越慢吗？

不一定。空白可能表示 goroutine 在等待资源，也可能表示当前没有可运行的工作；CPU 热点需要用 CPU profile 判断。

为什么 trace 里看到 goroutine Waiting，却找不到一个明显的锁？

Waiting 还可能来自通道、网络 I/O、定时器或其他运行时事件。应展开事件类型、栈和唤醒流，而不是只搜索 mutex。

trace 和 block profile 可以一起采集吗？

可以按诊断需要组合，但要意识到 profiling 工具可能影响调度观察。若要比较时间线，最好分开采集相近场景的短窗口。

线上偶发超时，等发现后再调用 trace.Start 还来得及吗？

通常可能已经错过问题窗口。长运行服务可以考虑 Go 1.25 提供的 FlightRecorder，在异常触发时保存最近一段 trace。