
trace 工具为什么抓不到调度延迟?
因为 runtime/trace 默认不开启调度器事件采集,trace.Start 只记录 goroutine 创建、阻塞、唤醒等基础事件,sched 相关的详细延迟(如 P 等待时间、G 在 runqueue 排队时长)需要额外启用运行时调试标记。
- 必须在程序启动前设置环境变量:
GODEBUG=schedtrace=1000,scheddetail=1(数字是毫秒间隔,太小会拖慢程序) - 仅靠
go tool trace打开 trace 文件,看不到“Scheduler Latency”面板——它依赖scheddetail输出的底层事件,否则 trace UI 里只有模糊的“Proc Status”条 - Go 1.21+ 中,
scheddetail仍有效,但部分字段含义有调整(比如runqhead改为runq长度统计),别直接套老文档的解读
如何用 trace + schedtrace 定位真实调度卡点?
核心是交叉比对两个数据源:可视化 trace 时间轴上的 goroutine 状态跳变,和终端里 schedtrace 打印的每 P 每秒快照。
- 启动时加
GODEBUG=schedtrace=500,scheddetail=1,同时调用trace.Start写文件 - 观察 trace UI 中某 goroutine 从
Runnable到Running的间隙:如果超过 1ms,且同期schedtrace显示某个 P 的runq长度持续 > 0,说明就绪队列积压 - 若 trace 里看到大量 goroutine 卡在
Runnable,但schedtrace显示所有 P 的runq都为空,那问题不在调度器排队,而在 P 被抢占或系统线程(M)卡住(比如 cgo 调用未释放 P)
trace.Start 后忘记 stop 会导致什么?
不是内存泄漏,而是运行时持续写入 trace buffer,最终触发强制 flush 并 panic,错误信息是:runtime: trace: failed to write to trace buffer: no space left。
-
trace.Start开启后,buffer 固定为 64MB(不可配置),写满即停;但若长期不trace.Stop,buffer 循环覆盖,丢失早期数据 - 线上服务切忌无条件调用
trace.Start,应配合信号或 HTTP endpoint 控制生命周期,例如监听SIGUSR2启动,收到两次则停止 - Go 1.22 修复了 stop 后 buffer 未清空的问题,但旧版本 stop 后仍可能残留部分事件,分析时注意时间范围是否完整
为什么 trace UI 里看不到 “Scheduler Latency” 面板?
这个面板只在 trace 文件包含 runtime.sched 事件时才激活,而这些事件依赖 scheddetail=1 且程序中显式调用了 runtime.SetMutexProfileFraction 或 runtime.SetBlockProfileRate —— 这是个隐藏耦合。
立即学习“go语言免费学习笔记(深入)”;
- 最简触发方式:在
trace.Start前加一行runtime.SetBlockProfileRate(1)(值非零即可) - 不设这个,即使开了
scheddetail,trace UI 也认为“调度细节不足”,隐藏该面板 - 该面板显示的是每个 G 从就绪到被 M 执行的实际延迟分布,横轴是延迟区间(ns),纵轴是频次,峰值 > 100μs 就值得查 P 是否过载或 M 是否频繁切换
schedtrace 快照和 trace 时间轴的微小错位里,比如一个 P 的 runq 长度突增 300ms 后,trace 里才出现大批 goroutine 卡在 Runnable——这说明你看到的“延迟”其实是积压结果,不是瞬时卡顿。别只盯着 trace UI 点来点去。










