在Go的Web项目中，日志中间件承担着请求入口的统一观测职责。很多团队在项目初期只是简单地把method和URL打印到控制台，等到接口数量增多、并发压力上来之后才发现，这样的日志既无法定位问题，也没法关联请求上下文。本文将围绕Golang中间件日志记录这个话题，从ResponseWriter包装原理讲起，逐步落到请求ID透传、结构化输出和性能优化，最终得到一个可以直接嵌入现有服务的日志中间件方案。
从零实现一个最小的日志中间件
要记录请求信息，首先需要理解net/http的中间件模型。一个中间件本质上就是一个函数，它接收http.Handler，返回一个新的http.Handler。在这个包装过程中，我们可以在调用下一个handler之前读取请求信息，也可以在调用之后记录响应信息。关键问题在于，Go标准库的http.ResponseWriter是一个接口，只暴露了WriteHeader和Write方法，并没有直接告诉我们响应状态码是多少。如果我们想在日志里看到404还是500，就必须自己包装这个接口。
下面这段代码展示了一个最基础的状态码捕获实现。我们定义了一个responseWriter结构体，内嵌http.ResponseWriter，用statusCode字段记录写入的状态码。当业务handler调用WriteHeader时，状态码会被存下来；如果handler直接调用Write而没有调用WriteHeader，我们会主动记一个200，避免日志里出现0这样的无意义数值。
type responseWriter struct {
http.ResponseWriter
statusCode int
}
func (rw *responseWriter) WriteHeader(code int) {
rw.statusCode = code
rw.ResponseWriter.WriteHeader(code)
}
func (rw *responseWriter) Write(data []byte) (int, error) {
if rw.statusCode == 0 {
rw.statusCode = http.StatusOK
}
return rw.ResponseWriter.Write(data)
}
func LoggerMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start := time.Now()
wrapped := &responseWriter{ResponseWriter: w}
next.ServeHTTP(wrapped, r)
log.Printf("%s %s %d %s",
r.Method,
r.URL.Path,
wrapped.statusCode,
time.Since(start).Truncate(time.Microsecond),
)
})
}
这个实现虽然能跑，但还存在一个隐患。http.ResponseWriter在实际使用中经常需要被断言成其他接口，比如http.Flusher，用来在流式响应时调用Flush将缓冲数据立刻发送给客户端。如果我们直接把responseWriter传给业务handler，而它只实现了最基本的三个方法，那么服务的流式推送、WebSocket升级等能力就会全部失效。更隐蔽的情况是，很多Web框架会在handler内部做http.Hijacker的断言，断言失败就会直接panic。
解决这个问题的办法是做一个完整的接口保真。我们可以定义额外的包装结构，把Flusher、Hijacker、Pusher等接口都转发到底层ResponseWriter上。还有一种更轻量的方案，在声明包装结构时同时声明对应的转发方法，如下面的代码所示。实际项目中，建议至少把Flush和Hijack补上，因为这两种场景在业务中最为常见。
type responseWriter struct {
http.ResponseWriter
statusCode int
}
func (rw *responseWriter) Flush() {
if f, ok := rw.ResponseWriter.(http.Flusher); ok {
f.Flush()
}
}
func (rw *responseWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) {
if h, ok := rw.ResponseWriter.(http.Hijacker); ok {
return h.Hijack()
}
return nil, nil, fmt.Errorf("underlying ResponseWriter does not support Hijacking")
}
通过请求ID串联整个调用链
单独记录一行访问日志很容易，难的是把一次用户请求在网关、业务服务和下游数据库之间的完整路径串起来。尤其在微服务架构中，一个接口会调用多个服务，如果每个服务各自维护一套日志格式，排障时只能靠时间去猜。业界通用的做法是引入X-Request-ID头，网关生成一个全局唯一的ID，后续每个服务都把它透传下去，并把它打印到自己的日志里。
在中间件里处理请求ID需要遵守一条规则：如果上游已经传了X-Request-ID，就继续沿用；如果没传，则自己生成一个。为了避免每次请求都做重复的字符串判断，中间件应该把最终确认的请求ID放进r.Context()中，路由handler通过context获取即可。需要注意的是，GetXRequestID这类函数往往会被多个中间件调用，如果每次都从Header里读，不仅容易遗漏，还会多出很多无意义的代码。
type contextKey struct{}
func RequestIDMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
requestID := r.Header.Get("X-Request-ID")
if requestID == "" {
requestID = uuid.New().String()
}
w.Header().Set("X-Request-ID", requestID)
ctx := context.WithValue(r.Context(), contextKey{}, requestID)
next.ServeHTTP(w, r.WithContext(ctx))
})
}
func RequestIDFromContext(ctx context.Context) string {
if v, ok := ctx.Value(contextKey{}).(string); ok {
return v
}
return ""
}
在使用ID关联日志的基础上，我们还可以对它做进一步的约束。比如在中间件里校验请求ID的格式，只允许UUID或者一定长度的字母数字组合，避免有人手工构造出超长字符串把日志库撑爆。对于没有传入X-Request-ID的请求，有些团队会有两套策略：对内接口强制生成，对外接口则使用网关的ID，避免外部客户端直接猜测内部链路信息。这个取舍可以根据公司的技术规范来定，但无论如何，请求ID记录的字段顺序在全链路中应该保持一致，否则跨服务检索时还得重新对齐格式。
结构化日志与文件轮转方案
将日志用空格分隔输出虽然直观，但不利于日志采集系统解析。现在主流的日志平台普遍支持JSON格式的文本输入，一条日志一行JSON，采集端不需要研发定制切分规则，直接在查询页面上按字段过滤即可。Go 1.21之后标准库加入了log/slog，天生支持结构化输出，非常适合用来替换传统的log.Printf写法。下面这段代码演示了如何让日志中间件输出JSON片段，并同时包含method、path、status、耗时和请求ID等核心字段。
func LoggerMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start := time.Now()
wrapped := &responseWriter{ResponseWriter: w, statusCode: http.StatusOK}
requestID := RequestIDFromContext(r.Context())
next.ServeHTTP(wrapped, r)
slog.Info("http_request",
"method", r.Method,
"path", r.URL.Path,
"query", r.URL.RawQuery,
"status", wrapped.statusCode,
"duration_ms", float64(time.Since(start).Microseconds())/1000.0,
"client_ip", r.RemoteAddr,
"request_id", requestID,
)
})
}
文件轮转是日志管理绕不开的一件事。如果不做任何处理，服务长期运行之后单个日志文件会膨胀到几十GB，排查问题时编辑器连打开都困难。Linux上可以用logrotate工具在外部切割，但更好的方案是在应用内引入lumberjack这类库，让服务自己控制日志文件的大小和保留份数。下面的代码将slog的输出目标同时指向标准输出和一个带轮转的文件，每天按照200MB切割，最多保留7份历史文件。
func main() {
logFile := &lumberjack.Logger{
Filename: "C:\\logs\\app.log",
MaxSize: 200,
MaxBackups: 7,
MaxAge: 30,
Compress: true,
}
writer := io.MultiWriter(os.Stdout, logFile)
logger := slog.New(slog.NewJSONHandler(writer, &slog.HandlerOptions{
Level: slog.LevelInfo,
}))
slog.SetDefault(logger)
mux := http.NewServeMux()
mux.Handle("/api/user", UserHandler())
handler := RequestIDMiddleware(LoggerMiddleware(mux))
http.ListenAndServe(":8080", handler)
}
选择按大小轮转而不是按日期轮转，是因为生产环境的流量并不总是均衡的。如果某个秒杀活动让当天的日志量瞬间暴涨，按日期切割的方案会在同一天产生多个超大文件，而按大小切割则能把文件控制在一个可预期的体积内，配合MaxBackups设置数量上限，磁盘占用自然就稳定了下来。Compress选项开启后，lumberjack会把过期文件压缩成gzip格式再保留，进一步减少磁盘空间的占用。
性能优化：采样、异步写入与慢请求追踪
日志中间件看起来只是多打印了一行字，但在高QPS的接口上，每一行日志都包含一次JSON序列化和一次磁盘I/O。如果这些操作全部同步执行，log本身的耗时可能占到整个请求的5%到10%。一个常见的优化思路是把日志写入放到一个独立goroutine中，中间件只负责把日志内容发送到缓冲通道，由后台消费者统一刷盘。这样做需要控制通道的长度，并对实在写不进去的日志做主动丢弃，防止日志积压反过来拖垮业务逻辑。
另一种更实用的降本手段是采样。对于每天上亿次请求的业务，绝大多数日志其实永远不会被人查看，缺的只是在出问题时能查到现场。可以设定一个采样率，只记录所有请求中的1%作为全量样本，而对状态码为5xx、耗时超过阈值的请求做到100%记录。下面的代码演示了基于请求ID哈希来稳定采样的思路，这比随机数有一个优势：同一个ID的多次请求会得到相同的采样结果，方便追踪链路。
func shouldSample(requestID string) bool {
if requestID == "" {
return true
}
h := fnv.New32a()
h.Write([]byte(requestID))
return h.Sum32()%10000 < 100
}
func LoggerMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start := time.Now()
wrapped := &responseWriter{ResponseWriter: w, statusCode: http.StatusOK}
requestID := RequestIDFromContext(r.Context())
next.ServeHTTP(wrapped, r)
elapsed := time.Since(start)
if wrapped.statusCode >= 500 || elapsed > 500*time.Millisecond || shouldSample(requestID) {
slog.Info("http_request",
"method", r.Method,
"path", r.URL.Path,
"status", wrapped.statusCode,
"duration_ms", float64(elapsed.Microseconds())/1000.0,
"request_id", requestID,
)
}
})
}
慢请求追踪是排障中最有价值的信息之一。很多性能问题在正常压测时无法复现，只会在高峰期偶发出现，如果日志里没有耗时字段，连问题发生的时间段都难定位。建议将慢请求的阈值设置为动态配置，比如默认500毫秒，但允许通过环境变量或配置中心随时调整。对于超时的请求，除了记录基本信息之外，还可以把请求URL的query参数完整打到日志里，方便复现现场。不建议记录请求体，因为涉及敏感数据风险较大，而且大部分POST请求体在出问题后也无法直接在日志中理解。
最后补充一个容易忽略的细节：中间件的注册顺序决定了日志记录的范围。如果把日志中间件注册在路由之前，它只能记录那些确实进入了路由的请求，静态文件请求、404路径等都会漏掉。把日志中间件放在最外层，可以确保所有进入服务的请求都留下痕迹，也更容易根据URL模式统计未匹配接口的流量占比，这对接口规范的治理也有参考价值。