结构化日志
这一课你将能做到
- 按 DEBUG / INFO / WARN / ERROR 为真实场景选对级别，解释为什么不能把「用户密码错误」打 ERROR
- 为 Spring Boot 配置 JSON 结构化日志，统一字段：
timestamp、level、service、traceId、message 及业务键
- 用
traceId 把日志、链路和告警串成一条可追踪的排障路径，写出从告警到日志再到 Trace 的跳转步骤
为什么要学
生产排障最常见的绝望是：日志很多，但搜不到「同一次请求」的上下文。你打开终端，tail -n 5000 一片散文，grep exception 结果几百条，但你不知道哪条是那个用户的。更糟的是，跨服务的日志没有共同标识，只能拿时间戳硬猜——并发稍微一上来就全乱。
结构化日志把一行事件变成可检索的字段集合（常见 JSON），让每一条日志都能独立回答：什么时间、哪个服务、哪次请求、发生了什么。它和指标、链路是铁三角：指标说「有事了」，日志说「这次出了什么事」，链路说「这次请求走了哪条路」。三者靠 traceId 关联，缺一不可。
先建立图像
| 级别 | 何时用（人话） | 反例（典型的级别滥用） |
|---|
| ERROR | 需要人介入或应触发告警的失败 | 把「用户密码错误」当 ERROR（这是预期内的业务拒绝） |
| WARN | 可恢复异常、降级、重试耗尽前兆 | 每次正常重试都打 WARN（制造噪音） |
| INFO | 关键业务里程碑（判题提交成功、结果返回） | 循环内每个元素都打 INFO（日志量爆炸） |
| DEBUG | 本地排障细节（SQL 语句、参数对象） | 生产默认全开 DEBUG（磁盘和 IOPS 全吃掉） |
排障跳转图：
告警（Metrics）发现 5xx 率升高
│
▼
用时间窗 + service 过滤 ERROR 级别的日志
│
▼
从 ERROR 行取出 traceId
│
├─► 日志系统：搜同 traceId 的全部日志上下文
└─► 追踪系统：打开整棵 Span 树，看慢在哪一跳
跟着做
步骤 1：为一次判题失败设计结构化事件
假设判题 worker 执行判题时抛出异常，正确的结构化事件应该是：
{
"timestamp": "2026-10-07T21:12:34.567+08:00",
"level": "ERROR",
"service": "coderoadmap-judge-worker",
"traceId": "4bf92f3577b34da6a3ce929d0e0e4736",
"spanId": "00f067aa0ba902b7",
"message": "judge execution failed",
"submissionId": 12345,
"language": "java",
"problemId": 42,
"error": "java.lang.RuntimeException: sandbox timeout",
"durationMs": 15500
}
注意：所有字段低基数可过滤；traceId 和 spanId 让跨系统关联成为可能；error 只保留类型和关键信息，不塞整个栈——全栈可以另外用 stackTrace 字段存，但要控制长度。
步骤 2：在 Spring Boot + Logback 里配 JSON 输出
依赖（pom.xml）：
<dependency>
<groupId>net.logstash.logback</groupId>
<artifactId>logstash-logback-encoder</artifactId>
<version>7.4</version>
</dependency>
logback-spring.xml（放到 src/main/resources）：
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="net.logstash.logback.encoder.LogstashEncoder">
<includeMdcKeyName>traceId</includeMdcKeyName>
<includeMdcKeyName>spanId</includeMdcKeyName>
<includeMdcKeyName>submissionId</includeMdcKeyName>
</encoder>
</appender>
<root level="INFO">
<appender-ref ref="CONSOLE"/>
</root>
</configuration>
步骤 3：让 traceId 自动注入 MDC
业务代码不自己管理 traceId，由 OTel/Brave 过滤器自动注入 MDC。确认你的 Spring Boot 已接入 OTel Java Agent（或 Spring Cloud Sleuth），启动后在日志里就能看到 traceId 字段自动出现。
@Slf4j
@Service
public class JudgeWorker {
public void judge(Submission submission) {
// 不要把整个 DTO toString 塞进 message，消息要短
log.info("judge started submissionId={} language={}",
submission.getId(),
submission.getLanguage());
try {
doJudge(submission);
} catch (Exception e) {
// ERROR 级别 + 业务字段 + 异常类名
log.error("judge failed submissionId={} problemId={}",
submission.getId(),
submission.getProblemId(),
e);
throw e;
}
}
}
启动后看控制台，应得到类似步骤 1 的 JSON 行。检查点：有 traceId、level、service、message 四个字段吗？
步骤 4：列出三条绝对禁止落盘的内容
- 访问令牌 / JWT：即使用户传了，也不能完整写入日志（可用脱敏或只取前几位）
- 密码 / API 密钥 / 数据库连接串：任何凭证类信息一律禁止
- 身份证号、手机号、完整邮箱：按团队合规要求脱敏或哈希
步骤 5：演练「指标 → 日志 → 链路」完整跳转
假设告警：POST /api/judge/submissions 5xx 率升高。写下你的操作顺序：
- 打开 Grafana RED 面板，确认 5xx 率升高的时间点和受影响的 URI
- 在日志系统（Loki/ELK）查询：
{service="coderoadmap-backend"} | json | level="ERROR" | http_path="/api/judge/submissions"
限制在时间窗口内
- 复制一条日志里的
traceId，打开追踪 UI（Jaeger/Tempo）搜索整棵 Span 树
步骤 6：用 LogQL 过滤日志（可选，有 Loki 时）
{app="coderoadmap-backend"} |= "ERROR" | json | traceId="4bf92f3577b34da6a3ce929d0e0e4736"
这是 Loki 查询语法，直接按字段过滤——这就是结构化日志的威力。
讲清楚要点
- 人要靠检索排障，所以日志必须结构化——纯文本「看起来像人话」但机器难聚合，grep 几个关键词就能崩溃。
- ERROR 常接告警，所以级别滥用会导致告警疲劳——预期内的业务拒绝（用户密码错误、资源不足拒绝判题）用 INFO/WARN；真正的系统异常才打 ERROR。
- 跨服务要用同一条故事线，所以必须注入
traceId/spanId——没有它们，日志就是无数个无法关联的孤岛。
- 日志成本按量计费且影响性能，所以生产默认级别要克制——INFO 是底线；DEBUG 只能临时开启或采样。一条包含超大 JSON 的 DEBUG 日志压垮集群不是都市传说。
- postmortem 复盘需要时间线，所以关键失败和决策要用稳定字段——方便事后按
submissionId、problemId 聚合并做时间线分析。
- 容器环境常采 stdout，所以应用打到标准输出由采集层收走——别写本地文件，让 K8s DaemonSet 或日志代理统一收集。
- message 是给人扫的，字段是给机器滤的——不要把所有信息塞进一句长 message。消息要短到能「扫一眼知道发生了什么」，字段负责精确过滤。
你可能会懵的地方
-
404 到底打 INFO 还是 WARN？
偶发用户输错 URL → INFO 或 WARN 团队统一即可。如果 404 暴增像爬虫扫描，可升 WARN 并用指标发现，不必每条都 ERROR。
-
栈跟踪要不要每条 ERROR 都打全文？
要，但要注意去重和采样。同一个异常刷屏时，可只保留第一条完整栈，后续只记「同类异常第 N 次」。切勿在 INFO 级别打完整栈。
-
结构化后还要不要人类可读的 message？
要。字段负责过滤和聚合；短 message 负责「扫一眼知道发生了什么」。两者都要有，不是非此即彼。
-
日志和指标重复了怎么办？
不冲突：指标计数「发生了多少次」；日志保留「这一次发生了什么」。错误率告警靠指标触发，根因分析靠日志取证。两者是配合关系。
-
为什么 traceId 不是 Logger 自动生成的？
日志框架本身不知道「请求边界」。HTTP 请求到达时，网关或 OTel agent 生成 traceId 并放入 MDC；后续所有日志自动带上。离开当前线程（如 @Async）可能丢失，需要显式传递。
错法对照
| 错法 | 问题 | 正解 |
|---|
System.out.println("error " + e) | 无法检索、无法级别过滤、无 traceId | 用 SLF4J 结构化 logger + 级别 + 字段 |
| 密码/Token 写入日志「方便排查」 | 安全事件、合规风险 | 脱敏、只打哈希、或按合规策略处理 |
无 traceId 的跨服务日志 | 无法关联同一次请求 | OTel/Brave 注入 MDC，全链路一致 |
| 生产长期 DEBUG | 磁盘满、CPU 高、日志系统拖垮 | 默认 INFO，动态临时开启 DEBUG |
| 把每次循环、每次健康检查打 INFO | 日志量爆炸、检索困难 | 里程碑才 INFO；心跳靠指标 |
卡点急救
- 日志没有 traceId：先确认是否开启了 OTel Java Agent 或 Sleuth；再看
logback-spring.xml 是否正确引用了 LogstashEncoder 并配置了 includeMdcKeyName。MDC 里的 key 名必须是 traceId（或对应 agent 使用的 key 名）。
- JSON 日志格式错乱或中文乱码：检查
logback-spring.xml 里是否遗漏 <charset>UTF-8</charset>；终端和日志采集侧都要确认编码是 UTF-8。
- 日志量太大导致采集侧丢失：先看是不是误开了 DEBUG；如果是正常 INFO 量也太大，考虑按服务拆分索引、加采样、或把高频低价值日志降到 DEBUG。
面试常问
-
为什么结构化日志比纯文本日志好？
结构化日志以键值对（JSON）组织，可被日志系统按字段索引、过滤、聚合。纯文本只能 grep，无法做 traceId=xxx 的精确查询，也无法在 Grafana/Loki 里按字段画图表。跨服务关联时，结构化 + traceId 能做到一键跳转。
-
日志级别怎么分？ERROR 什么时候用？
ERROR = 需要人介入的系统失败（数据库连不上、Kafka 发送失败、判题沙箱崩溃）。用户密码错误、参数校验失败、资源不足拒绝服务 → INFO/WARN。滥用 ERROR 导致告警疲劳，真正的问题反而被淹没。
-
生产日志有哪些安全红线？
凭证（密码、Token、API key）绝对禁止；PII（手机号、身份证号）按团队合规脱敏；内部调试密钥、数据库连接串不能出现在任何级别的日志中。脱敏策略要写入 code review 检查项。
自测三问
- 为什么说「一条日志应能独立读懂」？举一个反例。
- 从告警到日志再到 Trace，
traceId 扮演什么角色？如果缺失会怎样？
- 列出三个绝对不该落盘的字段类型，并说明为什么不能出现在日志里。
小结一句话
结构化 + 克制级别 + traceId = 日志从「翻文件」变成「可检索、可关联、可告警的信号」。
延伸