用 timinghandler 包裹 http.handler 实现耗时统计,需自定义 responsewriter 拦截 writeheader 和 write 以准确捕获状态码,避免日志中误记为200;勿用 time.unixnano 手动计算,应使用 time.since;日志应避免 fmt.sprintf 减少 gc 压力。

如何用 http.Handler 包裹现有路由统计耗时
Go 的 HTTP 服务本身不带响应时间埋点,得自己套一层中间件。核心是实现 http.Handler 接口,把原始 http.Handler 塞进去,在 ServeHTTP 里起始计时、结束打日志或写指标。
- 别直接改
http.HandleFunc,它返回的是func(http.ResponseWriter, *http.Request),要先用http.HandlerFunc转成Handler才能包裹 - 计时必须用
time.Now()和time.Since(),别用time.UnixNano()手动算——精度没区别,但可读性差、易出错 - 注意
ResponseWriter是接口,不能直接取状态码;得用struct包装它并重写WriteHeader方法才能捕获
type timingHandler struct {
next http.Handler
}
func (h *timingHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
start := time.Now()
tw := &timingResponseWriter{w: w, statusCode: 200}
h.next.ServeHTTP(tw, r)
dur := time.Since(start)
log.Printf("%s %s %d %v", r.Method, r.URL.Path, tw.statusCode, dur)
}
为什么 timingResponseWriter 必须实现 WriteHeader 和 Write
HTTP 状态码默认是 200,只有显式调用 WriteHeader 才会变;而很多库(比如 encoding/json)在写失败时不会调用它,而是直接往 ResponseWriter 写内容,触发隐式 200。不拦截这两个方法,你看到的永远是 200。
-
WriteHeader必须保存传入的code,这是唯一能拿到真实状态码的地方 -
Write也要转发,并检查是否首次写——如果还没调过WriteHeader就写内容,底层会自动设为 200,此时你要同步更新statusCode - 别漏掉
Flush、Hijack等方法:不实现它们会导致某些中间件(如 gzip)panic
net/http 默认不记录 4xx/5xx 耗时?真相是它根本不管业务逻辑异常
标准库只管连接建立、TLS 握手、请求解析和响应写出。你代码里 panic、数据库超时、JSON 解析失败……这些全在你的 handler 里,time.Since() 能覆盖,但状态码可能还是 200——除非你手动 WriteHeader。
- 常见坑:用
json.NewEncoder(w).Encode(...)出错时只返回 error,但没写 header,日志里就记成 200 + 超长耗时 - 修复方式很简单:所有写响应前加
if err != nil { http.Error(w, err.Error(), http.StatusInternalServerError); return } - 更稳妥的做法是统一用自定义错误响应函数,里面强制
w.WriteHeader,避免遗漏
要不要用 context.WithTimeout 替代耗时统计?完全不是一回事
context.WithTimeout 是控制 handler 执行上限,属于熔断/防护;耗时统计是观测手段。两者可以共存,但混用会掩盖问题。
立即学习“go语言免费学习笔记(深入)”;
- 加了
context.WithTimeout后,超时请求的耗时日志会显示接近 timeout 值(比如 5s),但这不代表它真跑了 5s——可能是前 10ms 就卡死在锁上,剩下全是等待 - 如果你只依赖超时上下文来“感知慢请求”,会漏掉大量 499ms、999ms 的毛刺,而它们加起来可能拖垮整个服务
- 真正该做的:统计 P95/P99 耗时 + 单独告警超时请求,而不是用 timeout 代替监控
最常被忽略的一点:日志里打耗时,别用 log.Printf 直接拼字符串——高并发下 fmt.Sprintf 分配小对象会显著抬高 GC 压力。用 log.Log 的 Printf 或结构化日志库的延迟求值字段。










