借助执行跟踪分析调度延迟和阻塞来源

Go 服务出现“平均延迟正常，但偶发请求突然慢很多”的情况时，先别急着在 CPU profile 里找热点。CPU profile 只能采样正在消耗 CPU 的代码，而 goroutine 排队、等待锁、等待 channel、等待网络或陷入系统调用时往往没有可采样的执行。执行跟踪会记录 goroutine 的创建、阻塞、唤醒、运行，系统调用、GC、堆变化和处理器状态，因此更适合回答两个问题：它为什么没有及时运行，以及它究竟在等什么。

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

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

go tool trace 文档：https://pkg.go.dev/cmd/trace

判断调度延迟与阻塞来源的关键，不是盯着一条长时间线猜原因，而是先把等待归入 sched、sync、net、syscall 等证据类别，再回到具体 goroutine 的事件栈、task 和 region。只有“状态、栈、业务语义”三者吻合，才算找到了根因。

影响面：为什么 CPU 不高，尾延迟仍然会升高

下面用一个教学复盘场景说明：某批处理接口平时耗时约几十毫秒，流量突增时少量请求超过一秒，但进程 CPU 使用率并没有同步打满。goroutine 数量上升，吞吐却没有线性增加。这个组合通常意味着工作并非一直在 CPU 上运行，而是花了较多时间处于以下状态之一：

Go 官方诊断文档也明确把 execution tracer 定位为延迟和利用率分析工具。它适合观察 goroutine 如何执行、GC 等运行时事件以及并行度不足；如果目标是找 CPU 热点或内存热点，仍应优先使用对应的 profile。两者不是替代关系。

时间线：先缩小等待类型，再看具体 goroutine

一次高效排查可以按“短窗口采集—派生 profile—事件栈—业务注解”的顺序推进。这里的时间线是诊断过程，而不是把浏览器视图从左拖到右。先把候选从整个程序缩小到一种等待类型，后面才不会被海量事件淹没。

1. 采集边界清晰的短跟踪

测试和基准可直接用 go test -trace。服务程序可以使用 runtime/trace.Start，也可以在受控的诊断端口通过 net/http/pprof 暴露 trace 入口。采集时尽量覆盖一次异常窗口，同时避免无边界地持续写大文件。

# 运行当前模块测试，并把执行跟踪写入 trace.out
go test -trace=trace.out ./...

# 打开官方 trace 分析入口；该命令会启动本地查看器
go tool trace trace.out

# 从跟踪中提取调度等待 profile，再用 pprof 查看累计栈
go tool trace -pprof=sched trace.out > sched.pprof
go tool pprof -top sched.pprof

# 分别提取同步、网络和系统调用阻塞，按证据类型缩小范围
go tool trace -pprof=sync trace.out > sync.pprof
go tool trace -pprof=net trace.out > net.pprof
go tool trace -pprof=syscall trace.out > syscall.pprof

go tool trace 官方支持的派生类型就是 net、sync、syscall 和 sched。其中 sched 代表调度延迟，sync 代表同步阻塞，net 代表网络阻塞，syscall 代表系统调用阻塞。先比较这些累计证据，通常比一上来浏览全部事件更快。

2. 回到事件栈确认谁让谁等待

派生 profile 只能告诉你累计等待主要落在哪些调用栈。根因确认还要回答：等待发生在哪类 goroutine、由什么事件唤醒、业务请求处于哪个阶段。若大量 worker 在 channel 接收处阻塞，这可能只是正常空闲；若请求处理 task 已开始，而 worker 长时间保持 runnable 或卡在同一把锁上，才与尾延迟直接相关。

触发条件：用 task 和 region 把运行时事件对齐业务阶段

执行跟踪本身认识 goroutine，却不天然认识“订单”“批任务”或“某次请求”。trace.NewTask 可以把跨多个 goroutine 的逻辑操作关联起来，trace.WithRegion 用于标记同一 goroutine 上的阶段区间，trace.Log 则记录少量分类消息。region 类型和日志类别应保持少量、稳定，不能把请求 ID 当成无限增长的类型。

package worker

import (
    "context"
    "runtime/trace"
    "sync"
)

type Job struct {
    ID      string
    Payload []byte
}

type Processor struct {
    mu    sync.Mutex
    jobs  chan Job
    cache map[string]int
}

func (p *Processor) Submit(ctx context.Context, job Job) {
    // Task 表示一次跨 goroutine 的完整业务操作，结束点必须明确。
    taskCtx, task := trace.NewTask(ctx, "batch-job")
    defer task.End()

    trace.Log(taskCtx, "job", "submitted")

    // enqueue region 只覆盖入队动作，可区分生产者排队与消费者处理。
    trace.WithRegion(taskCtx, "enqueue", func() {
        select {
        case p.jobs 

这个示例故意保留了两个可观察点：一是 enqueue，用于确认请求是否卡在满队列；二是 update-cache，用于确认锁竞争是否集中在共享 map 更新。若 region 本身很短，但 task 总时长很长，应继续检查 region 之间的 runnable 或 blocked 区间；若某个 region 长时间占据 task，则直接查看对应事件栈。

根因：四类等待不能混成一句“调度慢”

Runnable 很久：可运行不等于正在运行

goroutine 被唤醒后进入 runnable，但还没得到 P 执行，这段时间属于调度等待。常见原因包括瞬时 runnable goroutine 过多、可用并行度不足、长时间不让出处理器的工作，以及 GC 或 cgo 等运行时因素。判断时要同时看 runnable 堆积、处理器轨道和 sched profile 的栈，而不是仅凭 GOMAXPROCS 数值下结论。

Sync 阻塞：先区分正常协调与异常争用

channel、mutex、WaitGroup、条件变量都可能产生同步等待。消费者在空队列上睡眠属于正常协调；持锁代码把序列化范围扩大、无缓冲 channel 形成反压、任务忘记调用 Done，才是需要修复的来源。sync profile 的顶部栈给出累计阻塞位置，事件栈与唤醒关系则帮助判断等待双方。

Net 阻塞：没有超时的等待会伪装成调度问题

远端慢、连接池耗尽、DNS 或读写没有 deadline，都可能让大量 goroutine 停留在网络等待。此时 CPU 不高很正常。修复重点通常是为每层调用设置可传播的 context、超时和连接池上限，并在 task 日志中标出远端阶段。

Syscall 阻塞：关注是否把不可控耗时带进核心路径

文件 I/O、部分 DNS 路径、cgo 或设备调用可能进入系统调用。Go 运行时会尽力保持其他 goroutine 可运行，但大量或不可预测的阻塞调用仍会影响尾延迟。syscall profile 能累计这些等待栈；修复时应考虑批量化、隔离专用 worker、设置超时或把慢路径移出请求关键路径。

GC 事件：相关不代表就是根因

执行跟踪会包含 GC 与堆变化事件。若尾延迟窗口和 GC 重合，还要结合堆增长、分配速率以及 goroutine 是否处于 GC assist 等状态。执行跟踪适合解释“这段时间发生了什么”，但查找具体分配热点应回到 heap 或 allocs profile。

修复动作：让每类证据对应一个可验证改动

复盘最容易犯的错误，是看到锁、队列和网络都“有等待”，于是一次改很多参数。更稳妥的做法是每次只改一个主要假设，并在同样负载与采集窗口下重新生成 trace。下面是证据到动作的最小映射：

回归时至少保留三组数据：相同请求量下的 task 时长分布、四类派生 profile 的累计等待、goroutine 数量与队列深度。若尾延迟下降只是因为吞吐减少或请求被大量拒绝，这不是性能修复，而是负载转移。

防复发：把一次 trace 变成可重复的证据链

• 限制采集窗口：围绕异常前后采集短时间段，记录负载、版本与配置，避免巨型 trace 难以分析。
• 一次只开必要诊断：Go 官方提醒部分诊断工具会互相干扰，例如阻塞分析可能影响调度观察。需要精确比较时，分开采集。
• 注解业务边界：task 对应一次逻辑操作，region 对应少量稳定阶段，日志类别保持有限。
• 联动指标：持续记录队列深度、活跃 worker、请求超时、goroutine 数量和 p95/p99，指标触发后再保存短窗口 trace。
• 保留基线：对关键压测场景保存可复现命令和基线，而不是保存一张难以追溯的界面图片。

现代 Go 执行跟踪已经显著降低了常见程序中的运行开销，但“低开销”不等于可以忽略容量、文件大小和分析成本。生产采集仍应先评估影响、缩短窗口、限制访问，并避免把诊断入口暴露到不受信任网络。

常见问题

为什么 trace 里 goroutine 很多，却不一定是泄漏？

数量只表示某个时刻存在多少 goroutine。worker 池、连接处理和定时任务都可能长期存在。需要结合 goroutine 状态、创建栈、退出条件和数量趋势判断，执行跟踪主要回答这些 goroutine 在采集窗口内如何运行与等待。

只看 sched profile 能找到锁竞争吗？

不能把两者混为一谈。sched 关注 runnable 到获得执行机会的延迟，锁和 channel 的累计等待更适合先看 sync profile，再回到事件栈和唤醒关系确认。

执行跟踪能代替 CPU、heap 和 mutex profile 吗？

不能。执行跟踪擅长时间关系、调度、阻塞和运行时事件；CPU profile 擅长热点，heap/allocs profile 擅长分配，mutex profile 擅长锁竞争采样。先根据问题选择工具，再让多种证据互相印证。

task 和 region 有什么区别？

task 表示一次可能跨多个 goroutine 的逻辑操作，并通过 context 传播；region 是同一 goroutine 上的一段时间区间，可以嵌套。一次请求可对应一个 task，其中包含解析、排队、远端调用等多个 region。

执行跟踪真正有价值的地方，是让“请求慢”从模糊感受变成可归类的等待：究竟是可运行却没被调度、同步原语阻塞、网络等待、系统调用，还是运行时事件影响。按证据类型缩小范围，再用事件栈、task 和 region 还原业务语义，修复才不会停留在调大并发或盲目加缓存。