拓十年匠心定制 · 商业建站与技术教学双线并行 咨询热线:400-886-1026 service@lmnt.cn
ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

Gin中间件链详解:Logger与Recovery及自定义实践

Gin中间件链详解:Logger与Recovery及自定义实践 前两天我在一个 gin gorm go-redis 的实战项目里补请求链路日志绕不开的就是中间件链。一开始老老实实用gin.Default()自带的 Logger 和 Recovery觉得挺省事但后来要加 traceID、要捕获响应体、还要调整 panic 之后的返回结构才发现如果不把中间件链的运行机制吃透写出来的代码基本是靠经验猜。这篇文章就当作 Day03 的工程记录把 Gin 里的 Logger、Recovery 和自定义中间件一次性讲清楚顺带把我踩过的坑都列出来。适合刚开始用 Gin 写后端的人也适合从其他框架转过来、对c.Next()和c.Abort()还没完全理清的同学。1. 中间件链的本质为什么 Gin 要把请求处理串成一条链1.1 HandlerFunc 和 c.Next() 的执行模型先看一个最小例子package main import ( log github.com/gin-gonic/gin ) func m1(c *gin.Context) { log.Println(m1 before) c.Next() log.Println(m1 after) } func m2(c *gin.Context) { log.Println(m2 before) c.Next() log.Println(m2 after) } func main() { r : gin.New() r.Use(m1, m2) r.GET(/ping, func(c *gin.Context) { log.Println(handler) c.String(200, pong) }) _ r.Run(:8080) }启动后请求一次/ping控制台输出顺序是m1 before m2 before handler m2 after m1 after这就是中间件链最核心的直觉多个中间件按注册顺序排成一个 slicec.Next()负责把控制权交给下一个 handler等后续所有 handler 都执行完再回到当前中间件继续执行c.Next()之后的代码。用洋葱来类比会很好理解。最外层先进入最外层最后退出。每个中间件所谓“before”部分其实就是在c.Next()之前做的准备工作而“after”部分则是在整个后续链路执行回来的收尾工作。这也是为什么日志中间件要把耗时统计放在c.Next()前后两端因为只有这样才能覆盖完整请求生命周期。需要提醒的是c.Next()并不启动新的 goroutine它只是在一个循环里逐个执行 handler slice 里的函数。看到这里你应该明白一件事中间件本质上和业务 handler 没有区别它们都是gin.HandlerFunc只是通过c.Next()把执行流串联起来。理解这一点之后写自定义中间件就没有任何神秘感了。1.2 中间件注册的三种作用域Gin 提供三个层次的注册方式按作用范围从大到小排列注册位置写法适用范围全局路由r.Use(m1, m2)所有请求包括尚未注册的路由路由组group : r.Group(/api, m1)该分组下的所有请求单条路由r.GET(/ping, m1, m2, handler)只有这条路由这三种方式可以混用。比如全局挂一个 Recovery路由组里挂认证中间件单条路由再挂一个限流中间件r : gin.New() r.Use(gin.Logger(), gin.Recovery()) api : r.Group(/api, AuthMiddleware()) { api.GET(/users, ListUsers) api.GET(/orders, ListOrders) } open : r.Group(/api/open) open.GET(/health, HealthCheck) open.GET(/rate-test, RateLimitMiddleware(), RateTestHandler)选择哪种作用域本质是在回答“这个中间件要管多少请求”的问题。全局中间件虽然省事但也会拖累不需要它的接口。比如一个纯静态文件下载接口完全没必要走耗时的参数校验中间件。所以一般情况下我的习惯是基础能力日志、恢复放全局业务能力认证、鉴权、限流放路由组临时能力调试、mock、灰度标记放单条路由。1.3 中间件解决的核心问题横切关注点复用没有中间件的时候你会在每个 handler 里写一样的代码func ListUsers(c *gin.Context) { start : time.Now() defer func() { log.Printf(cost %v, time.Since(start)) }() // handler 业务代码 } func ListOrders(c *gin.Context) { start : time.Now() defer func() { log.Printf(cost %v, time.Since(start)) }() // handler 业务代码 }代码重复还只是表面问题。更麻烦的是如果有一天要求把日志切到 JSON 格式或者需要给所有接口的耗时日志加上 traceID你就要一个 handler 一个 handler 地改。中间件把这类“横切关注点”集中到一处让业务 handler 只关心自己的业务参数和返回结果。Logger、Recovery、鉴权、限流、请求ID、响应包装这些都不是业务逻辑但它们又是每个接口都需要的中间件就是为这种情况设计的。2. 内置 Logger 与 Recovery开箱即用的两个安全网2.1 gin.Default() 到底装了什么很多新手直接用gin.Default()却不知道它和gin.New()的区别。看源码就知道gin.Default()等价于gin.New()之后再Use(Logger(), Recovery())。换句话说你之所以在用 Gin 时不像用原生 net/http 那样经常因为 panic 整个程序挂掉是因为框架默认帮你兜住了。如果你图省事使用了gin.Default()那么在源码里看到engine.Use(Logger(), Recovery())时应该心里有数。如果你自己改用gin.New()记得手动加gin.Recovery()否则一个 handler 里的小 panic 可能导致整个进程退出。这个问题在线上非常致命因为一个请求触发 panic往往影响的是整个服务实例的存活而不仅仅是那一个接口。2.2 Logger 的默认输出结构和字段含义gin.Logger()默认输出到标准输出格式大致如下[GIN] 2025/06/12 - 10:15:30 | 200 | 1.234567ms | 127.0.0.1 | GET /api/users从左到右分别是时间、状态码、耗时、客户端 IP、请求方法和路径。这些字段基本够用但有几个问题默认输出是文本格式不方便直接进 ELK 这类日志系统没有 traceID也没有请求体或响应体内容。如果只是简单调整格式可以这样r.Use(gin.LoggerWithFormatter(func(param gin.LogFormatterParams) string { return fmt.Sprintf(%s | %d | %s | %s | %s %s\n, param.TimeStamp.Format(2006-01-02 15:04:05), param.StatusCode, param.Latency, param.ClientIP, param.Method, param.Path, ) }))但如果是生产环境我更建议不要依赖内置中间件做复杂日志直接用自定义中间件输出结构化 JSON。内置 Logger 适合开发和简单部署场景能快速看到请求概览一旦有链路追踪、Body 日志等需求就得自己接管了。2.3 Recovery 是怎么把 panic 变成 500 的gin.Recovery()的原理并不复杂内部使用 defer recoverfunc Recovery() HandlerFunc { return RecoveryWithWriter(DefaultErrorWriter) } func RecoveryWithWriter(out io.Writer, recovery ...RecoveryFunc) HandlerFunc { return func(c *gin.Context) { defer func() { if err : recover(); err ! nil { // 打印堆栈 // 调用 recovery 函数 c.AbortWithStatus(http.StatusInternalServerError) } }() c.Next() } }它捕获 panic 后默认返回空 body 的 500 响应并把堆栈打印到os.Stderr。在开发环境用挺方便但生产环境最好自定义返回格式否则前端拿到一个空 500排查问题时很难受。可以通过gin.CustomRecovery自定义兜底逻辑r.Use(gin.CustomRecovery(func(c *gin.Context, recovered any) { c.JSON(http.StatusInternalServerError, gin.H{ code: 500, message: 服务器内部错误, }) }))这里有一个新手经常搞混的点gin.Recovery()捕获的是某个 goroutine 内触发的 panic但它覆盖不了其他 goroutine 里的 panic。后面踩坑部分我会单独说因为 Go 的 recover 只能恢复当前 goroutine 的 panic跨 goroutine 是没办法的。2.4 顺序为什么是 Logger 在外、Recovery 在内gin.Default()内部注册顺序是Logger()先Recovery()后也就是r.Use(gin.Logger()) r.Use(gin.Recovery())一开始我以为是随便排的后来遇到一次 panic 才明白这个顺序的用意。假设顺序反过来也就是先gin.Recovery()再gin.Logger()。请求进入 Recovery 的c.Next()再去执行 Logger 的c.Next()最后进入 handler。如果 handler panicpanic 会沿着调用栈往外抛先碰到 Logger 的 defer recover但 Logger 并没有 recover 逻辑它只是 defer 打了日志之类的吗实际上gin.Logger并没有 recover。最初的 panic 会一路抛到 Recovery 的 defer recover 被捕获然后调用AbortWithStatus(500)整个中间件链的执行被中断。这时 Logger 中c.Next()之后的代码可能不会执行了导致请求日志丢失。而官方这种 Logger 在外、Recovery 在内的顺序panic 发生后会被内层 Recovery 捕获并恢复控制权正常返回外层 Logger 的c.Next()调用点Logger 的耗时统计和状态码记录就能正常执行。这就是为什么你看到gin.Default()在 handler panic 时也能打印一条 500 日志。所以不要随便调换这两个中间件的注册顺序尤其不能把 Recovery 放在 Logger 前面。3. 自定义中间件从复制粘贴到写出自己的套路3.1 最实用的自定义中间件请求 ID 追踪想做链路追踪第一步通常是给每个请求分配一个唯一 ID同时看前端的X-Request-ID没有就自动生成type contextKey string const traceIDKey contextKey trace_id func RequestIDMiddleware() gin.HandlerFunc { return func(c *gin.Context) { traceID : c.GetHeader(X-Request-ID) if traceID { traceID generateID() } c.Set(string(traceIDKey), traceID) c.Header(X-Request-ID, traceID) c.Next() } }这里有两个细节值得说。一是contextKey自定义类型而不是直接用字符串trace_id当 key。虽然 Go 里c.Set内部用的是 map[string]any从c.Get取出来时并不会有编译期错误但为了防止包之间 key 命名冲突统一用私有类型是更规范的做法。二是c.Set存在gin.Context内部后续在 handler 或同链路的其他中间件里用c.GetString(trace_id)就能拿出来。如果你想让 traceID 穿过整个调用链比如传到数据库层或者 Redis 客户端更稳妥的方式是放进c.Request.Context()而不是c.Setctx : context.WithValue(c.Request.Context(), traceIDKey, traceID) c.Request c.Request.WithContext(ctx)之后在 service 层只要用c.Request.Context()的派生 context 去调 GORM 和 go-redis就能把 traceID 完整贯穿。3.2 耗时统计中间件时间差要放在 c.Next() 前后日志里最常见的就是记录每个接口耗时。一个直接的写法是func CostMiddleware() gin.HandlerFunc { return func(c *gin.Context) { start : time.Now() c.Next() cost : time.Since(start) c.Set(cost, cost.String()) log.Printf([cost] %s %s %v, c.Request.Method, c.FullPath(), cost) } }这个中间件要能统计完整时间核心就在于start放在c.Next()之前而耗时计算放在c.Next()之后。如果只放在之前或只放在之后你拿不到整个链路的耗时。稍微进阶一点你还可以读取c.Writer.Status()拿到最终状态码配合耗时一起记录status : c.Writer.Status() log.Printf([cost] %d %s %s %v, status, c.Request.Method, c.Request.URL.Path, cost)需要提醒的是c.FullPath()在路由未匹配时可能为空比如 404 请求此时c.Request.URL.Path才是有意义的信息。这是我实际使用中发现的第一个小坑。3.3 认证中间件Abort 到底“中断”了什么认证中间件是自定义中间件里最常见的一类很多人的第一版代码长这样func AuthMiddleware() gin.HandlerFunc { return func(c *gin.Context) { token : c.GetHeader(Authorization) if token { c.AbortWithStatusJSON(http.StatusUnauthorized, gin.H{ code: 401, msg: 未登录, }) return } if !validateToken(token) { c.AbortWithStatusJSON(http.StatusUnauthorized, gin.H{ code: 401, msg: token 无效, }) return } c.Set(userID, getUserIDFromToken(token)) c.Next() } }关键在于c.AbortWithStatusJSON之后必须马上return。很多人不理解为什么因为Abort并不会真正终止整个函数栈它只是把c.index设置成一个很大的值让后续 handler 不再执行。但如果认证中间件后面还有逻辑代码没有 return这些代码依然会继续执行。另一个常见认知误区是Abort()不代表后续中间件的defer不会执行也不代表c.Next()之后的代码一定不会执行。如果你在一个中间件里调用c.Abort()后不 return而是继续往下走到函数末尾这个中间件的收尾代码还是会执行。所以口诀是要中断链路先Abort再return。3.4 捕获响应体的业务日志中间件内置 Logger 只能记录状态码想看响应体内容就得自己包一层gin.ResponseWriter。做法是写一个结构体实现Write和WriteHeader方法type bodyLogWriter struct { gin.ResponseWriter body *bytes.Buffer } func (w bodyLogWriter) Write(b []byte) (int, error) { w.body.Write(b) return w.ResponseWriter.Write(b) } func BodyLogMiddleware() gin.HandlerFunc { return func(c *gin.Context) { w : bodyLogWriter{ResponseWriter: c.Writer, body: bytes.Buffer{}} c.Writer w c.Next() log.Printf(trace_id%s status%d body%s, c.GetString(trace_id), c.Writer.Status(), w.body.String(), ) } }这个方案能解决问题但要注意几点Body 可能很大全量记录会对内存和日志造成压力写日志时最好截断比如只保留前 512 字节如果 handler 里流式输出大文件这种方式会破坏流式语义。所以这个中间件只适合测试或小型管理后台不适合高并发大响应接口。4. 中间件顺序、状态码与并发安全的细节4.1 注册顺序对执行链的影响前面已经多次提到顺序这里做一个系统总结。注册顺序就是 handler slice 的顺序c.Next()链条的执行规律是第一个中间件 before - 第二个中间件 before - handler - 第二个中间件 after - 第一个中间件 after放在前面的中间件更像“洋葱外层”。外层中间件能包裹内层中间件所以涉及全局兜底和前置拦截的尽量放前面依赖具体路由参数的放后面。几个实际建议Recovery()放最外层但不是理解那种最外层结合前面说的Logger 可以放在 Recovery 外面从 panic 日志角度Logger 是真正最外层。RequestID放比较靠前这样后续所有中间件都能c.Get(trace_id)。认证中间件放业务中间件前面避免未登录请求触达耗时统计或业务日志。限流中间件放认证之前或之后取决于你想给未认证请求也限流还是只限制已认证请求。4.2 状态码写入的时机问题Gin 的响应底层是http.ResponseWriter这个接口有个特性WriteHeader只能调用一次之后的Write不会改变状态码。很多中间件里想修改状态码却发现无效原因就是早前某个 handler 已经调用了c.String()或c.JSON()底层已经把 200 写出去了。举个例子func BadMiddleware() gin.HandlerFunc { return func(c *gin.Context) { c.String(200, 提前响应) c.Next() } }此时 handler 再c.JSON(500, ...)实际响应状态码仍然是 200用户看到的 body 可能还是第一个中间件的。所以中间件里要“预检”或“拦截”最好在c.Next()之前完成判断不要等到业务 handler 执行完再试图改状态码。4.3 c.Set 与并发安全Gin 的Context明确不建议在多个 goroutine 中共享。常见场景是你在 handler 里开一个 goroutine 去异步处理任务同时在 goroutine 里读c.Get(user_id)这其实是危险的因为请求结束之后 Context 可能被复用数据可能被污染甚至触发 panic。如果一定要在 goroutine 里使用请求上下文我建议只提取需要的基础类型值而不是持有整个*gin.ContextuserID : c.GetString(user_id) go func(userID string) { // 使用这个值做异步处理 }(userID)如果涉及c.Request的读取也要先复制一份请求副本。这里不做矫枉过正的禁止但底层逻辑要知道gin.Context是请求级别的对象默认设计就是串行使用的。4.4 性能小技巧不是中间件越多越好中间件本身只是函数调用开销通常不大但每个中间件都可能增加不必要的处理。我踩过两个问题一是日志中间件把整个请求体都读进内存导致大文件上传接口内存暴涨。解决方案是判断 Content-Type 和 Content-Length超过阈值就跳过 body 记录。二是自定义中间件里随手fmt.Sprintf拼日志在高并发下产生大量临时字符串内存分配压力很大。建议在业务量较低时无所谓到了高并发阶段尽量用log.Printf原生格式拼接减少额外 Sprintf 调用。5. 踩坑实录常见问题与排查思路5.1 panic 没有被 Recovery 捕获最经典的问题gin.Recovery()明明注册了为什么一个 panic 直接把服务打挂了原因基本都在 goroutine。比如func Handler(c *gin.Context) { go func() { var list []int _ list[10] // panic }() c.String(200, ok) }gin.Recovery所在的中间件链运行在主 goroutine 里它只能捕获取消链路上直接触发的 panic。上面这个 goroutine 里的 panic 会直接导致进程退出Recovery 无能为力。解决办法是在每个 goroutine 入口自己加 recover或者用一个统一封装的Go()函数func SafeGo(fn func()) { defer func() { if r : recover(); r ! nil { log.Printf(goroutine panic: %v, r) } }() go fn() }5.2 接口日志重复或丢失如果你既用了gin.Logger()又在业务 handler 里log.Printf可能会觉得日志“重复”如果你自定义了日志中间件但放在 Recovery 内层又可能在 panic 时缺失关键日志。这类问题的排查思路是先画出请求的中间件链顺序再用一个临时中间件打印所有经过的 handler 名称定位是哪一环出了问题。我习惯的做法是把请求日志拆成两层访问层只记录 method、path、status、latency由gin.Logger()或自研轻量中间件承担业务层日志由业务代码自己按需log.Printf不混在一起。这样就不会有“重复感”。5.3 中间件里改状态码不生效很多人会写一个响应包装中间件试图把业务 code 转换成 HTTP 状态码func ResponseMiddleware() gin.HandlerFunc { return func(c *gin.Context) { c.Next() if c.GetInt(biz_code) ! 0 { c.Status(http.StatusInternalServerError) } } }c.Next()之后业务 handler 通常已经调用了c.JSON响应状态码已经 written。此时再c.Status(500)并不会改变已发出的状态码。要想统一控制响应格式正确做法是不在中间件里等 handler 写完再改而是用一个包装 ResponseWriter 拦下写入时机或者约定 handler 只返回业务数据HTTP 状态码由中间件统一写。后者更符合实际项目里的“统一响应”需求但要求团队遵守规范。5.4 响应体捕获不全用自定义 ResponseWriter 捕获 body 时如果遇到流式响应或者 handler 多次调用Write捕获的 body 可能只有最后一次写入的部分或者顺序错乱。还有一个隐藏坑gin.ResponseWriter的WriteHeader可能在第一次Write时才被隐式调用如果你在包装器里太早访问Status()拿到的可能还是 200 默认值。遇到这类情况推荐把WriteHeader也包一层先记录再调用原始方法。随手整理一个排查表现象可能原因处理建议panic 整个服务退出goroutine 内 panic每个 goroutine 入口自行 recover请求日志缺失Logger 在 Recovery 内层调整顺序为 Logger 在外、Recovery 在内状态码修改无效响应已写出包装 ResponseWriter 或统一响应中间件traceID 取不到key 用字符串且拼写不一致统一包内 key 类型或从c.Request.Context()取值goroutine 里读c.Set的值不稳定跨 goroutine 使用 gin.Context提取基础类型值再传入 goroutine6. 结合实战项目的一点扩展想法6.1 把 traceID 贯穿到 GORM 和 Redis做 gin gorm go-redis 实战项目时中间件链最好的用途之一是链路追踪。在 RequestID 中间件里生成的 traceID除了放进c.Set还可以放入c.Request.Context()。之后 GORM 层用db.WithContext(ctx)Redis 层用client.WithContext(ctx)后端所有组件都围绕同一个 context 工作。这样一来日志平台里只需要按 traceID 搜索就能把一次 HTTP 请求从入口到数据库查询的完整链路拉出来。ctx : c.Request.Context() ctx context.WithValue(ctx, traceIDKey, traceID) c.Request c.Request.WithContext(ctx)注意从c.Request.Context()传给数据库的 context和c.Request一样不能脱离请求生命周期单独使用。要异步处理的任务应该复制 traceID 这类标量值。6.2 统一响应和业务错误码的设计很多项目里 HTTP 状态码和业务码是两回事。比如登录过期HTTP 返回 200但 body 里的code是 401前端靠 code 判断业务逻辑。这种模式下中间件特别适合做统一返回格式的兜底。但要注意的是不要试图在c.Next()之后统一改响应体因为响应一旦发出就很难收回。我自己更推荐的做法是定义业务错误类型handler 里直接返回错误由一个全局中间件集中写响应。6.3 什么时候不要写自定义中间件不是所有逻辑都适合塞进中间件。比如一个只服务于特定接口的参数预处理写在业务 handler 里反而更清晰一个只在一处使用的固定逻辑没必要抽象成中间件。中间件的定位是横切关注点多个接口共用、且希望与业务逻辑解耦的那部分内容才值得放到中间件链里。把中间件当万能工具最后会得到一个“魔法”太多、调试困难的接口层。我个人在 Day03 里最大的体会是中间件链的难点根本不是语法而是对执行时机的感觉。当你把c.Next()前后代码的顺序理清楚很多“玄学”问题就自动消失了。刚开始不熟的时候多打几条日志观察执行顺序比反复查文档有效得多。这也是我在那个实战项目里调到后面最受益的一点。
返回列表