最直接记录单个 goroutine 执行时长是入口 time.now() + defer 调用 time.since()，需在 goroutine 内部获取 start 时间、避免共享，defer 中避免高开销操作；配合 context.withtimeout() 主动中断超时任务，定期监控 runtime.numgoroutine() 防泄漏，用 cpu profile 定位阻塞点。
用 time.Now() + defer 记录单个 goroutine 执行时长最直接
想看某个 goroutine 跑了多久，最轻量的方式就是在入口打点、出口算差值。别一上来就上 Prometheus 或 pprof——那些适合长期聚合统计，不是查单次延迟。
常见错误是忘记用 time.Since() 而写成 time.Now().Sub(start)，语义一样但前者更简洁；更隐蔽的坑是把 start 声明在外部作用域，导致多个 goroutine 共享同一个起始时间。
- 必须在 goroutine 内部调用
time.Now()，不能从外层传入 - 用
defer包裹耗时打印或上报逻辑，确保 panic 时也能触发 - 避免在 defer 中直接调用高开销函数（如网络上报），先记到局部变量再异步处理
go func() {
start := time.Now()
defer func() {
dur := time.Since(start)
log.Printf("task done in %v", dur)
}()
// ... 实际工作
}()
用 context.WithTimeout() 主动中断超时 goroutine
监控不只是“看”，更是“控”。如果一个 goroutine 本该 500ms 完成却卡住，光记录时长没用，得让它及时退出，防止堆积和资源泄漏。
典型误用是只用 time.AfterFunc() 杀 goroutine——它无法真正终止正在运行的代码，只是发信号，后续仍需配合 select + ctx.Done() 检查。
立即学习“go语言免费学习笔记（深入）”；
- 所有可能阻塞的操作（HTTP 请求、channel receive、数据库查询）都要接受
context.Context - 不要用
time.Sleep()替代 context 超时，它不响应取消 - 注意
context.WithTimeout()返回的cancel()必须调用，否则底层 timer 不释放
用 runtime.NumGoroutine() 和 debug.ReadGCStats() 看全局协程水位
单个 goroutine 的时长只是表象，真正要警惕的是协程数持续上涨——说明有 goroutine 没退出，或者漏了 cancel()，或者 channel 发送端没关。
很多人只盯着 P99 耗时，却忽略 runtime.NumGoroutine() 从 1k 涨到 10k，这比慢 100ms 危险得多。
- 定期采样
runtime.NumGoroutine()，突增 3 倍以上就要查泄漏点 -
debug.ReadGCStats()里的NumGC和PauseTotalNs能辅助判断是否因 GC 频繁拖慢协程调度 - 生产环境慎用
pprof.Lookup("goroutine").WriteTo()，全量 dump 可能卡住调度器
用 pprof.StartCPUProfile() 抓住长尾协程的真实栈
日志里看到 “task done in 2.3s”，但不知道它卡在哪——是等锁？等磁盘？还是死循环？这时候需要 CPU profile，而不是靠猜。
容易踩的坑是 profile 时间太短（比如只跑 100ms），抓不到低频但关键的长耗时路径；或者 profile 开在错误位置，比如只 profile 主 goroutine，而实际慢的是子 goroutine。
- profile 至少开启 5–10 秒，确保覆盖目标协程的完整生命周期
- 用
pprof.SetGoroutineLabels()给关键 goroutine 打标签，后续可按 label 过滤 - 分析时重点看
runtime.gopark和sync.runtime_SemacquireMutex出现频率，它们指向阻塞源头
协程执行时长监控真正的复杂点不在怎么记时间，而在如何区分“合理慢”和“异常卡”：一次 DB 查询慢 2s 可能是数据量大，连续 10 次都慢 2s 就是连接池不够或索引失效。指标本身不会说话，得结合上下文判断。
