Files
zt-closet-backend/docs/日志专项评估报告-2026-09-15.md
2026-09-16 00:23:49 +08:00

135 lines
19 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# 日志专项评估报告(2026-09-15)
> **审计对象**:zt-closet-backend 后端服务**代码中的日志打点**(`log/slog`),及日志基础设施(写出通道、级别、trace 注入、脱敏)。
> **审计方式**:静态代码审计——全仓检索 + 逐文件逐条核对(共 **160 条 slog 语句 / 23 个文件**)+ 关键结论二次抽查。未运行服务、未连接数据库。
> **行号基准**:当前工作区代码(工作区存在未提交改动,历史报告行号不可复用)。
> **交付性质**:评估建议稿;所列问题已于 2026-09-15 按「纯日志改进(零控制流变更)」边界全量修复完成,逐项状态见第四章(✅ = 已修复)。
---
## 一、总体结论
**不存在系统性"没日志",但覆盖严重不均衡,且存在若干被静默吞掉的资金/安全相关失败。**
1. **资损防线的 Error 级打点较扎实**:普通支付/虚拟支付的金额校验、发货五类校验、退款金额校验、补偿超限告警、鉴权 Redis 降级等均有日志(见"值得保留的良好实践")。
2. **三类结构性空白**:
- HTTP 入口层与鉴权中间件:`internal/routers/` 15 个文件 **0 条日志**;鉴权中间件 8 类拒绝分支 **全部无日志**;
- 成功侧审计:下单/支付/退款/发放/回收**成功路径均无日志**,日志无法用于对账与业务量统计;
- `pkg/` 第三方客户端:wechat/cos/matting/classification 等 **0 条日志**,失败仅向上抛。
3. **最高风险是"失败被静默吞掉"**:幂等锁错误与锁竞争不可区分(Redis 故障时回调被当作"已处理"应答成功,权益漏发)、支付信息落库失败被 `_ =` 吞掉、XPay 退款 settle 返回值丢弃、过期补发全静默、额度事务失败静默等,共 **10 项高风险**(见第四章 H1–H10)。
4. **日志质量**:全仓 76% 打点使用 Context 版本(service 层 89%);**未发现** openid/手机号/token/密钥/回调报文数值泄漏;msg 与字段命名风格整体一致;主要质量问题为 trace 断链、缺实体 ID、少量级别不当、后台任务无运行心跳。
---
## 二、审计范围与方法
- **对象**:全仓 Go 代码(排除 `thirdparty/` Python 服务),共 160 条 `slog` 语句、23 个含日志的文件。
- **对照基准**:README 的 7 条业务主线、6 个后台任务、历史审查报告标注的资损敏感路径(支付/退款回调、发货校验、权益发放回收、额度扣减回退、鉴权降级)。
- **评估维度**:①覆盖度(遗漏);②级别合理性;③字段完整性;④敏感信息;⑤trace 关联;⑥规范一致性;⑦基础设施配置。
- **局限**:未运行服务,运行期行为(文件轮转、OTel 采样与导出、告警链路)仅在代码层评估;`storage/logs/app.log` 实际产出内容未纳入本次范围。
---
## 三、日志基础设施现状
| 项 | 现状 |
| --- | --- |
| 输出通道 | lumberjack 滚动文件(`storage/logs/app.log`,压缩、按大小/份数/天数)+ stdout;JSON 格式;`AddSource: true`(每条带 source 文件:行号) |
| trace 注入 | `tracing.OtelContextHandler` 仅在 **`slog.XxxContext(ctx,…)` 且 ctx 内存在有效 span** 时注入 trace_id/span_id;OTel Logs 桥接分支(`otelslog`)**不携带** trace_id/span_id(record 克隆后各自处理) |
| 日志级别 | 配置 `Log.LogLevel` **大小写敏感**精确匹配 Debug/Warn/Error,其余值静默回落 Info;当前配置 Info;全仓 **0 条 Debug** 打点 |
| 请求日志 | 每请求 1 条 Info(`GIN_REQUEST`):request_id/method/path/query/status/ip/latency/user_agent;query 中 token/code/secret/password/access_token/refresh_token/key 共 7 类参数脱敏;**不记录**请求体/响应体;状态码任意均 Info,不按 4xx/5xx 升级;panic 请求不落日志(`gin.Recovery` 位于更外层,输出 stderr 且非 JSON) |
| 敏感信息 | 未见 openid/手机号/token/session_key/密钥/回调报文数值落入日志;支付回调原始报文仅入库 `callback_raw` |
| 打点分布 | `internal/service` 127(18 文件)、`pkg/tokenhub/scheduler.go` 16、`main.go` 13、`internal/middleware` 3、`internal/redismodel/keys.go` 1;**0 打点**:`internal/routers/`(15 文件)、`internal/mysqldao/`(19)、`internal/redisdao/`(12)、`pkg/` 除 tokenhub/tracing 外全部包 |
| 级别分布 | Error 80 / Warn 51 / Info 29 / Debug 0(全仓 160 条) |
---
## 四、问题清单
分级原则:**资损/安全相关遗漏 = 高**;排查困难/可观测性缺口 = 中;规范一致 = 低。
**修复状态(2026-09-15)**:本清单全部 23 项及第五章矩阵点名的具体静默点已按「纯日志改进」边界完成修复——仅新增/调整日志与级别、补齐实体字段与 Context 版本、增加任务心跳与 Debug 能力、改进日志配置健壮性;控制流、返回值与幂等语义零变化。报告中涉及控制流调整的建议(如 H5「失败应答微信重试」)未采纳,已裁剪为「仅记录日志」。验证:`gofmt` / `go vet` / `go build` / `go test` 通过,全部修复点经全仓检索逐项核验。以下编号加 ✅ 表示已修复。
### 高(资损/安全,建议优先处理)
| # | 位置 | 问题 | 影响与建议 |
| --- | --- | --- | --- |
| **H1** ✅ | `internal/service/order.go:123-129`、`:354-357`;`internal/routers/api/v1/order.go:133-137`、`:142-143` | 支付/退款回调的**验签失败、解密失败、非 SUCCESS 状态**无任何应用日志,service 失败仅回微信 FAIL 应答 | 伪造回调、平台密钥/证书配置错误、微信重试风暴均不可见(仅访问日志 status=500 + span)。建议 Error 级补记 `out_trade_no/out_refund_no` + 失败阶段,验签失败附来源 IP |
| **H2** ✅ | `internal/routers/api/v1/order.go:180`、`:187-192`、`:152-173`、`:211-214` | XPay(虚拟支付)回调入口:读体失败、安全模式验签/解密失败、`XPayVerify` 验签失败均无日志;回包加密失败静默降级明文 | 虚拟支付通道的伪造回调尝试与密钥错误不可发现。建议 Error 级记录事件类型与失败原因;加密降级明文应 Warn |
| **H3** ✅ | `internal/service/order.go:134-136`、`:361-363`;`internal/service/virtualpay.go:244-246`、`:337-339`;`internal/service/virtualpay_compensate.go:82-85`;`internal/service/benefit_compensation.go:43-46` | 幂等 `TryLock` 错误与正常锁竞争**合并静默忽略**(部分为 `_` 丢弃) | Redis 故障时回调/补偿被当作"并发已处理"直接应答成功,**权益漏发且无任何日志痕迹**。建议 `lerr != nil` 记 Error,正常竞争记 Debug |
| **H4** ✅ | `internal/service/order.go:461-465`;`internal/service/virtualpay.go:426-430` | 支付成功后的支付信息更新(`pay_time`/`transaction_id`/`callback_raw`)返回值被 `_ =` 吞掉 | 对账所依赖的交易号与回调报文缺失而无告警。建议 Error 级补记 order_no + error |
| **H5** ✅ | `internal/service/virtualpay.go:370`;`internal/service/order.go:394-396` | XPay 退款推送 `settleRefundSuccess` 返回值未接收;普通退款回调 settle 失败无日志 | 退款已到账但订单终态流转/回收任务创建失败时完全无日志。建议接收返回值并 Error 记录,失败应答微信重试 |
| **H6** ✅ | `internal/service/order.go:196-206` | 已过期订单补发货分支:流转 DB 错误、条件竞争 `!ok`、成功补发**全部静默** | "用户付了钱、订单过期又补发"的关键资损场景无审计线索。建议成功 Info(order_no)、DB 错误 Error、竞争 Debug |
| **H7** ✅ | `internal/service/order.go:95-97`、`:99-102`;`internal/service/virtualpay.go:26-63`、`:92-106` | 下单链路失败静默:订单落库失败、JSAPI 下单失败(订单保留)、虚拟支付未开通/环境/商品/金额/session_key/落库/签名失败 | 遗留待支付单与微信侧下单失败无可追溯线索。建议 Error 级补记 order_no/user_id/goods_code;业务性拒绝(商品下架)可 Info/Warn |
| **H8** ✅ | `internal/middleware/lzcwyjwt.go:30-34`(缺失)、`:36-41`(格式)、`:44-56`(无效/过期/类型)、`:59-65`(会话失效)、`:71-75`(UID 不匹配)、`:84-89`(DB 回落失败)、`:95-99`(状态拒绝);`internal/service/user.go:343` | 鉴权 **8 类拒绝分支全部无日志**(响应层可区分,日志层 0 条);UID 不匹配(疑伪造/重放)无留痕;刷新令牌时旧 token 吊销失败 `_ =` 丢弃;另 `lzcwyjwt.go:52` 把底层解析错误回给客户端而服务端无日志(信息投放错位) | 无法统计鉴权失败、定位被攻击账号、排查封禁争议。建议统一 Warn(UID 不匹配/吊销失败 Error),字段 method/path/ip/user_id/reason |
| **H9** ✅ | `internal/service/benefit_compensation.go:129-134`、`:61`、`:73`、`:144-146`、`:157`;`internal/service/order.go:723-734`、`:786`、`:789` | 权益回收链路静默点:回收任务查询失败、恢复僵死任务错误与条数被丢弃、Claim 失败、成功写失败均无日志 | 退款已到账但权益未回收的"资金-权益不一致"无法从日志发现。建议 Error 级补记 order_no/retry_count,成功回收补 Info 审计 |
| **H10** ✅ | `internal/service/service.go:350-355`、`:103-109`、`:141-144`、`:155-157`;`internal/service/clothes.go:466-490` | 额度事务失败静默:Cos 消费事务失败(非额度不足)、VIP 读取失败当非会员处理、有效额度/免费已用查询失败、删除衣物回退额度失败(仅返回 50005) | 用户"白扣/少退"无从核查。建议按性质补 Warn/Error,携带 user_id/related_id/quota_type |
### 中(排查困难/可观测性缺口)
| # | 位置 | 问题 | 建议 |
| --- | --- | --- | --- |
| **M1** ✅ | `internal/service/order.go:104-115`、`:171-174`、`:341-346`、`:380-389`;`internal/service/user.go`(登录成功) | **成功侧审计日志整体缺失**:下单/支付/退款/发放/回收/登录成功均无 Info | 补 Info 审计日志(order_no/user_id/amount/channel),支撑对账与业务量统计 |
| **M2** ✅ | `internal/service/user.go:117`、`clothes.go:159`、`clothes.go:275`、`airecommend.go:270`、`outfit.go:289`、`closet.go:102`、`service.go:461` | 关键日志缺业务实体 ID:user_id/clothes_uuid(重试告警仅有 name)/task_id/outfit_uuid/share_uuid/related_id | 补齐对应实体 ID,重试类日志带 clothes_uuid 或 task_id |
| **M3** ✅ | `pkg/tokenhub/scheduler.go:115`;`internal/service/virtualpay_compensate.go:142`;`internal/service/airecommend.go:417`;`internal/redismodel/keys.go:39`;`internal/service/service.go:375`、`:434`;`user.go:541`;`clothes.go:320` | **trace 断链**:全仓 38/160 条非 Context 版本(scheduler 启动/panic 类属可接受);重点改进点如左列——已有 ctx 却用裸调用、worker panic 可用外层 ctx、显式 `context.Background()`、recovery 路径无 span | 上述重点位置改 `XxxContext(ctx,…)`;OTel Logs 桥接分支不携带 trace_id 属基础设施限制,如需可在 fanout 层统一注入 |
| **M4** ✅ | `internal/service/quota_expire.go:80`、`ai_outfit_cleanup.go:77`、`order_expire.go:44`、`clothes.go:597-620`、`virtualpay_compensate.go:155` | 后台任务**无运行心跳**:仅"有产出"时打汇总(total/count/confirmed>0),无事发生则无声;衣物恢复调度每轮无记录 | 每轮 Info/Debug 汇总(scanned/affected/failed/耗时),供存活巡检与积压趋势观察 |
| **M5** ✅ | `internal/service/order.go:438`、`:741`、`:525`;`notification.go:170`;`airecommend.go:213`;`pkg/tokenhub/scheduler.go:115`;`virtualpay_compensate.go:167` | **级别不当/不一致**:待人工审核资损事件仅 Info(438);回收链路主查询失败仅 Warn(741);cooldown skip 用 Warn 可能刷屏(525);通知未读计数(缓存 best-effort)用 Error 高于同函数通知创建失败的 Warn(170);快照保存失败(best-effort)用 Error(213);Redis 故障与锁竞争合并记为 Info"already in progress"(`scheduler.go:115`,当天运势可能缺失且无告警);错误分支 Warn 且 openid 为空时 `error` 字段输出 nil(`virtualpay_compensate.go:167`) | 按左列逐条调整级别与字段;scheduler 建议拆分 `lerr!=nil → Error` / `!ok → Info` |
| **M6** ✅ | `internal/middleware/logger.go:44-53`;`internal/routers/router.go`(Recovery 注册) | 访问日志恒 Info,4xx/5xx 不升级;panic 请求无访问日志且 `gin.Recovery` 输出 stderr 非 JSON;`user_agent` 未截断 | 按状态码升级级别;定制 Recovery 输出走 slog;user_agent 截断 |
| **M7** ✅ | `pkg/wechat/`(pay.go、virtualpay.go、mini.go 等)、`pkg/cos/`、`pkg/matting/`、`pkg/classification/`、`pkg/upload/` | 第三方客户端 **0 条日志**:验签/解密/退款/查单、COS 读写、模型调用失败仅向上抛(部分仅 span.RecordError) | 高价值失败点(验签/解密、模型重试终失败)下沉日志或确保调用方补记;`upload` 已有 span 约定可保持 |
| **M8** ✅ | `internal/routers/api/v1/*.go`(15 文件)、`internal/mysqldao/`(19)、`internal/redisdao/`(12) | DAO/handler 层 0 条 slog,错误仅靠 span + 响应码;JSON 日志文件中无错误率/错误类型分布 | 维持"错误由上层记录"的分工,但上层须落实 H/M1;关键降级路径(Redis 读回退等)可补 Debug |
### 低(规范一致性)
| # | 位置 | 问题 | 建议 |
| --- | --- | --- | --- |
| **L1** ✅ | `main.go:266-276` | `Log.LogLevel` 大小写敏感,误配 `debug`/`info` 等将**静默**回落 Info | 忽略大小写匹配,或未匹配时启动告警 |
| **L2** ✅ | `main.go:250-294` | `AddSource: true` 全量开启有 CPU/日志体积成本;lumberjack 未配 `LocalTime`(轮转文件名按 UTC);`Log` 段缺失时在 init panic(fail-fast 合理,保持) | 可考虑仅 Warn 以上开启 AddSource;按需配置 LocalTime |
| **L3** ✅ | `virtualpay.go:380`、`benefit_compensation.go:154`、`virtualpay.go:139`、`:151`、`order.go:565`、`:567` | msg 质量问题:DB 故障记成 "order not found"(380,误导排障);同一 msg 覆盖两种失败场景(154);包装与内层重复记 Error(139/151);发放失败缺 retry_count/amount | 拆分/明确 msg,去除重复日志,补重试进度字段 |
| **L4** ✅ | `user.go:117` vs `:124`;`notification.go:165` vs `:170`;`clothes.go:320` | 一致性瑕疵:同类日志是否带 user_id 不一致;best-effort 缓存失败级别不一致;置态失败与额度回退失败合并一条且缺 phase(无法判断是否白扣额度) | 统一字段与级别规范;`clothes.go:320` 补 phase 字段 |
| **L5** ✅ | 全仓 | **0 条 Debug 打点**,与"排障期临时提高详单"的能力矛盾(改代码才能加日志) | 为高频排查点(轮询、降级、批量任务细节)补 Debug 级日志,生产用 LogLevel 控制 |
---
## 五、关键路径日志覆盖度矩阵
> 现状标注:✅ 覆盖较好;◐ 部分覆盖;✗ 基本空白。缺口详情见第四章对应编号。
| 业务线/模块 | 关键路径 | 现状 | 主要缺口 |
| --- | --- | --- | --- |
| 1 注册与额度 | 登录 → 注册 → 免费额度 → 体验会员 | ◐ | H8(code2session/注册失败无日志)、`user.go:343`、封禁拒绝、额度初始化失败(部分有 Warn) |
| 2 衣物生命周期 | 上传校验 → 扣额 → 异步流水线 → 失败回退 → 删除回退 | ◐ | H10(删除回退)、上传校验三分支静默、扣额/建记录失败、恢复调度认领与心跳(M4) |
| 3 穿搭与社区 | 创建/更新/删除 → 公开 → 点赞/收藏 | ◐ | 创建/明细事务失败、公开扣额回退失败、点赞/收藏 Redis 双写静默(`like.go:60`、`collect.go:71`) |
| 4 衣柜分享 | 创建 → 详情(懒过期/接收) → 取消 | ◐ | 扣额/明细落库失败、懒过期更新、访问统计静默、取消无日志 |
| 5 交易与权益 | 下单 → 支付回调 → 发放 → 退款 → 回收 → 补偿 | ◐(防线较全,**静默点最多**) | H1–H7、H9、H10;成功侧审计缺失(M1) |
| 6 AI 推荐 | 提交 → 后台生成 → 轮询 → 保存 → 清理 | ◐ | 提交三失败点(`airecommend.go:68-103`)、衣物列表/落库失败(`:254-306`)、运势降级(`:364-386`)、清理无心跳 |
| 7 通知 | 创建 → 未读 → 已读 | ◐ | 标记已读失败(`notification.go:95-97`)、DB+Redis 双失败静默(`:124-131`)、级别不一致(M5) |
| 后台任务(6 个) | 定时调度循环 | ◐ | M4 无运行心跳;资损相关失败(补偿超限、回收失败)已有 Error |
| 鉴权 | JWT 全链路 | ✗ | H8 全部 8 类拒绝分支;仅 Redis 降级 2 处 Warn(缺 user_id/ip) |
| 基础设施 | 请求访问日志 / 日志写出 | ◐ | M6(级别不升级、panic 不落日志);L1/L2 配置健壮性 |
---
## 六、改进优先级建议
| 优先级 | 内容 | 说明 |
| --- | --- | --- |
| **P0(立即)** | 第四章高风险 **H1–H10**(10 项) | 重点消除"静默吞错":锁错误分离、`_ =` 返回值收口、回调验签失败与鉴权拒绝补日志。这些是资损/安全的最后一道人工可查防线 |
| **P1(随迭代)** | 中优先级 **M1–M8** | 补成功侧审计与实体 ID、修复 trace 断链、后台任务心跳、级别调整、pkg 高价值失败点下沉 |
| **P2(规范)** | 低优先级 **L1–L5** | 配置健壮性、msg/字段规范、Debug 级日志能力建设 |
**值得保留的良好实践**(后续改动请勿回退):
- 资损防线 Error 打点齐全:支付/退款/发货金额校验、环境校验、防伪反查、补偿超限告警均带订单号;
- 支付链路字段命名统一(`order_no`/`out_trade_no`/`*_amount`),可检索可对账;
- service 层 Context 版本使用率 89%,主流程 trace 关联良好;
- 敏感信息 **0 泄漏**(openid 相关分支只打订单号;回调报文仅入库);query 脱敏覆盖 7 类参数;
- DAO 层统一 `span.RecordError` 约定,trace 侧可完整回溯错误。
---
## 附:数据口径
- slog 语句统计:`internal/service` 127 条(18 个文件有打点,`adreward.go`、`goods.go`、`horoscope.go`、`constants.go` 及测试文件 0 条);`pkg/tokenhub/scheduler.go` 16;`main.go` 13;`internal/middleware`(`lzcwyjwt.go` 2、`logger.go` 1);`internal/redismodel/keys.go` 1。合计 160 条。
- 未使用 Context 版本:全仓 38 条,其中 30 条为进程启停 / 调度器启动与 panic 兜底类(本身无请求 span,影响有限);其余 8 条为运行期路径,其中 `pkg/tokenhub/scheduler.go:115`、`internal/service/virtualpay_compensate.go:142`、`internal/service/airecommend.go:417`、`internal/redismodel/keys.go:39` 等为建议改进点(详见 M3)。
- 本报告全部行号以 2026-09-15 当前工作区文件为准;引用敏感字段时仅出现字段名,不含任何真实值。