不能在中间件里直接用time.since()算耗时后累加计数器,因为部分请求(如404未匹配、panic被recover拦截)根本不会执行到该逻辑,导致指标漏报;且panic未恢复时中间件后续代码不执行,无法覆盖所有终止路径。

为什么不能在中间件里直接用 time.Since() 算耗时后累加计数器
常见错误是写一个中间件,在入口记下 start := time.Now(),出口调 time.Since(start) 然后直接往 Prometheus 计数器或日志里塞——这会导致指标漏报。原因有二:一是某些请求根本不会走到该中间件(比如 404 路由未匹配、panic 后被 echo.MiddlewareFunc(recover) 拦截),二是 handler panic 后若没恢复,中间件后半段逻辑(包括耗时统计)压根不执行。
真正稳定的耗时采集点,必须覆盖所有终止路径:2xx/3xx/4xx/5xx 响应、panic 恢复、超时中断、客户端断连。Echo 框架唯一满足这点的钩子是 echo.HTTPErrorHandler,它在每次请求生命周期彻底结束时必调用。
怎么用 echo.HTTPErrorHandler 补全耗时统计
重写 HTTPErrorHandler 时,不能替换原始逻辑,只能追加指标收集。关键前提是:你在自定义中间件中已把开始时间存入 c.Set("startTime", time.Now()),且该中间件注册在所有其他中间件之前(确保即使路由未匹配也生效)。
Echo框架 5.1.0 版本源码包下载,适合关注 RealIP 行为变化、StartConfig.Listener、NewDefaultFS 和观测性中间件入口的开发团队。
- 先保存原始 handler:
oldHandler := e.HTTPErrorHandler - 再赋值新 handler,在其中取
c.Get("startTime")计算耗时,并记录状态码、路径等维度 - 最后务必调用
oldHandler(err, c),否则 panic 不会打印堆栈、错误响应也不发出去 - 注意
c.Get("startTime")返回的是interface{},需类型断言为time.Time,否则time.Since()panic
echo-contrib/prometheus 中间件为啥比手写更省心
它内部已经做了上述所有正确实践:自动注入 startTime、统一走 HTTPErrorHandler 采集、支持自定义分桶和标签归一化。但默认配置仍要调整,否则生产环境会出问题:
- 禁用默认 path 标签,改用正则归一化(如
/api/v1/users/:id→/api/v1/users/{id}),避免动态 ID 导致指标爆炸 - 重设直方图分桶,把
prometheus.DefBuckets换成[]float64{0.01, 0.05, 0.1, 0.25, 0.5, 1, 2, 5}(单位秒),才能看清真实 P99 - 初始化时传入自定义
Registry,方便与 OpenTelemetry 或其他 metrics 组件共存
耗时统计值比真实慢 1–5ms 是 bug 吗
不是。这是 Go runtime 调度延迟 + 网络栈(如 TCP ACK 延迟确认)叠加导致的系统级偏差。你测到的“耗时”是从 net/http 的 conn.Serve() 开始,到 writeResponse() 结束,中间夹着 goroutine 切换、syscall 返回、内核缓冲区刷新等不可控环节。只要各接口偏差一致,就可用于横向对比;若要纳秒级精度,得用 eBPF 工具(如 bpftrace)在 socket 层抓包。
真正容易被忽略的是:耗时指标必须和状态码、路径、method 三者绑定,单独看“平均耗时”毫无意义——可能 99% 请求 10ms,1% 请求卡在 DB 连接池上 5s,平均值却显示正常。










