日志体系:SLF4J 门面与 Logback 配置实战

bee2026-10-0879 分钟0 次阅读
门面模式为什么重要、日志级别怎么用、Logback 配置文件怎么写、MDC traceId 如何贯穿链路——把日志从"随手 println"升级成可检索的工程能力。
1 / 174
小节
〇、30 秒看懂
2 / 174

System.out.println 也能输出,但它只会「往屏幕上打字」。真正的日志要同时做到五件事:能按级别关掉(生产不该刷 DEBUG)、能落到文件并自动滚动(磁盘不能被写满)、能带上上下文(这次请求是谁、traceId 多少)、能被机器检索(ELK 一行一条)、换实现不用改代码。这五项能力加起来才叫「日志体系」,而 Spring Boot 已经替你默认装好了整套。

3 / 174

先把六个词一句话解释(全文都会用到):

4 / 174
  • 门面(Facade):只定义「怎么调用」的接口层,不干活。org.slf4j.Logger 就是门面
  • 实现(Implementation):真正判级别、拼格式、写磁盘的那个库,比如 Logback、Log4j2
  • 绑定(Binding):把门面和实现接起来的那根线,物理上就是 classpath 里那个 logback-classic.jar
  • 桥接包(Bridge):把某个老实现的输出偷偷引到门面上,例:jul-to-slf4j
  • Appender:日志的「出口」——控制台、文件、异步队列各是一个 Appender
  • MDC:绑在线程上的一个临时小本子,往里写的 key-value 会自动出现在每条日志里
5 / 174
类比

日志门面就是出国用的电源转换头。你的电脑(业务代码)插头形状永远不变,到日本换个孔位、到英国换个方脚——设备没变,只是换了个转换头。直接 import org.apache.log4j.Logger 等于把电脑电源线剪断、焊死在英标插座上:搬家(换日志实现)那天,你只能把整屋线路重铺一遍。

6 / 174
架构图
图 · 一条日志的流水线:从 log.info 到磁盘过了几双手
图 · 一条日志的流水线:从 log.info 到磁盘过了几双手
7 / 174

学完这一篇,你应该能回答三个问题:

8 / 174
  • 为什么我加了 log.debug(...) 却什么都不打印?(两个最常见的答案,不是你以为的那两个)
  • logback.xml 和 logback-spring.xml 差一个字,差了多少功能?
  • 一次请求跨了五个服务、写了二十行日志,我怎么用十秒钟把它们串起来?
9 / 174
小节
一、日志门面:业务代码为什么不能直接依赖 Logback
10 / 174

先看一个真实的翻车现场。某项目早期图省事,每个类都直接 import org.apache.log4j.Logger,把日志写死在实现上。后来 Log4j 爆出安全漏洞,全公司要求升级到 Log4j2,别的地方改一行依赖版本就完事,这个项目却要改几十个类、重跑全部测试——因为日志调用散落在每个文件里,跟具体实现耦合死了。

11 / 174

问题的根源是把「你要什么」和「谁能给你」绑在了一起。日志体系里有两类角色:

12 / 174
  • 门面(Facade):只定义接口,比如 Logger.info(...)。业务代码只认它。
  • 实现(Implementation):决定日志最终写到哪、格式如何。比如 Logback、Log4j2、JDK 自带的 JUL。
13 / 174

中间还可能夹着桥接包(Bridge):把某个老实现的输出重定向到门面,让新旧日志走到同一条流水线上。

14 / 174
对照表
角色代表交给它什么职责
门面 APISLF4J、JCL业务只依赖它,调用形态永远不变
日志实现Logback、Log4j2、JUL真正决定级别判定、格式化、落盘
桥接包jul-to-slf4j、log4j-over-slf4j把第三方库散落的日志收拢到同一条链路
15 / 174

历史演进大致是:JCL(2002)→ 各家实现混战 → SLF4J(2006)一统门面。JCL 的失败在于它采用「运行时动态查找实现」,classpath 一乱就出现 NoClassDefFoundError 之类的诡异问题;SLF4J 改成「编译期静态绑定」,classpath 里没有实现时只打印一条警告,不会再崩。这就是为什么今天所有现代框架——Spring、Hibernate、MyBatis——内部用的都是 SLF4J。

16 / 174
架构图
图 1 · 日志系统的分层
图 1 · 日志系统的分层
17 / 174

开头那个翻车现场,值得用一条动图钉死——左边是「把线焊死在插座上」的代价,右边是「只换一个转换头」的代价,同一次漏洞公告、两种结局:

18 / 174
原理动画
动图 · 换个插头 vs 重做整栋楼的电路
动图 · 换个插头 vs 重做整栋楼的电路
19 / 174
说明

Spring Boot 的默认组合是 SLF4J(门面)+ Logback(实现),由 spring-boot-starter-logging 自动带入——它其实转依赖了 spring-boot-starter 里的日志 starter。只要你用了 spring-boot-starter-web,这套组合就已经就位,什么都不用配。

20 / 174
小节
二、日志级别:五档门槛怎么用
21 / 174
原理动画
动图 · 一条日志的完整旅程
动图 · 一条日志的完整旅程
22 / 174

级别不是「重要性排序」,而是过滤门槛:logger 上设一个级别,只有不低于它的日志才会被放行。搞混这一点,就会出现「生产疯狂打 DEBUG 把磁盘写满」的事故。

23 / 174
对照表
级别判断标准(问自己一句)生产建议
ERROR已经影响到用户/业务,需要人介入必开,且应触发告警
WARN可恢复但值得关注,可能恶化必开,定期巡检
INFO关键业务事实:启动、开关、状态变更必开,但别刷屏
DEBUG排查问题时才需要的细节默认关,按包临时开
TRACE比 DEBUG 更细,几乎是逐帧生产几乎永不开
24 / 174
小节
2.1 级别如何生效:root 与 logger 继承
25 / 174

Logback 的级别配置是一棵树。root 是树根,每个包/类是一条分支,没有显式配置的 logger 会向上寻找最近的祖先级别。所以:

26 / 174
代码对照
代码yaml
logging:  level:    root: INFO                 # 兜底:所有未单独配置的走 INFO    com.example.order: DEBUG   # 只有订单包开 DEBUG
解读
  • com.example.order.OrderService 会命中 com.example.order 的 DEBUG
  • com.example.user.UserService 没有匹配的 logger,往上找到 root,按 INFO 处理
  • 一次 log.debug 调用在 root=INFO 时会被直接丢弃,连字符串格式化都不会发生

要点:级别放行发生在格式化之前,这是 SLF4J 性能模型的关键——被过滤的日志,代价几乎为零。这也解释了后面第三节那个常被搞错的 isDebugEnabled。

27 / 174

「谁离这个类最近,谁说了算」这套继承关系,用点的比用背的快。下面这张图从下往上一格一格点,重点是第 ③ 格和第 ⑤ 格:

28 / 174
交互图解
分层一条 log.debug 的级别是谁定的1 / 5
从 ① 点到 ⑤。第 ②③ 格解释「我只给一个包开了 DEBUG,为什么别的包也吵」,第 ⑤ 格解释「级别明明开了却什么都没打」
→
→
→
→
① 先按类的全限定名找 logger
Logback 给每个 logger 名字都留了一个槽:com.example.order.OrderService 先问「有没有人单独配过我」,没有就把名字按点拆开往上找。这一步是纯字符串匹配,没有任何猜测成分。
全部看懂了调级别先问「谁离这个类最近」;查不到日志先问「是不是第二道门拦的」。
29 / 174
小节
三、SLF4J 使用规范:把每一行都写对
30 / 174
小节
3.1 用 `{}` 占位符,不要字符串拼接
31 / 174
代码对照
代码java
// 反例:拼接在 log 之前就执行了,级别再低也白拼logger.debug("查询用户 id=" + userId + ", 名称=" + name + ", 耗时=" + cost + "ms");// 正例:只有级别放行时才真正做字符串替换logger.debug("查询用户 id={}, 名称={}, 耗时={}ms", userId, name, cost);
解读
  • 反例里 + 拼接是「调用参数」,会在 debug() 之前完成——哪怕生产把级别压到 INFO,这次拼接照样发生
  • 正例传入的是「格式 + 参数」,SLF4J 先判级别,被过滤时一个字符串都不会拼
  • 循环里打日志时,这个差异会被放大成千上万倍
32 / 174
小节
3.2 异常栈必须作为最后一个参数
33 / 174
代码对照
代码java
try {    orderService.create(order);} catch (Exception e) {    // 异常对象放最后,SLF4J 自动识别并打印完整堆栈    log.error("创建订单失败 orderId={}, userId={}", order.getId(), order.getUserId(), e);}
解读

坑:很多人写成 log.error("创建订单失败: " + e.getMessage())。这样堆栈被彻底丢掉,线上只剩一行干巴巴的消息,你永远不知道是空指针还是超时。更糟的是 e.printStackTrace()——它把堆栈打到了标准错误,绕过了日志框架,既没有时间戳也没有 traceId,ELK 里根本搜不到。

34 / 174
小节
3.3 `isDebugEnabled` 到底还需不需要
35 / 174

老代码里常见这种写法:

36 / 174
java
if (logger.isDebugEnabled()) {    logger.debug("state={}", expensiveToString(obj));}// 绝大多数情况下,这样写就够了logger.debug("state={}", obj);
37 / 174

结论很明确:绝大多数场景不需要 isDebugEnabled。

38 / 174
  • 参数只是普通变量或对象引用时,占位符方案已经帮你省掉了格式化,外层判断是纯粹的噪音
  • 只有当「构造日志参数」本身很贵时才值得包一层——比如要遍历大集合并序列化、要计算一个聚合值。上面第一个例子里 expensiveToString 即使日志被过滤也会执行,这时判断才有意义
  • 代价是代码变长、可读性下降。默认不写,遇到真实性能问题再加,别凭想象提前优化
39 / 174
小节
四、Spring Boot 日志配置三件套
40 / 174

不用改任何代码,application.yml 里三个开关就能覆盖 80% 的日常需求:

41 / 174
代码对照
代码yaml
logging:  level:                                   # ① 改级别:不改代码,按包精细控制    root: INFO    com.example: DEBUG    org.springframework.jdbc.core: DEBUG   # 想看 SQL 参数时打开    com.zaxxer.hikari: INFO                # 连接池日志别刷屏  file:    name: ./logs/bee.log                   # ② 同时输出到文件(控制台依然保留)  pattern:    console: "%d{HH:mm:ss.SSS} %-5level [%X{traceId}] %logger{36} - %msg%n"    file: "%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%X{traceId}] %logger{36} - %msg%n"
解读
  • logging.level:以包名为 key,值就是级别。改一行重启即生效,是最常用的开关
  • logging.file.name:指定后,日志同时在控制台和文件输出;logging.file.path 只指定目录,文件名固定叫 spring.log
  • logging.pattern:控制格式。%X{traceId} 就是为第七节的 MDC 预留的打印位

提示:logging.file.name 与 logging.file.path 只能二选一,两个都写时以 name 为准。生产上更推荐「只打控制台」交给容器或日志采集侧处理,理由见第八节。

42 / 174

这三行是「够用」的下限,实际项目里通常还要挂上 profile 和 Actuator。别抄别人的 yml——勾一遍,看它生成什么,尤其注意每一项后面那行注释为什么存在:

43 / 174
生成器
生成器日志三件套 + 让它能在线改的那一行application.yml2 / 4
只勾「日志」看最小三行(级别、文件、pattern);再叠「Profile」,对照 5.1 节里 <springProfile> 与 yml profile 两种切换方式的分工;最后勾「Actuator」——它生成的 management.endpoints.web.exposure.include 正是 4.1 节能在线改级别的那个端点,勾完务必想想它是不是暴露在公网
产物
server:
  port: 8080

spring:
  application:
    name: demo-service

logging:
  level:
    root: INFO
    com.example.demoservice: DEBUG
    org.springframework.jdbc.core.JdbcTemplate: DEBUG   # 打 SQL 与参数
  file:
    name: logs/app.log
  logback:
    rollingpolicy: { max-file-size: 50MB, max-history: 14 }

---
spring:
  config:
    activate:
      on-profile: prod
logging:
  level: { root: WARN }
---
spring:
  config:
    activate:
      on-profile: dev
spring:
  jpa:
    show-sql: true
勾了这些,代价与理由在这里
logging级别可按包精细控制;logging.level.root=DEBUG 会把三方库全打爆,别在生产这么干。
profiles + 分档配置多文档块用 --- 分隔,spring.config.activate.on-profile 指定生效条件。
44 / 174
坑

logging.file.name 与第五节那份 logback-spring.xml 是两套出口配置,会互相覆盖。写了完整 XML 又配 logging.file.name,Boot 会把它自己的 appender 关掉、只保留你 XML 里那套——于是「明明配了文件路径却找不到文件」。定一个事实源:要么三件套,要么 XML。

45 / 174
小节
4.1 不重启改级别:Actuator 动态调级
46 / 174

排查线上问题,最怕的是「改配置要重启」。Spring Boot 2.0+ 的 actuator 暴露了 loggers 端点,能在线热改级别:

47 / 174
代码对照
代码bash
# 只把订单包临时调到 DEBUG,其他包不受影响curl -X POST http://localhost:8080/actuator/loggers/com.example.order \  -H 'Content-Type: application/json' \  -d '{"configuredLevel":"DEBUG"}'# 查当前生效级别curl http://localhost:8080/actuator/loggers/com.example.order
解读
  • 支持 GET 查看、POST 修改,改完立即生效、无需重启
  • 记得把 management.endpoints.web.exposure.include 里加上 loggers(或用 *)
  • 用完务必改回去——这就是第十二节决策卡要讨论的事
48 / 174
小节
五、Logback 深度配置:logback-spring.xml
49 / 174

当需求超过三件套的表达能力——按级别分流、异步、按大小+时间双滚动——就该写完整的配置文件了。放在 src/main/resources/logback-spring.xml:

50 / 174
代码对照
代码xml
<?xml version="1.0" encoding="UTF-8"?><configuration scan="true" scanPeriod="60 seconds">    <!-- 1. 变量:日志目录与文件前缀,改一处即可全局生效 -->    <property name="LOG_HOME" value="./logs"/>    <property name="APP_NAME" value="bee"/>    <!-- 2. 控制台:开发时看的,带颜色高亮 -->    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">        <encoder>            <pattern>%d{HH:mm:ss.SSS} %highlight(%-5level) [%thread] %cyan(%logger{36}) - %msg%n</pattern>        </encoder>    </appender>    <!-- 3. 文件:按天 + 按大小双维度滚动,历史 gzip 压缩 -->    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">        <file>${LOG_HOME}/${APP_NAME}.log</file>        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">            <fileNamePattern>${LOG_HOME}/${APP_NAME}.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>            <maxFileSize>100MB</maxFileSize>            <maxHistory>30</maxHistory>            <totalSizeCap>5GB</totalSizeCap>        </rollingPolicy>        <encoder>            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] [%X{traceId}] %logger{36} - %msg%n</pattern>        </encoder>    </appender>    <!-- 4. 异步包装:业务线程只写队列,落盘交给后台线程 -->    <appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">        <queueSize>1024</queueSize>        <discardingThreshold>0</discardingThreshold>        <neverBlock>true</neverBlock>        <appender-ref ref="FILE"/>    </appender>    <!-- 5. 按级别分流:ERROR 单独一封,方便告警系统直接 tail -->    <appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">        <file>${LOG_HOME}/${APP_NAME}-error.log</file>        <filter class="ch.qos.logback.classic.filter.LevelFilter">            <level>ERROR</level>            <onMatch>ACCEPT</onMatch>            <onMismatch>DENY</onMismatch>        </filter>        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">            <fileNamePattern>${LOG_HOME}/${APP_NAME}-error.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>            <maxFileSize>50MB</maxFileSize>            <maxHistory>60</maxHistory>        </rollingPolicy>        <encoder><pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{traceId}] %msg%n</pattern></encoder>    </appender>    <!-- 6. 包级别:自己的业务包放开,第三方框架压到 WARN -->    <logger name="com.example" level="DEBUG"/>    <logger name="org.apache.ibatis" level="WARN"/>    <logger name="com.zaxxer.hikari" level="INFO"/>    <root level="INFO">        <appender-ref ref="CONSOLE"/>        <appender-ref ref="ASYNC_FILE"/>        <appender-ref ref="ERROR_FILE"/>    </root></configuration>
解读
  • <property>:定义可复用变量,${LOG_HOME} 在全文引用,迁移目录只改一行
  • ConsoleAppender:%highlight 只在支持 ANSI 的终端生效,写进文件时会自动变成纯文本
  • RollingFileAppender:滚动策略见第六节,%i 是同一天内多份文件的自增序号
  • AsyncAppender:把真实 appender 包一层异步,appender-ref 指向 FILE 即代表异步写文件
  • LevelFilter:onMatch=ACCEPT 放行 ERROR,onMismatch=DENY 拦掉其它级别,于是 ERROR_FILE 只收错误
  • root 上是「兜底级别 + 出口列表」;logger 上是更精细的覆盖,谁近谁生效

坑:文件名 logback-spring.xml 与 logback.xml 不是一回事。只有 logback-spring.xml 才支持 <springProfile>、<springProperty> 这些 Spring 扩展标签,也才能在配置里用 ${spring.application.name}。写成 logback.xml 会被 Logback 在 Spring 环境就绪前抢先加载,标签直接报错,profile 支持也没了。

51 / 174

上面那些 pattern 里的 % 记号是整份配置里唯一「写错了也不报错、只是不打字」的部分。来一局配对:左边是记号,右边点它真正打印什么——点错会当场告诉你代价:

52 / 174
配对闯关
闯关pattern 里每个 % 记号到底在做什么已配对 0/6 · 配错 0
六组都是硬映射。别靠位置猜——右边那一列里有一格是「性能陷阱」,找到它
先点左边一个
53 / 174
小节
5.1 用 profile 区分开发与生产
54 / 174

logback-spring.xml 的杀手锏是按环境切换:

55 / 174
xml
<springProfile name="dev">    <root level="DEBUG"><appender-ref ref="CONSOLE"/></root></springProfile><springProfile name="prod">    <root level="INFO">        <appender-ref ref="ASYNC_FILE"/>        <appender-ref ref="ERROR_FILE"/>    </root></springProfile>
56 / 174

开发环境要 DEBUG 和控制台高亮,生产环境要 INFO 和异步落盘——同一份文件,两种行为,这是 logback.xml 做不到的。

57 / 174
小节
六、滚动策略与磁盘账
58 / 174

日志文件不能无限长,必须滚动(rotate)。Logback 提供了三种滚动策略:

59 / 174
对照表
策略触发条件适用场景
TimeBasedRollingPolicy按时间(默认按天)只需按日归档
SizeAndTimeBasedRollingPolicy按时间 + 单文件大小大流量,一天可能写几百 MB
60 / 174

SizeAndTimeBasedFNATP(SizeAndTimeBasedFileNamingAndTriggeringPolicy)是「按大小 + 按时间」组合的核心组件,现在通常直接用 SizeAndTimeBasedRollingPolicy 简写形式:

61 / 174
代码对照
代码xml
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">    <fileNamePattern>./logs/bee.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>    <maxFileSize>100MB</maxFileSize>   <!-- 单文件超过 100MB 就滚,%i 递增 -->    <maxHistory>30</maxHistory>        <!-- 只保留最近 30 天 -->    <totalSizeCap>5GB</totalSizeCap>   <!-- 所有归档加起来不超过 5GB --></rollingPolicy>
解读
  • %d{yyyy-MM-dd} 按天命名,%i 是当天第几个分片(bee.2026-10-07.0.log.gz、.1.log.gz…)
  • maxFileSize 防止单文件过大——单文件过大的日志既难 tail 也难传输
  • maxHistory 控制时间维度的保留天数
  • totalSizeCap 是总磁盘上限,超过时从最旧的文件开始删;必须 ≥ maxHistory 的预期总量才有意义

说明:为什么需要 totalSizeCap?因为 maxHistory 只管「保留多少天」,管不了「一天写多少」。假如某天日志暴涨到 2GB,30 天就是 60GB——totalSizeCap=5GB 会兜住这个上限,把最老的归档删掉。生产环境这两个参数必须同时配,否则一次流量尖峰就能把磁盘写满。

62 / 174
小节
七、MDC 链路追踪:让 traceId 贯穿一次请求
63 / 174

微服务里最痛的问题是:一个请求打过 5 个服务、写了 20 行日志,出问题时怎么把它们串起来?答案是 MDC(Mapped Diagnostic Context)——一个绑定在线程上的 key-value 容器,日志 pattern 里用 %X{key} 就能引用。

64 / 174

第一步,用 Filter 在请求入口塞入 traceId:

65 / 174
代码对照
代码java
package com.example.web.filter;import jakarta.servlet.FilterChain;import jakarta.servlet.ServletException;import jakarta.servlet.http.HttpServletRequest;import jakarta.servlet.http.HttpServletResponse;import org.slf4j.MDC;import org.springframework.core.Ordered;import org.springframework.core.annotation.Order;import org.springframework.stereotype.Component;import org.springframework.web.filter.OncePerRequestFilter;import java.io.IOException;import java.util.UUID;@Component@Order(Ordered.HIGHEST_PRECEDENCE)public class TraceIdFilter extends OncePerRequestFilter {    public static final String TRACE_ID = "traceId";    @Override    protected void doFilterInternal(HttpServletRequest request,                                    HttpServletResponse response,                                    FilterChain chain) throws ServletException, IOException {        // 上游网关已透传就沿用,保证全链路同一个 ID        String traceId = request.getHeader("X-Trace-Id");        if (traceId == null || traceId.isBlank()) {            traceId = UUID.randomUUID().toString().replace("-", "").substring(0, 16);        }        MDC.put(TRACE_ID, traceId);        response.setHeader("X-Trace-Id", traceId);        try {            chain.doFilter(request, response);        } finally {            MDC.remove(TRACE_ID);   // 必须清理,否则线程复用会串味        }    }}
解读
  • Ordered.HIGHEST_PRECEDENCE:最先执行,确保后续所有日志都能带上 traceId
  • 优先读 X-Trace-Id:让网关或前端生成的 ID 一传到底,全链路可对齐
  • MDC.put 后,pattern 里的 %X{traceId} 就会自动渲染,业务代码一行都不用改
66 / 174

第二步,pattern 里引用它(也就是第四节配的 [%X{traceId}]),日志立刻变成这样:

67 / 174
text
2026-10-07 10:12:33.482 INFO  [http-nio-8080-exec-3] [9f2c1a7b3e5d8401] c.e.order.OrderService - 创建订单 orderId=10023
68 / 174

这两步一个在内核里能按出来。第一格「放与取」,看的就是上面那个 map:MDC 底层是 ThreadLocal<Map<String,String>>,put 写进当前线程自己那份,%X{} 读的也是当前线程那一份:

69 / 174
内核实验
TeaVMMDC 的放与取:谁写、谁读、存在哪未启动
点「放与取」,看清 put 落到哪张 map、%X{} 又从哪里读——这一步想通了,后面异步丢 traceId 就不是「意外」而是「必然」
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
70 / 174

第二格是那条 pattern:%X{traceId} 为什么有时候打印成 []?因为替换发生在 Encoder 那一格,读的是那一刻所在线程的 map,跟「这条业务从哪来」没有关系:

71 / 174
内核实验
TeaVM%X{traceId} 是在哪一格被替换的未启动
点「输出格式」,看 %thread、%-5level、%X{traceId} 各自的取值时机;把 MDC 留空跑一次,就得到那对空括号
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
72 / 174
小节
7.1 异步线程会丢 MDC
73 / 174

MDC 底层是 ThreadLocal,新开的线程拿不到父线程的 MDC。如果你的业务用了 @Async 或自定义线程池,日志里的 traceId 会变成空的。解法是给线程池装一个 TaskDecorator,在任务提交时把上下文复制过去:

74 / 174
代码对照
代码java
@EnableAsync@Configurationpublic class AsyncConfig implements AsyncConfigurer {    @Override    public Executor getAsyncExecutor() {        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();        executor.setCorePoolSize(8);        executor.setMaxPoolSize(16);        executor.setQueueCapacity(200);        executor.setThreadNamePrefix("async-");        executor.setTaskDecorator(new MdcTaskDecorator());  // 关键:传递 MDC        executor.initialize();        return executor;    }}class MdcTaskDecorator implements TaskDecorator {    @Override    public Runnable decorate(Runnable runnable) {        Map<String, String> context = MDC.getCopyOfContextMap();  // 提交线程快照        return () -> {            try {                if (context != null) MDC.setContextMap(context);  // 在子线程还原                runnable.run();            } finally {                MDC.clear();   // 归还线程前清空,避免污染下一个任务            }        };    }}
解读
  • getCopyOfContextMap() 在提交任务的线程上抓一份快照
  • setContextMap() 在执行任务的线程上还原
  • finally 里 MDC.clear():线程池的线程会被复用,不清就会把上一个请求的 traceId 带给下一个请求,排查问题时会被彻底带偏

警告:MDC 清理漏掉一次,故障现象极其隐蔽——两个不相关的请求共享同一个 traceId,你会以为是同一笔业务。凡是 MDC.put,必须有一个对应的 finally { MDC.remove(...) },这是铁律。

75 / 174

挂与不挂 TaskDecorator,差别全在这张对照图里。注意左边最后一格——串味比空白更难查,因为日志看起来一切正常:

76 / 174
架构图
图 · MDC 过线程:搬与不搬
图 · MDC 过线程:搬与不搬
77 / 174

代码抄得到,顺序抄不到。把这条链摊成一次单步执行,连点下一步,盯线程名从 http-nio-8080-exec-3 变成 async-2 的那一拍,以及第 ④ 拍那个「在谁的线程上抓快照」:

78 / 174
单步调试台
单步台跟着调试器走一遍:那对空括号是怎么打出来的1 / 7
七拍。第 ④ 拍决定快照抓不抓得到,第 ⑥ 拍决定 traceId 还在不在
被调试的代码
1MDC.put("traceId", "9f2c1a7b"); // TraceIdFilter,最先跑的一拍
2log.info("下单 userId={}", 7); // 这一行打得出 traceId
3notifier.sendAsync(order); // @Async:把活交给线程池
4Map<String,String> snap = MDC.getCopyOfContextMap(); // 在提交线程上抓快照
5executor.setTaskDecorator(new MdcTaskDecorator()); // 少这一行,后面全是空括号
6MDC.setContextMap(snap); task.run(); // 在 async-2 上回放,再执行
7log.info("短信已发 orderId={}", 10023); // 这行有没有 traceId,取决于第 ⑥ 拍
此刻的变量
线程http-nio-8080-exec-3
这条线程的 MDC{traceId=9f2c1a7b}
存储本质ThreadLocal<Map<String,String>>
调用栈
1TraceIdFilter.doFilterInternal
2MDC.put
1put 写的不是「全局的一张表」,而是这条 Tomcat 工作线程自己的 map。@Order(HIGHEST_PRECEDENCE) 保证它排在所有会打日志的组件之前——否则第一批日志仍然是空括号。
79 / 174

同一条链在内核里跑一遍,切「异步」那一档就能看见 traceId 在第 ⑤ 拍消失:

80 / 174
内核实验
TeaVM异步分支上,traceId 是怎么消失的未启动
先跑不带 decorator 的时间线,看空括号出现在哪一拍;再打开 TaskDecorator 重跑一遍,对比第 ⑥ 拍的 map 内容
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
81 / 174
小节
7.2 跨服务:traceId 要跟着出站请求走
82 / 174

搬到异步线程只解决了「一个进程内」。请求一旦打到下一个服务,MDC 是 ThreadLocal,天然过不去网络——它必须被塞进 HTTP 头,由对端的 Filter 再放回对端的 MDC。工业做法是 W3C 的 traceparent 头:

83 / 174
代码对照
代码java
@Componentpublic class TraceFeignInterceptor implements RequestInterceptor {    @Override    public void apply(RequestTemplate template) {        String traceId = MDC.get("traceId");        if (traceId != null) {            template.header("traceparent", "00-" + traceId + "-" + spanId() + "-01");        }    }}
解读
  • 出站:拦截器从当前线程的 MDC 取值写进 header,所以第 7.1 节那套搬运是前提
  • 入站:下游的 TraceIdFilter 优先复用 header 里的 ID,没有才自己生成——这就是第七节那段 request.getHeader("X-Trace-Id") 的用意
  • 两端格式要一致:traceparent 的字段顺序是 版本-traceId-spanId-flags,自己拼的字段名对不上,链路系统只会把它当两个孤立请求
84 / 174

下面这条动画走完「同一个 ID 怎么跨过两次网络跳」,注意第 ④ 帧那个空括号:

85 / 174
原理动画
动图 · 一个 traceId 的跨国旅行
动图 · 一个 traceId 的跨国旅行
86 / 174
内核实验
TeaVM跨服务传递:从 MDC 到 traceparent 再回到 MDC未启动
按顺序点:出站前 header 是空的 → 拦截器写入 → 下游 Filter 取出并 put 进它自己的 MDC → 下游日志的 traceId 与上游一致
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
87 / 174
说明

真正上线时不必手写这一套——micrometer-tracing-bridge-brave 加 spring-boot-starter-actuator 就能让 Spring Boot 3 自动生成 traceId、自动放进 MDC 键 traceId/spanId,并自动透传 traceparent。本节手写它,是因为只有手动走过一遍,才知道框架替你做完了哪几拍。

88 / 174
小节
八、JSON 结构化日志:为 ELK 铺路
89 / 174

前七节的日志对人友好,对机器不友好——ELK 采集时要写一堆正则才能提取字段。更工程化的做法是直接输出 JSON,一行一条,每条自带字段:

90 / 174
xml
<dependency>    <groupId>net.logstash.logback</groupId>    <artifactId>logstash-logback-encoder</artifactId>    <version>7.4</version></dependency>
91 / 174
xml
<appender name="JSON_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">    <file>${LOG_HOME}/${APP_NAME}-json.log</file>    <encoder class="net.logstash.logback.encoder.LogstashEncoder">        <includeMdcKeyName>traceId</includeMdcKeyName>   <!-- 把 MDC 里的 traceId 一并输出 -->    </encoder>    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">        <fileNamePattern>${LOG_HOME}/${APP_NAME}-json.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>        <maxFileSize>100MB</maxFileSize>        <maxHistory>15</maxHistory>    </rollingPolicy></appender>
92 / 174

输出就是一行标准 JSON:

93 / 174
代码对照
代码json
{"@timestamp":"2026-10-07T10:12:33.482Z","level":"ERROR","logger_name":"com.example.order.OrderService","thread_name":"http-nio-8080-exec-3","traceId":"9f2c1a7b3e5d8401","message":"创建订单失败 orderId=10023","stack_trace":"java.lang.RuntimeException: 库存不足..."}
解读
  • @timestamp、level、logger_name 等字段由 encoder 自动补全,无需手写
  • includeMdcKeyName 把 traceId 提成独立字段,ELK 里可以直接按它 filter
  • 生产建议:控制台仍用人类可读格式,文件用 JSON——人看终端,机器读文件
94 / 174
小节
九、日志规约十条
95 / 174
对照表
#规约为什么正确做法
1禁止 System.out.println绕过日志框架,没有级别和格式一律用 log.info(...)
2禁止 e.printStackTrace()打到 stderr,无时间戳无 traceIdlog.error("msg", e)
3异常必须打完整堆栈只有 message 等于没有线索异常对象作为最后一个参数
4禁止打印敏感信息密码/token/身份证会进日志平台脱敏后打,或只打 hash
5禁止在循环里打 INFO10 万次循环就是 10 万行日志汇总成一条:「处理 N 条,失败 M 条」
6用占位符,禁拼接拼接在级别判定前就执行了log.debug("id={}", id)
7日志要可检索无法定位的日志等于噪声带上业务主键:orderId、userId
8ERROR 要克制全打 ERROR 会让告警失效只有需人介入才 ERROR
9别用日志当流程控制靠日志判断逻辑是脆弱设计逻辑归逻辑,日志归日志
10路径与级别外部化硬编码无法适配环境交给 yml / 配置中心
96 / 174
要点

这十条里,第 1~3 条是红线——它们直接决定「出了问题能不能查」。其余是效率与规范问题,可以逐步治理,但红线一次都不能破。

97 / 174
小节
十、三个真实的坑
98 / 174
小节
10.1 异步日志为什么会丢
99 / 174

AsyncAppender 默认策略是:当队列快满(剩余 20%)时,主动丢弃 TRACE/DEBUG 级别的事件,这叫 discardingThreshold。如果你既配了 neverBlock=true(队列满时不阻塞业务线程),又把 queueSize 设得很小,流量尖峰时就会丢日志——而丢的往往正是你最需要的那些。

100 / 174
坑

异步日志丢日志的根本原因,是「不想让日志拖慢业务」和「一条都不能少」这两个目标天然冲突。要吞吐就把 queueSize 调大(如 4096)并接受极端情况下丢低级别;要零丢失就 neverBlock=false + discardingThreshold=0,代价是队列满时业务线程会被阻塞。没有两全,只有取舍。

101 / 174

这条取舍只有一个数字可以拖,拖一遍比读三遍管用。queueSize 从 64 拖到 8192,看丢的是谁、卡的是谁:

102 / 174
参数调节台
调节台异步队列有多长:丢日志,还是拖慢业务
logback AsyncAppender queueSize
512条日志事件当前 64 – 8192
常规区间:够吸收一次抖动
  • 512~1024 对多数服务正好:能吞下秒级的写盘抖动
  • 队列长度决定的是「能容忍多久的落盘延迟」,不是「会不会丢」
  • 这时候还丢,说明磁盘或下游采集端真的跟不上,调队列没用
  • 配套:includeCallerData 别打开,它会为每条事件抓调用栈
事件丢弃率12%
业务线程被阻塞6%
队列长度买的是「多久的落盘抖动」;要一条都不丢就得接受业务线程可能被阻塞——两个目标只能选一个。
103 / 174
小节
10.2 循环打印把磁盘写满
104 / 174

下面这段代码是事故常客:

105 / 174
java
// 反例:一次导入 5 万条数据,每条打一行 INFO,日志文件瞬间 500MB+for (Order order : orders) {    log.info("正在处理订单 {}", order.getId());    importService.handle(order);}
106 / 174

改成汇总:

107 / 174
代码对照
代码java
int failed = 0;for (Order order : orders) {    try { importService.handle(order); }    catch (Exception e) { failed++; log.warn("单条导入失败 orderId={}", order.getId(), e); }}log.info("批量导入完成 total={}, failed={}", orders.size(), failed);
解读
  • 单条成功不打日志,只打失败与汇总
  • 这样一次导入只产生「失败数 + 1 条」日志,量级从 5 万降到个位数
108 / 174
小节
10.3 打印大对象导致性能骤降
109 / 174

log.debug("resp={}", hugeResponse) 看起来无害,但如果 hugeResponse.toString() 要递归序列化几千个字段,每次调用都在做重活。更糟的是有人习惯在 toString 里拼全量数据,一次日志能吃掉几十毫秒。

110 / 174
警告

日志对象优先打「主键 + 关键字段」,不要图省事直接 log.debug("obj={}", obj) 打整个聚合根。真要看全量,也应该放进 if (log.isTraceEnabled()) 里,并且用专门的序列化手段,而不是靠 toString。

111 / 174
小节
十一、交互演示:日志该挂在哪一个回调上
112 / 174

日志和 Bean 生命周期其实有个天然的连接点:如果要在「对象被创建」时打一条日志,应该挂在生命周期八个阶段的哪一步?下面这个演示把 Bean 从实例化到销毁的全过程跑一遍,边看边想这个问题。

113 / 174
内核实验
TeaVM观察对象生命周期与日志时机未启动
思考:如果要给 Bean 创建打日志,应该挂在哪一个回调上?
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
114 / 174
  • 想记录「谁被创建了」,最合适的是初始化后置(BeanPostProcessor#postProcessAfterInitialization),此时依赖已注入、代理已就绪
  • 想记录「资源被释放」,挂在销毁回调(@PreDestroy)
  • 直接写在构造器里往往太早——依赖还没注入,日志内容不完整
115 / 174
小节
十二、线上思辨:DEBUG 该不该临时打开
116 / 174
决策
决策线上服务夜里开始零星超时,可疑路径平时只有 INFO 日志,看不出细节。你的第一反应是把整个应用日志级别临时调到 DEBUG 吗?
117 / 174
小节
十三、亲手拆一条日志的流水线:五个参数各看一段
118 / 174

前面把结论讲完了,这一节把「为什么是这个结论」跑出来。第〇节那张流水线图(业务调用 → 门面 → 绑定 → Filter → Layout → Appender → 落地)就是下面这个实验的主线:

119 / 174
内核实验
TeaVM门面与实现在哪一格接上未启动
选「门面与实现绑定」,看清 org.slf4j.Logger 是怎么在启动那一刻找到 logback-classic 的——这就是电源转换头的插合瞬间
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
120 / 174

级别过滤发生在格式化之前,第二节那条要点值得现场验证一次:

121 / 174
内核实验
TeaVM级别门槛到底拦在哪一步未启动
选「级别过滤」,观察被拦掉的日志连字符串都没拼;再切「输出格式怎么拼」看 %X{traceId}、%-5level 是在哪一格被替换的
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
122 / 174

异步和滚动放在最后一起看,因为它们决定的是「事件放行之后」的命运:

123 / 174
内核实验
TeaVM异步队列与滚动归档未启动
先选「异步 Appender」看业务线程只写队列就返回,再选「滚动与归档」看文件什么时候改名、什么时候压缩、什么时候被删
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
124 / 174
  • 绑定发生在启动早期,所以 classpath 里有多个绑定时会立刻告警(第十七节第一行)
  • 级别过滤由 Logger 完成,Filter 由 Appender 完成——两者不是一回事,配错了会出现「级别明明开了却不打印」
  • Layout/Encoder 是唯一能看到 MDC 的地方,%X{key} 在这里被替换
  • AsyncAppender 改变的是「谁去做 I/O」,不改变「要不要输出这条日志」
  • 滚动策略只在写满或到期时触发,totalSizeCap 才是真正的磁盘保险丝
125 / 174
小节
十四、配置从哪来、级别谁能改、异步为什么会卡
126 / 174

日志这套东西有三个「不在链路里却决定链路行为」的外围机制,各用一个实验收尾。

127 / 174

第一个:你的 logging.level.* 到底怎么进到 Logback 里的?答案是走 Spring 的属性体系,因此优先级和 Profile 完全服从那一套规则:

128 / 174
内核实验
TeaVMlogging.level 也被优先级压着未启动
选「谁覆盖谁」,把 logging.level.com.example 依次写成 yml、环境变量、命令行三种来源,预测哪个赢;再用「Profile 激活」看 application-prod.yml 什么时候盖掉默认值
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
129 / 174

第二个:第四节的在线热改级别,背后是谁在做这件事?Actuator 暴露了一个可写的端点,它直接调 Logback 的 API 改 Logger 对象:

130 / 174
内核实验
TeaVM/actuator/loggers 能改级别也能出事未启动
选「暴露面控制」看 endpoints 该露哪些;再选「全暴露的风险」理解为什么 /actuator/loggers 也属于要鉴权的东西——任何人 POST 一下就能把你的生产刷爆磁盘
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
131 / 174

第三个:第七节说 MDC 会在异步线程丢失,第十节说异步 Appender 会丢日志。这两个「异步」其实是同一类问题的两个方向——一个丢上下文,一个丢事件:

132 / 174
内核实验
TeaVM异步的两副面孔:丢 traceId 与丢日志未启动
选「任务提交」和「队列堆积」对照第十.1 节:队列一满,neverBlock 与 discardingThreshold 决定丢谁;再把异常路径那档和 MDC 的 TaskDecorator 放一起想
场景参数
点「运行演示」,在浏览器内真实执行 Java 编译出的内核算法,逐步看它怎么跑。
133 / 174

实验按完了,换成命令行自己敲。这台控制台连着浏览器里的同一个内核,回显全部由内核算出来——logs 直接看此刻打出来的日志长什么样,再逐条 lab:

134 / 174
内核控制台
135 / 174
说明

logs 之后紧接着敲 lab logtrace async,两次输出并排看——同一段业务代码,前者那对括号里有值、后者是空的,差别只在执行线程。这就是第七.1 节整段话的三十秒版本。

136 / 174
小节
十五、沙盘:root=INFO 加一个包的 DEBUG,究竟差多少
137 / 174

新手最想知道的不是「有哪些级别」,而是「我这么配,屏幕上到底会跳出什么」。这个沙盘固定 root: INFO,只切换那个额外开 DEBUG 的包名,同屏对比输出行数与内容:

138 / 174
沙盘
沙盘日志级别选择器:只开一个包的 DEBUG
运行结果
10:12:33.482 INFO c.e.o.OrderController - 下单请求 userId=7
10:12:33.490 DEBUG c.e.o.OrderService - 校验库存 sku=A1 need=2 stock=5
10:12:33.498 DEBUG c.e.o.PriceCalculator - 原价=99.0 券=10.0 应付=89.0
10:12:33.510 INFO c.e.o.OrderService - 订单创建成功 orderId=10023
# 只有 order 包变吵,user/pay 包纹丝不动
总行数:4 行/请求
推荐姿势。爆炸半径限定在一个包,磁盘涨幅可控,排查线索全在里面。
139 / 174
说明

这里的行数与体积是示意,但规律是真的——开 DEBUG 的成本按「请求数 × 每请求行数」放大。同一个包在你手上是 4 行,在 QPS 200 的接口上就是每秒 800 行。这也是为什么第四节的 Actuator 方案强调「用完立刻改回去」。

140 / 174
小节
十六、随堂自测
141 / 174

先来一道热身题,直接对应第一节那个翻车现场:

142 / 174
随堂自测
随堂自测团队要把日志实现从 Log4j2 换成 Logback。下列哪种代码现状会让这次迁移代价最大?
先自己选一个,选中立刻告诉你对不对
143 / 174

再来一道综合题,把第二节的级别继承、第四节的配置来源和第五节那个 logback.xml 陷阱串起来:

144 / 174
随堂自测
随堂自测application.yml 里配了 logging.level.root=INFO 和 logging.level.com.example.order=DEBUG,但 OrderService 里的 log.debug("订单={}", order) 一行都不输出。下列哪项解释**不可能**成立?
先自己选一个,选中立刻告诉你对不对
145 / 174
小节
十七、常见报错速查
146 / 174
对照表
报错原文(片段)真实原因30 秒自救深挖看第几篇
Classpath collision detected: ... both import ... org.slf4j.impl.StaticLoggerBinderclasspath 上有两个以上绑定(例如既有 logback-classic 又有 log4j-slf4j-impl),SLF4J 只能挑一个,于是报警并随机选mvn dependency:tree -Dincludes=org.slf4j,ch.qos.logback,org.apache.logging.log4j 找出来,用 <exclusions> 只留一套本篇第三节
Logging system failed to initialize using configuration from 'null' / Could not initialize Logback logging from class path resource [logback-spring.xml]XML 本身语法错、appender 类名写错,或你在 logback.xml 里用了 <springProfile>(那个文件读得太早,不认识 Spring 标签)看 caused by 第一行指出的是哪个元素;确认文件名是 logback-spring.xml;临时把文件改名让它回落默认配置以确认是它的问题本篇第五节
应用起来了但一行日志都没有,或者只有 banner级别被压住了:logging.level.root=ERROR,或某个第三方包把 root 改了;也可能是 logback.xml 抢先加载curl localhost:8080/actuator/loggers/ROOT 看 effectiveLevel;再看启动日志里有没有 Defaulting Log4J/Logback to ...本篇第二、四节
日志里 [traceId] 一直是空的 []异步执行(@Async、线程池、CompletableFuture)在新线程上跑,新线程没有父线程的 MDC给线程池装 TaskDecorator(第七.1 节),并在 finally 里 MDC.clear()本篇第七节
流量尖峰后发现 ERROR 之外的日志整段消失AsyncAppender 的 discardingThreshold 默认会在队列剩 20% 时丢弃 TRACE/DEBUG;配了 neverBlock=true 时队列满还会直接丢要零丢失就 discardingThreshold=0 + neverBlock=false 并接受阻塞;要吞吐就加大 queueSize本篇第十.1 节
日志文件里中文变成 ??? 或乱码encoder 没显式声明字符集,于是沿用 JVM 的 file.encoding;写入端与查看端(编辑器、tail、日志平台)编码不一致时必乱<encoder><charset>UTF-8</charset></encoder> 显式写上;必要时启动加 -Dfile.encoding=UTF-8,并统一查看端编码本篇第五节
改了 logback-spring.xml 没生效要么改的是 target/classes 下的副本,要么 scan="true" 没开且没重启改源文件并重新编译;或在 <configuration scan="true" scanPeriod="60 seconds"> 上等待一分钟本篇第五节
java.lang.IllegalStateException: Logback configuration error detected: ... Failed to parse mapping (Spring Boot 3.x)logstash-logback-encoder 版本与 Logback 主版本不匹配对齐版本(Boot 3.x 用 encoder 7.4+);mvn dependency:tree 确认没有两个 logback-classic本篇第八节
147 / 174
提示

这张表里最容易被忽略的一行是「日志一行都没有」。九成不是框架坏了,而是有人在你看不见的地方放了另一个配置文件。第一件事永远是查 /actuator/loggers/ROOT 的实际生效级别,第二件事是搜 classpath 上有没有多个 logback*.xml。

148 / 174

「另一个配置文件」这件事,最典型的现场就是下面这段——它一行异常都没有,却把整个生产环境的级别决定权抹掉了。先别看解析,点出你认为的凶手行:

149 / 174
报错急救
报错急救no applicable action for [springProfile]
改了个文件名,prod 那段配置整段失效

同事把项目里的 logback-spring.xml 重命名成 logback.xml,理由是「IDEA 提示我这个模板叫这个名字」。启动照常成功,只是 prod 环境的 INFO 好像从来没生效过。

10:12:31,482 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:12:31,483 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/D:/bee/target/classes/logback.xml]
10:12:31,552 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@14:82 - no applicable action for [springProfile], current ElementPath is [[configuration][springProfile]]
10:12:31,553 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@15:30 - no applicable action for [springProperty], current ElementPath is [[configuration][springProfile][springProperty]]
10:12:31,560 |-WARN in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Attempted to append to non started appender [FILE]
10:12:31,561 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@3f1a2b - Registering current configuration as safe fallback point
点你认为的「凶手行」(可反复试)
不会也没关系:先猜异常名,再猜哪一行在做决定。
150 / 174
小节
十八、动手练习
151 / 174
小节
第一档 · 照做
152 / 174

目标:搭出一个「开发看彩色控制台、生产落 JSON 文件、并且带 traceId」的最小可用配置。

153 / 174

第一步,依赖只要默认的(spring-boot-starter-web 已带入 SLF4J + Logback),额外加结构化输出:

154 / 174
xml
<dependency>    <groupId>net.logstash.logback</groupId>    <artifactId>logstash-logback-encoder</artifactId>    <version>7.4</version></dependency>
155 / 174

第二步,src/main/resources/logback-spring.xml:

156 / 174
xml
<?xml version="1.0" encoding="UTF-8"?><configuration scan="true" scanPeriod="60 seconds">    <property name="LOG_HOME" value="./logs"/>    <property name="PATTERN"              value="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] [%X{traceId}] %logger{36} - %msg%n"/>    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">        <encoder>            <pattern>%d{HH:mm:ss.SSS} %highlight(%-5level) [%X{traceId}] %cyan(%logger{36}) - %msg%n</pattern>            <charset>UTF-8</charset>        </encoder>    </appender>    <appender name="JSON_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">        <file>${LOG_HOME}/bee-json.log</file>        <encoder class="net.logstash.logback.encoder.LogstashEncoder">            <includeMdcKeyName>traceId</includeMdcKeyName>        </encoder>        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">            <fileNamePattern>${LOG_HOME}/bee-json.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>            <maxFileSize>50MB</maxFileSize>            <maxHistory>7</maxHistory>            <totalSizeCap>1GB</totalSizeCap>        </rollingPolicy>    </appender>    <springProfile name="dev">        <root level="INFO"><appender-ref ref="CONSOLE"/></root>    </springProfile>    <springProfile name="prod">        <root level="INFO">            <appender-ref ref="CONSOLE"/>            <appender-ref ref="JSON_FILE"/>        </root>    </springProfile></configuration>
157 / 174

第三步,塞入 traceId 的那个 Filter 直接用第七节的 TraceIdFilter,然后在任意 Service 里写一行:

158 / 174
java
log.info("订单创建成功 orderId={}", order.getId());
159 / 174

第四步,命令与预期输出:

160 / 174
bash
$ mvn spring-boot:run -Dspring-boot.run.profiles=dev... Started BeeApplication in 3.42 seconds# 浏览器访问 /orders 后,控制台:10:12:33.510 INFO  [9f2c1a7b3e5d8401] c.e.o.OrderService - 订单创建成功 orderId=10023$ ls logs/# dev profile 下没有 bee-json.log —— 因为 JSON_FILE 只挂在 prod 上
161 / 174

看到控制台那行带方括号 traceId、且 logs/ 目录为空,就算过关。

162 / 174
小节
第二档 · 变体
163 / 174
  1. 换成 -Dspring-boot.run.profiles=prod 再打一次请求。你会观察到:logs/bee-json.log 出现,内容是一行标准 JSON,里面有 "traceId":"9f2c1a7b3e5d8401" 字段。
  2. 把 maxFileSize 改成 1KB,写个循环打 5000 行日志。你会观察到:目录下瞬间冒出 bee-json.2026-10-07.0.log.gz、.1.log.gz… 一串分片,这就是 %i 的含义;再把 totalSizeCap 改成 1MB,你会观察到老分片开始被删除。
  3. 故意把 <charset>UTF-8</charset> 那行删掉,并在 Windows 控制台跑。你会观察到中文位置变成乱码——补回来即恢复。接着把文件名改成 logback.xml(去掉 -spring)重启,你会观察到启动直接抛 Logging system failed to initialize,因为 <springProfile> 在那个文件里不被认识。
164 / 174
小节
第三档 · 造一个
165 / 174

做一个「可运维的日志基线」,要求交付一份能被别人接手排障的配置。验收清单:

166 / 174
  • [ ] 三个 profile(dev / staging / prod)用同一份 logback-spring.xml,靠 <springProfile> 区分,无重复文件
  • [ ] 业务包 INFO、SQL 包按需 DEBUG,且第三方框架(Hibernate、Hikari)被压到 WARN 或 INFO
  • [ ] 有一条完整的 traceId 链路:入口 Filter 写入 → pattern 输出 → 异步线程通过 TaskDecorator 不丢失 → 响应头回传
  • [ ] ERROR 单独落到一个文件,且只收 ERROR(LevelFilter 的 onMatch/onMismatch 都用上了)
  • [ ] 文件同时受 maxFileSize、maxHistory、totalSizeCap 三者约束,并能解释「少了 totalSizeCap 会发生什么」
  • [ ] 用 Actuator 把一个包临时调到 DEBUG、复现一次问题、再改回 INFO,全程不重启
  • [ ] README 里写清:出线上问题时,第一句该执行的 curl 命令是什么
167 / 174
小节
十九、要点自查
168 / 174
自检

我能说出「门面 / 实现 / 桥接包」三者分别对应流水线的哪几格吗?说不出就回到第〇节那张图。

169 / 174
自检

我知道 logback.xml 与 logback-spring.xml 的差别不是名字而是加载时机,因此后者才有 <springProfile> 吗?

170 / 174
自检

我的每条 log.error 都把异常对象放在了最后一个参数,而不是 e.getMessage()?

171 / 174
自检

我的异步线程池装了 TaskDecorator,并且 MDC 的每次 put 都能在同一个方法里找到一个 finally 里的 remove/clear?

172 / 174
自检

我能对 queueSize、discardingThreshold、neverBlock 三个参数的任意组合,说出「丢了什么、堵了谁」?

173 / 174
口诀

代码只认插头,插座随便换;级别能热调,MDC 必归还。

174 / 174
总结

这一节请把三件事刻进肌肉记忆——业务代码只依赖 SLF4J 门面,实现交给 Logback;级别是过滤门槛而不是重要性排序,能动态调就别重启;MDC 的 put 必须配一个 finally 里的 remove。日志的价值不在「写了多少」,而在「出问题时能不能在十秒内定位」——把它当成一门可检索的工程能力,而不是随手一行的 println。