因为time.Now()放在中间件开头仅记录进入中间件时刻,而非请求真实处理起点;正确做法是在c.Next()前后分别调用time.Now()以覆盖完整生命周期,确保耗时统计包含所有中间件和handler执行时间。

为什么 time.Now() 不能直接放在中间件开头就记录时间?
因为 Gin 的中间件是链式调用,next(c) 才真正执行后续 handler 和其他中间件。如果只在开头记一次时间,拿到的是“进入中间件的时刻”,而非“请求开始处理的时刻”——尤其当上游有反向代理(如 Nginx)或负载均衡时,真实请求时间可能更早。更关键的是,你无法知道 handler 是否 panic 或提前 abort,导致耗时统计失真。
正确做法是:在 next(c) 前后各调一次 time.Now(),确保覆盖整个请求生命周期(包括所有中间件和最终 handler):
func CostTime() gin.HandlerFunc {
return func(c *gin.Context) {
start := time.Now()
c.Next() // 这里才真正执行路由逻辑
cost := time.Since(start)
log.Printf("path=%s method=%s cost=%v", c.Request.URL.Path, c.Request.Method, cost)
}
}
如何避免 c.Next() 后取不到 status code?
Gin 默认不暴露响应状态码给中间件,因为 http.ResponseWriter 被封装了。直接读 c.Writer.Status() 是可行的,但要注意:这个值只有在 c.Next() 返回后才被写入,且前提是 handler 没有 panic 或手动调用 c.Abort() 中断流程。
常见错误是把 Status() 放在 c.Next() 前,或者没检查是否已写 header:
- 必须在
c.Next()之后调用c.Writer.Status() - 如果 handler 调用了
c.JSON(400, ...)或c.String(500, ...),状态码能正常获取 - 但如果 handler panic 且未被 recover 中间件捕获,
Status()会返回 0 —— 这时候建议搭配recovery中间件一起用
示例中建议这样写:
c.Next()
status := c.Writer.Status()
cost := time.Since(start)
log.Printf("status=%d cost=%v path=%s", status, cost, c.Request.URL.Path)
怎样让耗时统计支持 Prometheus 指标暴露?
单纯打日志不够,线上服务需要可聚合、可告警的指标。Gin 本身不内置 metrics,需配合 prometheus/client_golang 使用。核心是定义一个 prometheus.HistogramVec,按 path 和 method 维度打点。
注意三点:
- 不要为每个请求 new 一个 Histogram —— 必须复用全局注册的
*prometheus.HistogramVec - 路径要脱敏,比如把
/user/123归一为/user/:id,否则 label 爆炸 - 记得在
main()中调用prometheus.MustRegister()注册指标
简单示例(不带脱敏):
var (
requestDurHistogram = prometheus.NewHistogramVec(
prometheus.HistogramOpts{
Name: "http_request_duration_seconds",
Help: "Duration of HTTP requests.",
Buckets: prometheus.DefBuckets,
},
[]string{"path", "method", "status"},
)
)
func Metrics() gin.HandlerFunc {
return func(c *gin.Context) {
start := time.Now()
c.Next()
requestDurHistogram.WithLabelValues(
c.Request.URL.Path,
c.Request.Method,
strconv.Itoa(c.Writer.Status()),
).Observe(time.Since(start).Seconds())
}
}
为什么加了耗时中间件后接口变慢了?
不是中间件本身慢,而是日志或 metrics 写入成了瓶颈。比如每请求都调用 log.Printf(),在高并发下会阻塞 goroutine;或者 Prometheus 的 .Observe() 在未配置本地缓存时,频繁锁竞争。
优化方向很实际:
- 日志级别控制:生产环境关闭 debug 级别耗时日志,只保留 error 或 warn
- 异步打点:对 Prometheus,可用
promauto+ 本地计数器先 accumulate,再定时 flush(但 histogram 不支持攒批,得权衡) - 采样开关:高频接口(如健康检查)可跳过统计,用
if c.Request.URL.Path != "/healthz" { ... } - 避免字符串拼接:用
fmt.Sprintf比多次+更快,但最好用log.Sugar().Infow()这类结构化日志库
最常被忽略的一点:中间件顺序。如果把耗时统计放在 recovery 之后,panic 就不会被统计到;放在 cors 之前,则跨域预检请求也会被计入——这些都会扭曲真实业务耗时。


















