Golang Web开发中的自定义Logger中间件 Go语言请求耗时记录实战

go http中间件记录请求耗时应直接在handler开头用time.now()获取起始时间，并通过defer传参调用time.since()计算，避免闭包捕获变量或手动算差值引发溢出；日志需结构化包含method、path、status、cost_ms、remote_addr等字段，用fmt.sprintf拼接提升性能；trace_id应在最外层中间件用uuid.must(uuid.newrandom()).String()生成并存入context，确保全链路一致；日志输出到文件需手动flush或改用os.stderr/os.stdout以保证实时性。

Go HTTP中间件里怎么记录请求耗时

直接在 http.Handler 包裹函数里用 time.Now() 和 time.Since() 就行，别绕到 context 或中间件框架里加抽象——Go 的中间件本质就是函数套函数，越简单越稳。

常见错误是把耗时计算放在 defer 里但没传入起始时间，导致闭包捕获的是最后的 time.Time{} 值；或者用 time.Now().UnixNano() 手动算差值，反而引入整型溢出风险（尤其在高并发短请求下）。

实操建议：

• 在 handler 函数开头调一次 start := time.Now()
• 用 defer 打日志，但必须把 start 作为参数传进匿名函数，例如：defer func(s time.Time) { log.printf("cost: %v", time.Since(s)) }(start)
• 避免在 defer 中直接引用外部变量（如 start），Go 1.22 之前会捕获变量地址而非值

为什么不能直接用 log.Printf 而要封装成结构体

因为原生 log.Printf 没法区分不同请求，日志会挤在一起，排查时分不清哪条属于哪个 req.URL.Path 或 req.Method。更麻烦的是，它默认不带毫秒级时间戳，也压根没有请求 ID 支持。

立即学习“go语言免费学习笔记（深入）”；

你不需要写个完整日志库，但至少得有个轻量封装：

• 字段必须包含：method、path、status、cost_ms、remote_addr
• 用 fmt.Sprintf 拼接比多次 log.Print 更快（减少 I/O 调用次数）
• 别用 log.SetFlags(log.LstdFlags | log.Lshortfile) —— Lshortfile 在高并发下有锁竞争，拖慢整个 handler

示例片段：

logLine := fmt.Sprintf("[%s] %s %s %d %dms %s", time.Now().Format("15:04:05"), r.Method, r.URL.Path, statusCode, cost.Milliseconds(), r.RemoteAddr)

如何让每个请求带唯一 trace_id 方便串联日志

靠中间件往 context.Context 里塞 trace_id 最可靠，不是为了“微服务”，而是为了一旦下游调用出错，你能从 access log 里捞出对应请求的全部 debug 日志。

注意：别用 uuid.NewV4().String() 在每层都生成新 ID，那等于没串；也别用 rand.Intn() 这种低熵值——攻击者可能猜中 ID 并伪造日志。

实操建议：

• 在最外层中间件生成 ID，用 uuid.Must(uuid.NewRandom()).String()（Go 1.20+）
• 存进 context：ctx := context.WithValue(r.Context(), traceKey{}, tid)，其中 traceKey 是私有类型，避免 key 冲突
• 后续所有日志打印前，先从 r.Context().Value(traceKey{}) 取值，取不到就 fallback 到 "-"

为什么 log 输出到文件后看不到实时耗时统计

因为 Go 的 log.SetOutput 默认写的是带缓冲的 *os.File，而标准库的 log 不自动 flush。你看到的日志延迟，其实是内核页缓存 + Go runtime 缓冲叠加的结果。

这不是 bug，是设计权衡：吞吐优先于实时性。但开发期或小流量服务，你确实需要“写了就看到”。

解决方法很简单：

• 用 log.SetOutput(&os.Stderr) 替代文件句柄（终端输出无缓冲）
• 如果非要用文件，包装一层 bufio.Writer 并在每次写完后调 w.Flush()，但注意这会显著降低 QPS
• 更推荐方式：用 log.SetOutput(os.Stdout) + nginx 或 systemd 做日志收集，它们天然支持行缓冲和转发

顺带一提：log.Println 比 fmt.Println 多一次锁和格式化开销，在核心 handler 里高频打点时，差异能到 5%～10%。