日志排查有多痛苦做过分布式系统的都应该有体会。一条用户请求从网关进来打到订单服务订单服务又去调库存服务中间还穿插着MQ异步消息、缓存查询、定时任务……一旦出问题你得打开五六个服务的日志文件对着时间戳一条条人工拼链路。运气好半小时能拼出来运气不好日志时间差个几百毫秒直接对不上整个下午就耗进去了。我当时接手一个老系统日均请求量上千万服务拆了七八个排查问题基本靠猜。后来定了个规矩所有服务必须在日志里打上TraceId一次请求从入口到出口日志必须能通过同一个ID串起来。这个决定回头来看是用最小成本把排查效率拉高了一个量级。这篇文章就说说SpringBoot里落地TraceId日志追踪的完整思路从日志基座改造到过滤器埋点再到跨线程、跨服务传递最后聊几个生产环境才踩得到的坑。适合正在被分布式日志困扰的后端开发也适合想系统化梳理日志链路的团队参考。1. 为什么日志里需要一条追踪码——排查现场与核心思路1.1 一次真实到不想再经历的排查过程去年有个线上事故用户反馈下单后一直收不到确认通知。我们查支付回调日志发现回调确实到了但后续的订单状态更新、消息发送链路断掉了。问题在哪一段没人知道。支付服务打出的日志有序号订单服务有自己的requestId消息服务则是完全按时间戳打点。三个服务的日志ID体系互不相认只能靠时间反推。更惨的是支付回调和订单状态的更新之间隔了两秒多中间还夹着好几个线程池日志顺序完全乱掉。那次我们三个人花了快一下午最后在一个线程池Executor的日志里发现任务执行时抛了一段JSON解析异常。但因为日志里没有统一ID我们根本无法确认这条异常和用户的订单到底是不是同一条链路。事情解决后我们复盘结论特别一致日志系统缺一个贯穿全链路的身份标识。这个标识就是TraceId。1.2 TraceId到底是什么它解决了什么问题TraceId翻译过来就是追踪ID。它是一次外部请求进入系统时生成的一个全局唯一ID然后在整条调用链路上一直传递下去网关生成一条HTTP头里带着走每个服务收到后把它写进自己的日志上下文下游继续往下传直到整条链路结束。它的作用和快递单号非常像。你寄一个包裹快递单号从发货到中转再到达收货人手上全程不变。任何一段出了岔子你只要报出单号客服就能查出包裹在哪一步滞留了。TraceId就是这条请求链路的物流单号。没有它你在快递堆里找一个包裹只能凭感觉翻有了它输入单号直接定位。它能解决的三个核心问题日志串联一次请求的多个服务日志通过同一个TraceId可以一次性搜索出来按时间线还原完整生命周期。耗时分析把同一条TraceId的日志按时间戳排列能看出时间到底耗在哪个服务、哪个环节上。异常聚类某段时间某个服务错误率飙升按TraceId前缀或包含关系快速聚合同一批失败请求从而缩小故障范围。1.3 三种常用实现方案对比网上搜TraceId方案能搜出来一堆但落地路径其实就三条。我排了个对比表方便你们选型时参考方案实现方式优点缺点适合场景方案A网关统一生成在网关层生成TraceId通过HTTP头向下游传递各服务透传源头唯一链路清晰需要所有服务配合传递改动面大已有API网关的微服务团队方案B日志框架MDCFilter生成在服务入口用Filter生成TraceId写入日志上下文下游透传实现简单改造量小框架选型Logback需团队统一日志规范中小团队、单体多模块、逐步微服务化方案C链路追踪系统引入专业链路追踪中间件自动埋点上报功能全支持可视化部署重侵入性强有学习成本大厂、业务复杂、链路深我个人对中小团队的建议是从方案B起步。原因很简单它能解决80%的日志排查痛点但成本和入侵性只有方案C的20%。等以后业务真复杂到需要拓扑图、耗时火焰图那一步再平滑迁移到方案C也不迟因为TraceId的传递思路是通用的你前期加的TraceId字段到后期一样能复用。2. 环境准备与日志基座改造——先让每条日志都有目击证词2.1 动手前的工程结构设计TraceId的能力不属于任何单一业务模块它属于公共基础设施。所以建议单独建一个模块或者至少一个独立package放相关的类和配置比如叫trace或common-log。这样业务模块引用时只需要加一行依赖不污染主流程代码。如果你用的是多模块Maven工程大概会长这样your-project ├── trace-starter # TraceId基础能力模块 │ ├── TraceIdFilter.java # 请求入口过滤器 │ ├── TraceIdContext.java # MDC封装 │ ├── TraceIdTaskDecorator.java # 线程池装饰器 │ └── TraceIdRestInterceptor.java # HTTP客户端拦截器 ├── order-service # 业务模块依赖trace-starter ├── user-service └── gateway这个设计的核心思路是业务代码里不要出现任何TraceId的操作逻辑。Filter自动做线程池自动做HTTP调用自动做业务代码完全无感知。这种横切关注点就该用切面技术解决而不是让每个业务开发手写一遍。2.2 改造logback日志格式把traceId塞进每一行SpringBoot默认的日志格式是时间戳日志级别线程名logger名消息内容没有TraceId的位置。我们要做的第一件事就是改日志pattern加一个%X{traceId}输出占位符。创建一个logback-spring.xml放在src/main/resources下下面是我在项目中实际在用的基础配置?xml version1.0 encodingUTF-8? configuration !-- 控制台输出 -- appender nameCONSOLE classch.qos.logback.core.ConsoleAppender encoder pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [%X{traceId}] %msg%n/pattern charsetUTF-8/charset /encoder /appender !-- 文件输出 -- appender nameFILE classch.qos.logback.core.rolling.RollingFileAppender filelogs/app.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/app.%d{yyyy-MM-dd}.log/fileNamePattern maxHistory30/maxHistory /rollingPolicy encoder pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [%X{traceId}] %msg%n/pattern charsetUTF-8/charset /encoder /appender root levelINFO appender-ref refCONSOLE/ appender-ref refFILE/ /root /configuration重点是pattern里的[%X{traceId}]。%X是Logback读取MDCMapped Diagnostic Context日志诊断上下文的语法大括号里的traceId就是我们要写入MDC的key。写完之后每行日志会变成这样2024-06-18 14:32:10.456 [http-nio-8080-exec-3] INFO com.example.OrderService - [a7f3b91c8d2e4f5a] 订单创建成功, orderId123456以后再用日志搜索直接在关键字后面加一个a7f3b91c8d2e4f5a整条链路的日志就能全部捞出来。这一步做完日志就已经具备了身份标识的存储能力但还缺一个关键环节——谁负责把TraceId写进MDC。2.3 MDC的原理一个可编程的日志上下文这里有必要把MDC讲透因为后面所有的TraceId操作都在围绕它打转。MDC是SLF4J日志门面提供的一个功能本质是一个线程私有的Map。每个线程往MDC里put的key-value只对当前线程可见当前线程打印的所有日志都会自动带上这个Map里的内容。这正是Logback在pattern里通过%X{traceId}取到值的原理。import org.slf4j.MDC; // 写入 MDC.put(traceId, a7f3b91c8d2e4f5a); // 使用 log.info(业务日志打印traceId会自动出现在pattern对应位置); // 移除 MDC.remove(traceId);注意MDC底层用的是ThreadLocal这意味着父子线程天然隔离。这个特性在同步场景下没问题但一旦牵涉到线程池、Async异步方法、MQ消费就会出现子线程打印日志时TraceId为空的情况。这正好是后面第四章要专门处理的核心坑。3. 拦截器与过滤器请求进来时生成并绑定TraceId3.1 用Filter还是Interceptor为什么选FilterSpringBoot里实现请求前拦截有两个常用组件Servlet的Filter和SpringMVC的HandlerInterceptor。绝大多数方案贴子推荐用Interceptor但我建议用Filter而且是OncePerRequestFilter。核心区别在于请求到达的时序。Filter是Servlet容器级别的组件在请求进入DispatcherServlet之前就执行了Interceptor则是在SpringMVC的HandlerMapping定位到处理器之后才执行。也就是说Filter更早、更外层连静态资源请求、其他Servlet路径都能覆盖到而且Filter天然支持异步请求的多次调用。还有一个实际原因如果你以后接网关、接链路追踪组件它们绝大多数都是在Filter层面工作的。你早点在Filter层把TraceId的规范确定下来后面对接会更省事。OncePerRequestFilter是Spring提供的一个Filter封装它保证同一个请求只执行一次过滤逻辑解决了Servlet规范中Filter在转发场景下可能被多次调用的问题。3.2 完整实现添加、传递、移除的三个关键时刻先看代码这是TraceId过滤器最核心的实现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 javax.servlet.FilterChain; import javax.servlet.ServletException; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; 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 filterChain) throws ServletException, IOException { // 1. 从请求头中尝试获取上游传递进来的TraceId String traceId request.getHeader(X-Trace-Id); if (traceId null || traceId.isEmpty()) { // 2. 上游没有则生成一个新的 traceId UUID.randomUUID().toString().replace(-, ); } // 3. 写入MDC上下文 MDC.put(TRACE_ID, traceId); try { // 4. 继续执行后续业务逻辑 filterChain.doFilter(request, response); } finally { // 5. 请求结束必须清理 MDC.remove(TRACE_ID); } } }这段代码看着简单但三个关键决策点需要解释清楚为什么要从请求头里先取一次因为在一个微服务架构里你处理的请求很可能不是用户直接打进来的而是上游服务转发过来的。如果上游已经在Header里放了TraceId你直接接住它继续用整条链路才能连成线。如果你无视上游ID重新生成一个那上游日志和下游日志就彻底断了。这一点到第五章讲跨服务传递时会再次体现。为什么用UUID还是其他生成器UUID是通用做法而且去掉横杠后长度16位日志里不占太多空间。生产环境如果对ID生成有更高要求可以换成雪花算法或美团开源的Leaf那种发号器但从日志追踪的角度来说UUID的冲突概率已经足够低了没必要过度设计。为什么要在finally里面MDC.remove这个动作最容易被忽略但如果漏了后果相当严重。Tomcat的线程池是复用的一个请求处理完了线程会回到线程池待命下一个请求可能拿到同一个线程。如果上一个请求在MDC里留下的TraceId没被清理下个请求打印日志时就会继承上一个请求的ID两个毫无关系的请求日志搅合在一起排查时会出现幻觉一样的跨请求串号。这个坑我见过不止一次。3.3 兼容标准链路参数的接法现在很多团队已经开始接入OpenTelemetry规范了如果你们系统里已经有链路追踪中间件最好在Filter里做一层兼容让TraceId和规范的traceparent头对齐。业界比较通用的链路上下文头是W3C标准的traceparent格式是版本号-全局TraceId-SpanId-标志位。既然标准已经定好了我们自己定义的X-Trace-Id最好能兼容读取它private String extractTraceId(HttpServletRequest request) { // 优先取自定义头方便外部排查开放 String traceId request.getHeader(X-Trace-Id); if (traceId ! null !traceId.isEmpty()) { return traceId; } // 兼容W3C标准traceparent的第二个字段就是全局TraceId String traceParent request.getHeader(traceparent); if (traceParent ! null !traceParent.isEmpty()) { String[] parts traceParent.split(-); if (parts.length 2 parts[1].length() 32) { return parts[1]; } } return null; }这样做的意义在于今天你用的是自研TraceId明天如果要升级到专业的链路追踪系统TraceId的来源和格式不需要迁移日志侧完全不用动。4. 异步线程池子线程丢失TraceId的坑与TaskDecorator解法4.1 为什么异步日志里traceId会断线上一章我提到MDC底层是ThreadLocal线程之间天然隔离。这意味着在同步调用链路中TraceId从Filter写入MDC后后续同线程的每行日志都能正常输出。但一旦你把任务丢给一个线程池处理情况就变了// 伪代码示意 Async public void sendAsyncMessage(Order order) { // 这里打印的日志[%X{traceId}]是空的 log.info(异步发送消息, orderId{}, order.getOrderId()); }原因就是Async会把方法提交到另一个线程执行而这个新线程的MDC是空的。父线程在MDC里存的TraceId不会自动遗传给子线程。这个问题的隐蔽性在于同步链路里日志完全正常唯独异步链路里TraceId时有时无日志文件看起来一段有一截没有。如果你不知道MDC的线程隔离机制很容易怀疑是Filter写丢数据然后反复在Filter代码里加日志排查最后发现Filter一点问题没有问题出在线程切换。4.2 一个TaskDecorator把上下文复印过去Spring的ThreadPoolTaskExecutor和Async底层都支持一个叫TaskDecorator的扩展点。它的作用是在任务真正执行前做一些包装操作。我们完全可以利用它把父线程的MDC内容复制到子线程里任务执行完再清掉。import org.slf4j.MDC; import org.springframework.core.task.TaskDecorator; import java.util.Map; public class TraceIdTaskDecorator implements TaskDecorator { Override public Runnable decorate(Runnable runnable) { // 父线程的MDC上下文 MapString, String contextMap MDC.getCopyOfContextMap(); return () - { if (contextMap ! null) { // 把父线程的MDC复制到当前线程 MDC.setContextMap(contextMap); } try { runnable.run(); } finally { // 清理当前线程的MDC防止线程池复用串号 MDC.clear(); } }; } }用的时候只需要在线程池Bean上装配装饰器import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Configuration; import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor; Configuration public class AsyncConfig { Bean(asyncExecutor) public ThreadPoolTaskExecutor asyncExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); executor.setCorePoolSize(8); executor.setMaxPoolSize(16); executor.setQueueCapacity(1000); executor.setThreadNamePrefix(async-); // 关键步骤绑定装饰器 executor.setTaskDecorator(new TraceIdTaskDecorator()); executor.initialize(); return executor; } }如果你用的核心线程池是java.util.concurrent.ThreadPoolExecutorSpring也提供了对应的适配器ThreadPoolTaskExecutor如果你的代码里直接new了原生ThreadPoolExecutor就需要手动在任务提交前复制MDC或者用中介包装Runnable。这里更推荐直接统一用ThreadPoolTaskExecutor这样装饰器能统一管理。4.3 踩坑实录装饰器漏配导致的半小时定位事故讲一个实际发生的案例。某次压测架构组要求全链路日志必须带TraceId。订单服务接了Filter日志打印正常。但发现一个问题订单创建成功后发Kafka消息、发短信通知的日志里TraceId要么是空的要么是上一次请求残留的。我们当时以为是MQ生产者配置问题翻遍了Kafka相关的配置类毫无头绪。后来发现这个服务里混用了两种线程池一部分Bean是ThreadPoolTaskExecutor一部分是裸ThreadPoolExecutor。前者通过setTaskDecorator配置了装饰器TraceId正常传递后者没有任何包装直接execute任务MDC当然是空的。更隐蔽的是因为线程池里线程是复用的那些裸ThreadPoolExecutor处理的日志里TraceId有时候显示的是上一个任务的ID——看起来好像有值实际上完全是串号的脏数据。这种日志如果你不仔细关联请求时间线根本发现不了。排查经验总结成一条不要在一个应用里混用多种线程池执行异步逻辑统一用ThreadPoolTaskExecutor并且统一配TaskDecorator。如果有历史裸线程池写个工具类统一提交时复制MDC别让这个坑留到生产爆雷。5. 跨服务传递把TraceId装进HTTP头寄给下一个系统5.1 为什么TraceId必须随RPC请求出门本地日志做得再好一次业务请求如果跨了三个服务A服务日志里TraceId是a7f3...B服务里TraceId却是新生成的一个ID那这条链路在跨服务层面又断了。所以TraceId必须跟着请求出门——每次发起HTTP调用时把当前线程MDC里的TraceId塞进请求头下游服务的Filter才能通过request.getHeader(X-Trace-Id)把它接住。远程调用主要分两种场景RestTemplate/WebClient这种HTTP客户端以及OpenFeign这种声明式客户端。两个场景都要做拦截器注入。5.2 RestTemplate与OpenFeign的请求头注入RestTemplate是Spring最经典的HTTP客户端它提供了ClientHttpRequestInterceptor扩展点可以在请求发出前统一设置请求头import org.slf4j.MDC; import org.springframework.http.HttpRequest; import org.springframework.http.client.ClientHttpRequestExecution; import org.springframework.http.client.ClientHttpRequestInterceptor; import org.springframework.http.client.ClientHttpResponse; import java.io.IOException; public class TraceIdRestInterceptor implements ClientHttpRequestInterceptor { Override public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { String traceId MDC.get(traceId); if (traceId ! null !traceId.isEmpty()) { request.getHeaders().set(X-Trace-Id, traceId); } return execution.execute(request, body); } }然后在构建RestTemplate实例时把它注册进去Configuration public class RestTemplateConfig { Bean public RestTemplate restTemplate() { RestTemplate restTemplate new RestTemplate(); restTemplate.setInterceptors(List.of(new TraceIdRestInterceptor())); return restTemplate; } }如果你的服务用的是OpenFeign也有一个非常对口的扩展点RequestInterceptorimport feign.RequestInterceptor; import feign.RequestTemplate; import org.slf4j.MDC; public class TraceIdFeignInterceptor implements RequestInterceptor { Override public void apply(RequestTemplate template) { String traceId MDC.get(traceId); if (traceId ! null !traceId.isEmpty()) { template.header(X-Trace-Id, traceId); } } }Feign的RequestInterceptor会在模板构建完成、真正发送请求之前执行所以这里设置Header是安全且有效的。注册方式也简单在Feign的配置类里把这个类声明成Bean即可。如果你用的是Spring Cloud Gateway网关甚至可以在全局过滤器里统一透传避免每个下游服务都自己加拦截器。网关侧逻辑就是从ServerWebExchange的请求头里取TraceId如果没有则生成然后塞进MDC转发时通过ServerWebExchange.Builder改写请求头。这一层做好之后下游服务理论上可以无感接入因为它们只需要在Filter里读取Header。5.3 消费方如何优雅地认领头部TraceId请求到了下游服务之后就是第三章TraceIdFilter的活了。Filter里优先读Header读到了就用Header里的值写入MDC读不到才自己生成。这段逻辑我在3.2节已经给了完整实现这里想补充一个设计原则Header里的TraceId优先级永远大于本地生成。原因是整条链路需要一个唯一的根TraceId如果每个服务都优先生成自己的链路就断了。严谨的做法是在Filter里做好上接下传HTTP客户端侧做好下发两边配合链路才能完整。我把这条路线的数据流画出来别嫌我用文字描述流程图在博客里经常排版乱文字反而更清楚用户请求 - 网关Filter(生成TraceId: a7f3...) - 设置响应头X-Trace-Id: a7f3... - 转发请求头X-Trace-Id: a7f3... - 订单服务Filter(读到a7f3...,写入MDC) - 订单服务RestTemplate拦截器(从MDC取a7f3...,加到下游请求头) - 库存服务Filter(读到a7f3...,写入MDC) - ... - 整条链路日志都带a7f3...整条链路只要有一个环节没传TraceId链路就会断一截。这也是为什么我强烈建议把TraceId传递做成公共starter而不是每个业务服务自己复制粘贴一份代码。公共组件意味着一次改造全链路生效少一个遗忘角落。6. 响应头输出与生产排查的实战技巧6.1 在HTTP响应中带回TraceId日志追踪不只是给后端开发自己看的前端调用接口报错时如果接口响应头里带着一个TraceId前后端联动排查的效率会高很多。用户在前端页面看到网络异常客服把浏览器开发者工具里的TraceId报给后端后端拿这个ID直接捞日志几分钟就能定位。实现方式是在入口Filter里把TraceId设置到响应头Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { String traceId extractTraceId(request); if (traceId null || traceId.isEmpty()) { traceId UUID.randomUUID().toString().replace(-, ); } MDC.put(TRACE_ID, traceId); // 关键把TraceId写入响应头 response.setHeader(X-Trace-Id, traceId); try { filterChain.doFilter(request, response); } finally { MDC.remove(TRACE_ID); } }这一步动作很小但收益很直接。尤其是用了API网关做统一入口的系统在网关层统一注入响应头所有服务的HTTP响应都自带TraceId临时的联调排错都不需要扒日志看半天。6.2 日志检索的三条黄金经验TraceId落地之后怎么用好它才是真正见功夫的地方。分享三条我在生产环境摸索出来的经验经验一用TraceId做全链路耗时分析。找出同一条TraceId下的所有日志按时间戳排序重点看每个服务入口日志和出口日志的时间差能迅速定位耗时集中在哪个节点。比如一条请求总耗时800ms其中商品服务占50ms库存服务占700ms问题在库存服务就非常明显。经验二ERROR日志必须带上TraceId一起告警。我们后来给日志采集加了规则ERROR级别的日志必须从MDC里把TraceId提取出来作为一个独立维度字段上报到监控系统。这样告警平台触发的每一条告警都能在日志平台里按TraceId一键关联上下文大幅缩短了值班人员的定位路径。经验三定期抽查空TraceId日志。如果你发现日志里有一批日志的TraceId是空的排查顺序是入口Filter是否被其他Filter拦截了异步线程池是否都配了TaskDecoratorMQ消费是否在消费端入口补充了TraceId生成逻辑日志里空TraceId的比例某种程度上反映了你的TraceId链路覆盖率的健康程度。6.3 TraceId之外的衍生玩法全链路标签池TraceId只是日志追踪的第一层。等这套机制跑稳了你会发现MDC里还能放更多维度比如用户ID、订单号、渠道来源、环境标识。把它们都放进MDC日志的检索维度会一下子丰富起来。MDC.put(traceId, traceId); MDC.put(userId, String.valueOf(userId)); MDC.put(channel, channel);日志配置里统一加上对应输出项pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [%X{traceId}][%X{userId}][%X{channel}] %msg%n/pattern这样排障的时候不只知道你这条链路是谁traceId还知道是哪个用户、从哪个渠道进来的。前端的电商客服一报用户ID是123456在支付宝渠道下单失败后端直接拿userId刷日志比拿TraceId更快进入场景。不同领域可以从这个思路延伸出自己的标签体系核心逻辑是一样的——在日志里建立多维度的诊断上下文。TraceId这件事从需求提出到全链路跑通我们走了大概两周真正写代码的时间三四天剩下时间都在补历史线程池的坑和规范统一。回头来看这可能是最近一年里性价比最高的一次架构改造。如果你也在被多服务日志问题困扰建议找个下午把Filter和日志Pattern先搭起来跑通一条最简单的链路再逐步覆盖异步线程和跨服务调用。这一层基建越早铺好后面排查问题的时间就越值钱。