time.Since()是最轻量、最安全的函数执行时间统计方式,需在目标goroutine内调用,自动防护系统时间跳变,避免负值,且语义清晰、精度达纳秒级。

time.Since() 是最轻量的延迟统计方式,但必须在目标 goroutine 内部调用
想看某个函数或 goroutine 执行了多久,time.Since() 是最快、最直接的选择。它比 time.Now().Sub(start) 更简洁,且内部做了系统时间跳变防护——如果 NTP 调整导致 time.Now() 回拨,time.Since() 会返回 0,避免 Prometheus 拒绝负值样本。
常见错误是把 start := time.Now() 放在外部作用域,然后传进多个 goroutine 共享,结果所有耗时都从同一时刻开始算。正确做法是每个 goroutine 自己调用 time.Now():
go func() {
start := time.Now()
defer func() {
log.Printf("worker done in %v", time.Since(start))
}()
// 实际工作
}()
- 别在 defer 里做网络上报、JSON 序列化等高开销操作;先存到局部变量,再异步处理
- 如果函数可能 panic,
defer仍能触发,这点比手动写结束时间更可靠 - 生产环境慎用
log.Printf频繁打点——每毫秒一次就可能压垮日志系统
HTTP 中间件里统计请求延迟,必须用 ResponseWriter 捕获真实 status code
很多中间件在 handler 返回后才读 r.Context().Value() 或假设状态是 200,结果所有 4xx/5xx 都被记成成功请求。真正靠谱的方式是包装 http.ResponseWriter,重写 WriteHeader() 方法来捕获首次写出的状态码。
更隐蔽的问题是:Gin/Echo 等框架可能在 handler 执行前就写了 header(比如预设 CORS),你的中间件若只在 handler 后读状态,就会漏掉这部分。所以必须拦截 WriteHeader() 调用时机:
立即学习“go语言免费学习笔记(深入)”;
type responseWriter struct {
http.ResponseWriter
statusCode int
}
func (rw *responseWriter) WriteHeader(code int) {
rw.statusCode = code
rw.ResponseWriter.WriteHeader(code)
}
- 打点前务必用
time.Since(start),别用time.Now().Sub(start)——后者在系统时间跳变时可能返回负值 - 打标维度至少包含
path、method、status,否则查“登录接口 P99”时会混入健康检查流量 - bucket 设置要贴业务:电商下单建议用
[]float64{0.05, 0.1, 0.2, 0.5, 1.0, 3.0, 5.0},不是默认的DefBuckets
延迟毛刺比平均值更重要,优先监控 go_gc_duration_seconds_count 和 rate(go_goroutines[5m])
单看 P99 延迟容易误判。真正危险的信号是底层资源水位异常:比如 go_gc_duration_seconds_count 每分钟突增,大概率是内存泄漏刚发生;rate(go_goroutines[5m]) 持续上升,说明有 goroutine 卡住没退出。
别盯着 go_gc_duration_seconds{quantile="0.5"} 看中位数——GC 毛刺往往藏在尾部;也别只看瞬时 go_goroutines 值,它波动太大,单点无意义。
- 告警规则应写成:
go_goroutines > 5000 and rate(go_goroutines[5m]) > 0(持续增长才触发) -
go_memstats_alloc_bytes的 raw 值含未释放临时对象,应关注rate(go_memstats_alloc_bytes_total[5m])分配速率 - pprof 必须限访问权限和采样时长,生产环境禁用无认证的
/debug/pprof/全开放
单次延迟排查别上 Prometheus,先用 pprof + trace 定位 Goroutine 阻塞点
当某次请求明显变慢(比如从 100ms 延迟到 2s),别急着查 metrics——那是聚合数据,看不到单次路径。该上 net/http/pprof 和 go tool trace。
启动 pprof 服务后,用 wget "http://localhost:6060/debug/pprof/goroutine?debug=2" 获取当前所有 goroutine 堆栈,重点找处于 select、chan receive、mutex 等阻塞状态的调用链。再配合 go tool trace 查看 GC 暂停是否干扰调度。
- 阻塞 profiling(
/debug/pprof/block)比 CPU profiling 更快暴露锁竞争问题 - trace 文件需用
go tool trace trace.out在浏览器打开,观察 Goroutine 的 runnable → running → blocking 状态流转 - 如果 trace 显示大量 goroutine 卡在
runtime.gopark,优先检查 channel 是否没关闭、context 是否没 cancel
time.Since() 放错作用域,或者用错状态码来源,结果监控数据全是噪音。



















