日志不是给人看的，是给查询用的

有一次线上问题，我们四个人对着一份 2GB 的日志文件看了二十分钟，最后是靠 grep 一个用户 ID 才找到那几行。事后我意识到一个挺别扭的事实：日志写的时候是给人看的，用的时候却是给机器查的。这两件事从一开始就没对上。

那天的问题本身不复杂：某个用户下单失败，但错误日志里只有一句「订单创建失败」。谁失败了、哪一步、参数是什么、上游返回了什么，全都没有。于是只能靠时间窗口去猜，把前后几秒所有日志拉出来人肉拼上下文。

一句「失败」能有多少种含义

改造前，代码大致长这样：

try {
    orderService.create(req);
} catch (Exception e) {
    log.error("订单创建失败: " + e.getMessage());
}

这句话在任何一次故障里都会出现，但它回答不了排查时真正要问的问题：

• 是哪一个请求失败了？用户、订单号、幂等键是什么？
• 失败在哪一步？参数校验、库存扣减、还是支付调用？
• 是偶发还是全量？同一分钟内同类错误有多少条？
• 是我们的问题还是下游的？下游的状态码和耗时在哪？

于是每一次排查都要重新去代码里找上下文，再回到日志里对时间。日志明明打了，却没省下任何时间。

先改的不是格式，是「一条日志该带什么」

我们定了一条很朴素的规矩：任何一条 ERROR 日志，必须能单独回答「谁、做什么、卡在哪、上游怎么说」。不要求读起来像句子，要求字段齐全。

log.error("order.create.failed userId={} orderId={} step={} upstream={} costMs={} err={}",
          req.getUserId(), req.getOrderId(), "reserve-stock",
          stockResp == null ? "null" : stockResp.getCode(),
          System.currentTimeMillis() - t0, e.toString());

后来换成结构化输出，字段直接变成可检索的键：

{"ts":"2026-11-08T14:22:31.408+08:00","level":"ERROR","event":"order.create.failed",
 "traceId":"4bf92f3577b34da6a3ce929d0e0e4736","userId":"u_88213","orderId":"SO-20261108-7731",
 "step":"reserve-stock","upstream":"STOCK_503","costMs":3021,"service":"order-api","host":"pod-7"}

变化不只是「从文本变成 JSON」。真正有用的是现在可以直接问平台：

event:order.create.failed AND step:reserve-stock | count by upstream, 1m

一句话就能看出是某个下游在 14:22 集中返回 503，还是各步骤都在报错。从"读日志"变成"查日志"，排查方式才真的变了。

traceId 是性价比最高的一项

如果只能改一件事，我会选 traceId。

没有它的时候，一个请求跨三个服务，你得靠时间戳和用户 ID 把三份日志对齐，遇到同一用户并发请求就彻底乱了。有了它，入口生成一次，通过 HTTP header / MQ 消息一路透传，每个服务打印时都带上，任何一条日志都能反查整条链路。

// 入口过滤器：没有就生成，有就沿用
String traceId = Optional.ofNullable(request.getHeader("X-Trace-Id"))
        .filter(StringUtils::hasText).orElseGet(() -> UUID.randomUUID().toString().replace("-", "").substring(0, 16));
MDC.put("traceId", traceId);
try { chain.doFilter(req, resp); } finally { MDC.clear(); }

有两个坑我们踩过：异步线程里 MDC 会丢（要手动把上下文传给线程池，或用 TTL 包装）；调用外部服务时别忘了把 header 写进请求，否则链路在边界处断掉，比没有还让人困惑。

级别不是「严重程度」，是「谁该被叫醒」

以前团队把 ERROR 当成「比较重要的信息」，结果告警一响就是几百条，大家学会了忽略。后来重新约定：

| 级别 | 含义 | 是否告警 |

|---|---|---|

| ERROR | 请求失败且需要人工介入 | 是 |

| WARN | 系统自己兜住了（重试成功、降级生效） | 只看趋势 |

| INFO | 关键业务节点，一次请求最多 2~3 条 | 否 |

| DEBUG | 排查期临时打开 | 否 |

关键是 WARN 不告警。重试第一次失败、缓存未命中走 DB、限流触发降级，这些系统已经处理好了，写 WARN 供事后分析趋势即可。真正需要半夜叫人的是「用户操作失败且没有自动恢复」。

改完之后告警量掉了九成，剩下的每一条都值得看。

别把日志当垃圾桶

还有几件小事，看着琐碎，出事时特别要命：

别打整对象。 log.info("req={}", req) 在参数里带了手机号、证件号、token，日志一采集就等于把敏感数据复制到了另一个系统，权限还更松。要么白名单字段，要么在序列化层统一脱敏。

别在循环里打 INFO。 一次批量任务打十万条，真正有用的那一条被淹了，存储账单还涨一截。批量场景打开始和汇总，异常单独打。

异常别只打 message。 e.toString() 丢了堆栈，log.error("{}", e) 又可能只打出一行类名。用 log.error("event=xxx ...", e) 把异常对象作为最后一个参数交给框架，堆栈才会完整。

时间带时区和毫秒。 跨服务对齐时，14:22:31 和 14:22:31.408+08:00 的差别，就是「大概那几秒」和「就是这条」的差别。

消息用稳定的事件名。 order.create.failed 这种标识符比中文句子好聚合，也方便后来做告警规则。中文描述可以放在单独的 msg 字段里，不参与检索。

检验标准其实很简单

改完之后我们有个自测办法：随便挑一条最近的错误日志，只看这一条，不打开代码、不翻相邻行，问自己四个问题——谁的请求、哪一步、上游返回什么、能不能按这个条件统计出同类有多少条。

四个都答得上来，这套日志就算能用了。答不上来，就还只是把 System.out 换了个更漂亮的壳。

日志写在代码里，但读者从来不是写代码的那个人，而是某个凌晨两点盯着屏幕、只想尽快缩小范围的陌生人。替那个人多写几个字段，成本很低，回报在他最需要的时候。