做后台管理系统有一个功能很容易被忽略操作日志。刚开始做项目的时候很多人觉得日志很简单log.Println(用户删除成功)但真正上生产以后老板突然问你昨天下午 3 点是谁把这个用户删了或者谁修改了管理员角色的权限甚至为什么某个订单状态突然变了这个时候普通程序日志基本没什么用。你真正需要的是一套谁 在什么时间 从哪个 IP 调用了什么接口 操作了什么模块 执行了什么动作 成功还是失败 耗时多久也就是操作审计日志我最近在整理 ShiyuAdminhttps://github.com/Rodert/ShiyuAdmin里面专门通过 Gin Middleware 做了一套操作日志。今天就从这个功能往下拆。一、程序日志和操作日志不是一回事很多项目会把这两种日志混在一起。比如logger.Info(delete user success,userCode,userCode,)这是程序日志。主要给开发人员排查问题。例如数据库连接失败 Redis 超时 请求耗时 SQL 执行失败 panic但是操作日志解决的是另一件事谁干了什么比如操作人zhangsan 模块system-user 动作delete 请求 DELETE /api/v1/system/users/U10001 IP 192.168.1.12 结果 success 耗时 38ms这两个日志的目标完全不同。所以后台系统最好分开Application Log 程序运行日志 Operation Log 用户操作审计日志二、最简单的做法Controller 里写日志很多项目一开始会这么做。删除用户funcDeleteUser(c*gin.Context){userCode:c.Param(code)err:userService.Delete(c,userCode,)iferr!nil{operationLogService.Create(c,OperationLog{Action:delete,Status:0,},)return}operationLogService.Create(c,OperationLog{Action:delete,Status:1,},)}看起来可以。但是当系统有100 个接口你就得写100 次操作日志代码新增用户CreateOperationLog(...)修改用户CreateOperationLog(...)删除角色CreateOperationLog(...)修改菜单CreateOperationLog(...)最后 Controller 到处都是logService.Create(...)这明显属于重复代码。而这些请求其实有一个共同点它们全部经过 Gin Router所以最合适的地方其实是Middleware三、用 Gin Middleware 统一拦截写操作首先我们并不需要记录所有请求。例如GET /users如果每访问一次列表都写数据库刷新一下页面 ↓ 一条操作日志 再次刷新 ↓ 又一条操作日志很快日志表就会爆炸。一般重点审计POST PUT PATCH DELETE也就是新增 修改 删除判断很简单funcisWriteMethod(methodstring)bool{switchmethod{casehttp.MethodPost,http.MethodPut,http.MethodPatch,http.MethodDelete:returntruedefault:returnfalse}}然后写一个 Gin MiddlewarefuncOperationLogger(logSvc OperationLogService,)gin.HandlerFunc{returnfunc(c*gin.Context){if!isWriteMethod(c.Request.Method,){c.Next()return}// 记录开始时间start:time.Now()// 继续执行后面的业务c.Next()// Handler 执行结束后再记录saveOperationLog(c,logSvc,start,)}}这里一个非常关键的地方是c.Next()必须先执行。为什么因为操作日志需要知道最终 HTTP 状态码 最终是否成功 接口实际耗时 Handler 有没有报错这些东西只有业务代码执行完之后才知道。四、为什么日志要在c.Next()后面处理假设请求DELETE /api/v1/system/users/U10001开始start:time.Now()然后c.Next()请求进入权限 Middleware ↓ Handler ↓ Service ↓ Repository ↓ MySQL全部执行完成以后回来。这时候latency:time.Since(start).Milliseconds()就能得到38ms同时statusCode:c.Writer.Status()可以知道结果200还是400 403 404 500于是操作日志就可以自动判断成功失败。例如status:1ifstatusCode400{status0}这比每个 Controller 手动写successtrue靠谱很多。五、从 JWT 里拿到操作人操作日志最重要的一项当然是谁操作的前面的 Auth Middleware 已经解析过 JWT。可以把用户信息放进gin.Context例如c.Set(currentUser,claims,)Operation Middleware 再读取claimsValue,exists:c.Get(currentUser)然后claims,ok:claimsValue.(*Claims)获取userCode:claims.UserCode username:claims.Username于是整个链路变成HTTP Request ↓ JWT Middleware ↓ 解析 Token ↓ 把 Claims 放入 Gin Context ↓ Permission Middleware ↓ Handler ↓ OperationLogger ↓ 获取当前操作用户这样业务 Handler 完全不需要关心日志。六、操作日志表应该存什么一个比较实用的结构typeOperationLogstruct{IDint64UserCodestringUsernamestringModulestringActionstringMethodstringPathstringIPstringStatusintErrorMsgstringLatencyMsint64CreatedAt time.Time}分别看一下。UserCode业务用户唯一标识U10001Username用户名zhangsan这里其实可以冗余一份。因为未来用户改名 用户被删除你仍然希望历史日志能够显示当时是谁执行的审计日志适当做冗余数据其实很正常。Module模块system-user system-role system-menu system-deptAction操作create update deleteMethodHTTP MethodPOST PUT PATCH DELETEPath例如/api/v1/system/users/:codeIP操作来源192.168.1.10公网系统可能是103.xxx.xxx.xxxStatus例如1 成功 0 失败ErrorMsg错误摘要权限不足 用户不存在 参数校验失败建议限制长度。例如iflen(errorMsg)500{errorMsgerrorMsg[:500]}否则一条异常堆栈可能几 KB。长期下来日志表会非常大。LatencyMs例如38ms这个字段非常有用。因为操作日志除了做审计还可以顺手发现某个后台接口越来越慢七、Module 和 Action 可以自动推导如果每个接口都手动写Module:system-userAction:delete还是有很多重复代码。实际上可以从HTTP Method Path自动计算。例如DELETE /api/v1/system/users/U10001MethodDELETE对应deletePath/api/v1/system/users/:code解析第一层业务资源users得到system-users例如funcderiveAction(methodstring,)string{switchmethod{casehttp.MethodPost:returncreatecasehttp.MethodPut,http.MethodPatch:returnupdatecasehttp.MethodDelete:returndelete}returnother}路径funcderiveModule(pathstring)string{constprefix/api/v1/system/if!strings.HasPrefix(path,prefix,){return}rest:strings.TrimPrefix(path,prefix,)parts:strings.Split(rest,/,)iflen(parts)0{return}returnsystem-parts[0]}最后DELETE /api/v1/system/users/:code自动得到Module system-users Action delete这样新增接口时几乎不用额外处理日志。八、真正的大坑不要同步写操作日志很多人的实现到这里就结束了c.Next()logService.Create(c,logEntry,)但是这里会有一个问题。数据库写日志需要5ms 10ms 20ms那么用户每一次修改操作都会额外增加数据库 INSERT 时间本来业务接口35ms加入日志35ms 15ms变成50ms更糟糕的是日志数据库慢了结果业务接口也跟着变慢这就非常不合理。因为对于绝大多数后台用户业务优先级应该高于审计日志实时落库所以更合理的方案是异步写日志九、最简单的异步方式goroutine可以直接gofunc(){_logService.Create(ctx,logEntry,)}()主线程业务执行完成 ↓ 启动 goroutine ↓ 立即返回用户后台goroutine ↓ INSERT operation_log看起来非常完美。但这样又产生了第二个问题。十、千万不要无限创建 goroutine假设正常100 QPS问题不大。但是突然来了5000 QPS而数据库又突然变慢。每一个请求gosaveLog()可能不断产生goroutine goroutine goroutine goroutine goroutine ...如果数据库迟迟处理不完goroutine 数量持续上涨最终内存上涨 调度压力上涨 数据库连接池打满严重时甚至可能日志系统把主业务拖死所以异步不是简单一句gofunc()就结束了。必须做并发限制十一、ShiyuAdmin 用 channel 做并发槽位这是一个很适合 Go 的实现。定义varoperationLogWorkersmake(chanstruct{},256)什么意思最多允许256个日志任务同时执行。写日志前select{caseoperationLogWorkers-struct{}{}:gosaveLog()default:// 放弃本次异步日志}goroutine 完成以后deferfunc(){-operationLogWorkers}()整个模型就像停车场。一共256 个停车位正常情况请求 ↓ 占一个位置 ↓ 写日志 ↓ 释放位置如果 256 个位置全部占满新日志任务 ↓ 没有位置 ↓ 直接丢弃关键是不能阻塞业务请求十二、为什么宁可丢日志也不阻塞业务这个设计其实值得讨论。假设日志 DB 已经挂了如果坚持日志必须写成功请求会不断等待。最终日志系统故障 ↓ 整个后台业务不可用显然不合理。所以一般需要明确优先级核心业务请求 普通操作审计日志当系统已经过载保护主请求优先级更高。这就是一种非常常见的Backpressure思想。系统承载不了的时候不要无限接任务而应该限流 拒绝 降级 丢弃当然如果你的行业是金融 支付 证券 医疗 强审计系统操作日志可能不能丢。这时就不应该用简单 goroutine。而应该上Kafka RabbitMQ RocketMQ Pulsar这样的消息系统。十三、还有一个非常隐蔽的问题Request Context很多人会这么写gofunc(){logService.Create(c.Request.Context(),logEntry,)}()看起来没问题。但 HTTP 请求结束以后Request Context通常也会被取消。于是异步 goroutine 可能刚开始INSERT请求已经返回。ContextCanceled数据库操作可能直接收到context canceled这就是异步任务特别容易踩的坑。十四、context.WithoutCancel是个很有意思的处理ShiyuAdmin 当前做法是ctx:context.WithoutCancel(c.Request.Context(),)然后再异步gofunc(ctx context.Context,entry*OperationLog,){_logSvc.Create(ctx,entry,)}(ctx,logEntry)这样做的核心目的继承原 Request Context 中的 Value但不要因为 HTTP 请求结束 就取消日志写入这点非常重要。否则主请求返回成功日志却可能context canceled一条都没写进去。十五、但 WithoutCancel 以后也要注意超时这里还能继续优化。去掉 Request Cancel 以后异步日志请求可能没有合理截止时间如果数据库一直卡着goroutine可能长时间不退出。所以更稳一点的做法是baseCtx:context.WithoutCancel(c.Request.Context(),)ctx,cancel:context.WithTimeout(baseCtx,3*time.Second,)defercancel()完整gofunc(base context.Context,entry*OperationLog,){deferfunc(){-operationLogWorkers}()ctx,cancel:context.WithTimeout(base,3*time.Second,)defercancel()_logSvc.Create(ctx,entry,)}(baseCtx,logEntry)这样就变成不跟随 HTTP Request 取消 但是 最多允许日志写 3 秒通常更加合理。十六、再加一个 TraceID日志价值会高很多ShiyuAdmin 本身已经有 Trace Middleware。请求进来以后检查 X-Trace-Id如果客户端没有自动生成 TraceID类似743bc812d93d4d64b4cf8056319d01c5然后放进Context同时返回响应头X-Trace-Id: 743bc812d93d4d64b4cf8056319d01c5这样一次请求里的日志全部可以关联起来。例如trace_id abc123你可能看到HTTP Request trace_idabc123然后permission check trace_idabc123然后database error trace_idabc123最终operation log trace_idabc123这时候排查问题非常方便。十七、OperationLog 也应该增加 TraceID当前可以进一步把实体升级成typeOperationLogstruct{IDint64TraceIDstringUserCodestringUsernamestringModulestringActionstringMethodstringPathstringIPstringStatusintErrorMsgstringLatencyMsint64CreatedAt time.Time}数据库字段trace_idVARCHAR(64)加索引CREATEINDEXidx_operation_log_trace_idONsys_operation_logs(trace_id);生成日志traceID,_:c.Get(trace_id)然后logEntry:OperationLog{TraceID:fmt.Sprint(traceID),UserCode:userCode,Username:username,Module:module,Action:action,Method:method,Path:path,IP:c.ClientIP(),Status:status,LatencyMs:latency,}以后看到某条删除记录失败直接SELECT*FROMsys_operation_logsWHEREtrace_id?;再去应用日志搜索相同trace_id整条请求链路就串起来了。十八、请求日志还要特别注意密码泄露还有一个非常值得提醒的问题。很多 Request Logger 会记录request_body例如登录{username:admin,password:123456}如果直接写日志password123456这就是严重安全问题。不只是密码。还有token access_token refresh_token secret api_key authorization 银行卡 身份证 手机号都可能属于敏感信息。所以日志系统最好增加Sensitive Field Mask例如varsensitiveKeysmap[string]struct{}{password:{},token:{},access_token:{},refresh_token:{},secret:{},api_key:{},}递归脱敏funcmaskSensitive(value any,){data,ok:value.(map[string]any)if!ok{return}forkey,value:rangedata{lower:strings.ToLower(key)if_,exists:sensitiveKeys[lower];exists{data[key]******continue}maskSensitive(value)}}日志最后应该是{username:admin,password:******}而不是保存明文密码。十九、为什么请求 Body 要限制长度还有一种场景。用户提交100 KB JSON甚至5 MB 文本如果完整写日志一次请求就几 MB日志磁盘很快就会爆。所以一般会设置constmaxBodyLogLength2048超过2 KB直接截断。例如iflen(body)maxBodyLogLength{bodybody[:maxBodyLogLength]...}操作日志里的ErrorMsg也一样。可以控制500 字符核心原则日志不是数据备份。不要想着把整个 Request 和 Response 原封不动塞进去。二十、操作日志表也会越来越大假设一天100 万次写操作一年3.65 亿条日志如果全部塞一张sys_operation_logs查询会越来越痛苦。所以真实大系统还要继续考虑日志归档 分区表 冷热分离 ES / OpenSearch ClickHouse 对象存储比如 MySQL 按时间分区PARTITIONBYRANGE(TO_DAYS(created_at));也可以最近 30 天 ↓ MySQL 历史日志 ↓ ClickHouse / S3普通后台当然没必要一开始就做这么复杂。但表设计最好至少给user_code created_at module status这些高频查询字段建立合适索引。二十一、如果日志绝对不能丢该怎么办前面说channel 满了 ↓ 丢掉日志这是为了保护主业务。但如果需求是所有管理员操作必须审计就不能这么干。可以升级HTTP Request ↓ Operation Middleware ↓ 发送 Kafka ↓ 立即返回消费者Kafka Consumer ↓ 批量写数据库变成Gin ↓ Kafka ↓ Consumer ↓ ClickHouse / MySQL这样主请求不需要等待数据库同时消息也不会轻易丢失还可以批量 INSERTINSERTINTOoperation_logsVALUES(...),(...),(...),(...);吞吐量会高很多。二十二、普通后台没必要一开始就 Kafka但也不要一看到异步就上 Kafka。如果后台每天只有几千 几万 几十万次操作。其实Gin Middleware goroutine channel 并发限制 MySQL完全够用。架构选择一定要看规模。可以这样演进第一阶段 同步 INSERT发现慢了第二阶段 goroutine 异步担心 goroutine 爆炸第三阶段 channel 并发限制要求日志可靠第四阶段 Kafka日志量特别大第五阶段 Kafka ClickHouse这才是比较正常的工程演进。二十三、最终完整链路一条管理员请求DELETE /api/v1/system/users/U10001完整链路可以设计成HTTP Request ↓ Trace Middleware ↓ 生成 TraceID ↓ Request Logger ↓ JWT Middleware ↓ 解析当前用户 ↓ Permission Middleware ↓ 检查删除权限 ↓ Operation Logger ↓ 记录开始时间 ↓ Handler ↓ Service ↓ Repository ↓ MySQL ↓ 返回结果 ↓ Operation Logger ↓ 获取 用户 IP Method Path 状态 耗时 TraceID ↓ 尝试获取异步 Worker ↓ goroutine ↓ 写入 sys_operation_logs ↓ HTTP Response这样 Controller 里面甚至不需要知道操作日志存在业务代码仍然可以保持干净funcdeleteUser(c*gin.Context,userSvc UserService,){code:c.Param(code)iferr:userSvc.Delete(c,code,);err!nil{response.Error(c,500,err.Error(),)return}response.Success(c,gin.H{deleted:true,},)}日志全部由Middleware统一完成。最后后台操作日志真正做起来其实不只是INSERT INTO log里面至少包含几个值得学习的后端知识点Gin Middleware Context JWT TraceID 异步任务 goroutine channel 并发控制 Backpressure 日志脱敏 数据库设计 可观测性尤其有三个点我觉得特别值得记住。第一横切逻辑尽量放 Middleware不要让每一个 Controller 重复写日志。第二异步任务不能无限创建 goroutine必须考虑系统过载时怎么办。第三日志系统不能反过来拖垮主业务日志本质上是辅助系统。除非业务明确要求强审计否则它的故障不应该导致整个后台不可用。ShiyuAdminhttps://github.com/Rodert/ShiyuAdmin如果你正在学习 Go 后端这个模块其实很适合单独拆出来练一次。因为它看起来只是一个操作日志但往下挖会发现里面全是实际项目才会遇到的问题。