ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

SpringBoot MDC链路追踪实战:过滤器、线程池与traceId排坑

SpringBoot MDC链路追踪实战:过滤器、线程池与traceId排坑

线上排查问题的时候,最让人崩溃的瞬间不是报错本身,而是你根本不知道这段报错对应的是哪一次请求。流量稍微一上来,几十个并发请求在日志里混成一片,同一个线程池里的线程日志交错出现,你grep半天,看到的只有一堆孤立的ERROR,缺参数、缺上下文、缺来龙去脉。后来我在项目里稳定落地了 MDC 日志链路追踪,整个局面才彻底改观:每个请求进来都带一个 traceId,无论走到 Controller、Service、异步任务还是下游服务,日志里都会跟着这同一个ID。彻底告别“捞针式排查”。

这套方案在 SpringBoot 项目里落地难度不高:一个过滤器、一段日志配置、一个线程池装饰器,半天时间就能跑通。但真正把它用对、用稳,躲开异步线程池丢上下文、线程复用串traceId这些坑,还是有一些门道。这篇文章就从原理、实现、异步场景到实战排坑,完整梳理一遍,适合正在做日志治理、或者被线上问题排查折磨到崩溃的Java后端开发者参考。

1. 先从排查日志的痛点出发:MDC 链路追踪到底在做什么

1.1 MDC 到底是什么

MDC 的全称是 Mapped Diagnostic Context,翻译过来是“映射诊断上下文”,它是 SLF4J 提供给日志框架的一套线程级键值对存储机制。SpringBoot 默认使用的 Logback 对它做了完整实现,核心原理简单说就是:当前线程往 MDC 里放一个 key-value,之后这条线程上打出的每一条日志,都能从日志 pattern 里的 %X 占位符拿到这个值。

举个例子,在过滤器里执行了MDC.put("traceId", "abc123"),然后日志 pattern 里配置了[%X{traceId}],那么同一个线程后续输出的每一行日志,都会自动带上“abc123”这个 ID。请求处理完,调用MDC.remove("traceId")清理,这条链路的上下文就正式结束。

这个机制和日志框架的耦合非常深,所以不需要你做任何字符串拼接,不需要在业务代码里传递一个“日志上下文对象”,一行 put、一行 remove,剩下的事情全交给日志框架。

1.2 为什么不建议用全局静态变量或裸 ThreadLocal

第一次做链路追踪的人最容易想的方案是:在过滤器里搞一个public static String traceId,每次请求来了往里赋值。但并发场景下这基本是自杀式设计——两个请求同时进来,后一个请求的 traceId 会覆盖前一个,前一个请求后续打日志时拿到的全是错的值,排查完直接精神崩溃。

用裸 ThreadLocal 虽然能做到线程隔离,但还得自己管理生命周期,而且日志框架并不认识你的 ThreadLocal,每行日志都得手动拼接 traceId,侵入性太强,代码里到处是“传参地狱”。

MDC 的价值恰恰在这里:它用 ThreadLocal 保证了线程隔离,又通过%X占位符打通了日志框架,把“取当前线程上下文”这件事标准化了。你可以把它理解为每个请求拿到的一张“通行证”,请求处理到哪一步,日志就自动向“查票员”出示这张通行证。

1.3 和分布式链路追踪中间件怎么取舍

有人会说:全链路追踪不是有现成的中间件吗?为什么还要自己搞 MDC。确实,像 OpenTelemetry、SkyWalking 这类方案功能强大得多,能自动生成 traceId、spanId,形成跨服务的调用链路树,还能做耗时分析和拓扑展示。但它们需要引入 Agent、上报组件,有一定运维成本,对小团队和轻量系统来说属于“杀鸡用牛刀”。

MDC 加 traceId 的轻量方案,解决的是最核心的诉求:一条请求的所有日志能串起来,报错时能快速定位到这次请求的全过程。几个服务之间只要约定好 header 字段,同样能实现跨系统追踪,只是没有自动拓扑和调用树罢了。

我的建议是:服务数量不多、团队还没有完整可观测性基础设施的时候,先用 MDC,投入产出比极高。而且将来真要引入 OpenTelemetry,它也会把 trace_id 注入到 MDC 里,你现在做的事情完全不浪费。

2. SpringBoot 落地:过滤器 + traceId + 日志 pattern

2.1 依赖其实不用新增

SpringBoot Web 项目默认内置了 SLF4J 和 Logback,MDC 的 API 就在 SLF4J 里,所以不需要额外引依赖。这里要提醒一句:如果项目里有人把默认日志实现换成了 Log4j2,SLF4J 的MDC类用法依然一致,只是底层适配器不同,pattern 的写法略有差异(Log4j2 是用%X{traceId},本质上和 Logback 相同)。

还有一个前提,项目得有spring-boot-starter-web,因为核心落地位置在 Servlet 过滤器。如果你用的是 WebFlux 响应式项目,那 MDC 这套方案不直接适用,需要在 Reactor Context 里做传递,那是另一个话题,按下不表。

2.2 核心过滤器代码

实现链路追踪的第一步是写一个过滤器,在所有请求的最入口处做三层事情:从上游拿 traceId、没有就自己生成、放入 MDC。同时记得把 traceId 通过响应头返回给调用方,方便排查问题的时候看到“这个请求最终的 traceId 是什么”。

@Component public class TraceIdFilter extends OncePerRequestFilter { public static final String TRACE_ID = "traceId"; public static final String HEADER_NAME = "X-Trace-Id"; @Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { String traceId = request.getHeader(HEADER_NAME); if (!StringUtils.hasText(traceId)) { traceId = TraceIdGenerator.generate(); } MDC.put(TRACE_ID, traceId); response.setHeader(HEADER_NAME, traceId); try { filterChain.doFilter(request, response); } finally { MDC.remove(TRACE_ID); } } }

为什么继承OncePerRequestFilter而不是直接实现Filter?因为 Servlet 容器里一个请求可能经历多次 dispatch(比如 forward、error 跳转),普通 Filter 会被执行多次,而OncePerRequestFilter保证同一请求只过滤一次,避免 traceId 被中途覆盖或者重复生成。

try-finally 是这套方案的生命线。Tomcat 的工作线程会被线程池复用,一个线程处理完 A 请求后,如果不清理 MDC,下一次处理 B 请求时 B 的日志里可能还带着 A 的 traceId,串号就是这么来的。所以“用完必须 remove/clear”不是建议,是原则。

2.3 traceId 生成方案怎么选

生成 traceId 看起来是个小问题,但选错方案在线上是会出事的。我见过直接用UUID.randomUUID()的,也见过用“时间戳加六位随机数”的,这里说下各自的取舍。

生成方案长度是否有序冲突概率适用场景
UUID(去横线)32位无序极低实现最简单,不关心 ID 长度
雪花 ID18-19位数字有序低分布式环境、需要按 ID 感知时间
时间戳+8位随机数约18位局部有序低单实例或少量实例够用
时间戳+6位随机数约16位局部有序高并发下偏高演示项目勉强可用

我个人的偏好是:如果系统已经有统一的 ID 生成服务,直接复用;如果没有,单机部署且并发不极端的情况下,用“时间戳 + 随机数”这种可排序的方案就够了,排查日志时能通过 ID 大概看出请求时间,比纯 UUID 友好。并发特别高的场景用雪花 ID 更稳,能保证简单排序和全局唯一。

public class TraceIdGenerator { private static final SecureRandom RANDOM = new SecureRandom(); public static String generate() { return Long.toHexString(System.currentTimeMillis()) + String.format("%08d", RANDOM.nextInt(100000000)); } }

注意:MDC 里只放体量轻的字符串,绝不要放对象、请求体、响应体。日志输出时每次都会读取 MDC,放一个大的业务对象进去,内存占用和 GC 压力都会显著上升。

2.4 logback-spring.xml 配置

代码写完后,还要让日志输出真正把 traceId 打印出来。这一步在日志配置文件里配 pattern 即可。关键就是%X{traceId},其中花括号里的 key 必须和代码里MDC.put(TRACE_ID, ...)的 key 保持一致,区分大小写。

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId}] %-5level %logger{36} - %msg%n</pattern> <charset>UTF-8</charset> </encoder> </appender>

线上环境我建议把日志同时输出到文件,按天滚动,再用异步 appender 包一层,避免日志 I/O 阻塞业务线程。Logback 的AsyncAppender会把日志事件提交到队列,日志事件生成的那一刻 MDC 快照已经带进去了,所以异步输出不会导致 traceId 丢失,这个可以放心。

另一个小技巧:如果希望 traceId 缺失时在日志里给出显式提示,而不是显示为空串,可以用带默认值的写法%X{traceId:-}或显式固定一个标记。对于排查问题而言,看到空串比看到“no-trace-id”更难判断,所以建议用默认值展示。

2.5 为什么选 Filter 而不是拦截器或 AOP

SpringMVC 的 Interceptor 和 AOP 也能实现类似效果,但有个关键的覆盖范围问题:Filter 处于 Servlet 容器链路上,比 SpringMVC 的 HandlerInterceptor 更靠前,能覆盖到进入 Controller 之前的几乎所有环节,包括拦截器自身日志、参数解析、AOP 切面等。也就是说,在 Filter 里 put 的 traceId,能保证后面所有环节的日志都带上链路 ID。

此外,Filter 天然适配所有走 Servlet 容器的请求路径,包括静态资源、错误分发等。如果某个请求根本没进入 SpringMVC 的处理器链路,Interceptor 和 AOP 都拦不到,Filter 却可以。

还有一个容易被忽略的点:一旦你开启了全局异常处理,错误页面被重新 dispatch 时,Filter 的默认配置可能不覆盖 ERROR 分发,导致错误日志里没有 traceId。解决方法是给过滤器显式设置 dispatcher 类型,把ERROR、ASYNC加进来,保证任何分支里打出来的日志都有链路上下文。

3. 异步线程池、跨服务、MQ 场景的 MDC 传递

3.1 问题根源:ThreadLocal 不传子线程

MDC 底层基于 ThreadLocal,而 ThreadLocal 的设计本意是“当前线程独享”,所以子线程天然拿不到父线程的 MDC 内容。一旦请求处理过程中把任务丢给了线程池,异步线程里打日志时,MDC 就是空的,traceId 直接消失。

这个问题几乎每个做 MDC 的团队都会遇到,而且往往在测试阶段发现不了,因为单测和压测场景很少会去校验异步日志。等上了线上,业务日志里一半有 traceId、一半没有,排查起来照样抓瞎。

更隐蔽的是线程池复用问题:异步线程处理完任务后,如果不清理上下文,下一次被复用处理其他任务时,MDC 里可能残留上一个任务的 traceId。两个不同链路的日志串在一起,比没有 traceId 更可怕。

3.2 线程池传递的标准答案:TaskDecorator

Spring 从 4.3 开始提供了TaskDecorator,专门用于在线程池提交任务时执行一层装饰逻辑。我们可以利用它在任务提交前取到父线程的 MDC 快照,再在任务真正执行前把快照放回子线程,任务结束后清空。

public class MdcTaskDecorator implements TaskDecorator { @Override public Runnable decorate(Runnable runnable) { Map<String, String> contextMap = MDC.getCopyOfContextMap(); return () -> { try { if (contextMap != null) { MDC.setContextMap(contextMap); } runnable.run(); } finally { MDC.clear(); } }; } }

注意这里用的是getCopyOfContextMap()而不是直接拿 MDC 的内部 Map,目的就是复制一份快照,避免子线程修改影响到父线程。子线程执行完之后用clear()而不是简单的remove(traceId),是因为父线程可能在 MDC 里放了多个键值对,clear()才能确保线程池复用时没有任何残留。

配置线程池时挂上这个装饰器:

@Bean public ThreadPoolTaskExecutor taskExecutor() { ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor(); executor.setCorePoolSize(8); executor.setMaxPoolSize(16); executor.setQueueCapacity(200); executor.setTaskDecorator(new MdcTaskDecorator()); executor.setThreadNamePrefix("async-"); executor.initialize(); return executor; }

JDK 原生的ThreadPoolExecutor没有setTaskDecorator这个方法,所以优先使用 Spring 的ThreadPoolTaskExecutor,它内部包装了 JDK 线程池,同时支持这个装饰逻辑。如果项目里大量使用了原生线程池,要么改造提交代码,在execute前手动包装 Runnable,要么统一替换成 Spring 版本的线程池。

3.3 @Async 和定时任务场景

SpringBoot 的@Async默认会找容器中的TaskExecutorBean。如果你按上面方式定义了一个名为taskExecutor的ThreadPoolTaskExecutor,SpringBoot 的异步任务执行器会直接使用它,那么@Async方法内部打日志时 traceId 就能正确传递。如果项目里定义了多个执行器并且@Async("otherExecutor")指定了其他的,那对应的执行器也要配上TaskDecorator。

定时任务同理。@Scheduled任务的执行线程通常由TaskScheduler维护,不在请求链路上,它本身没有 traceId 可以传递。但如果在定时任务里又调用了异步逻辑,可以按同样的思路给TaskScheduler配置装饰器,或者直接约定“定时任务不参与链路追踪”,在它内部生成的日志单独打一个固定标识,别混进请求链路日志里。

3.4 Feign 跨服务如何透传 traceId

微服务场景下,只会单服务打日志还不够,A 服务调用 B 服务时,需要把 A 的 traceId 透传到 B,B 的日志才能和 A 串成同一条链路。Feign 默认同步执行时,请求线程就是调用方线程,所以直接在RequestInterceptor里从 MDC 取值塞进 header 即可。

@Bean public RequestInterceptor traceIdRequestInterceptor() { return template -> { String traceId = MDC.get(TraceIdFilter.TRACE_ID); if (StringUtils.hasText(traceId)) { template.header("X-Trace-Id", traceId); } }; }

下游服务的 Filter 在入口处先从 header 取 traceId,取到了就不自己生成。这个“上游优先”的逻辑就是跨服务链路打通的关键。

RestTemplate 类似,实现一个ClientHttpRequestInterceptor,在请求发出前把 MDC 里的 traceId 设置到请求头。但要注意,如果用的是异步 HTTP 客户端或者开启了 Hystrix 线程池隔离,发起请求的线程已经不是调用方线程了,还是得先解决线程池传递的问题,否则在拦截器里MDC.get拿到的是 null。

3.5 MQ 场景的思路

异步消息场景是 MDC 链路追踪的终极考验:生产者在发送消息时把 traceId 塞进消息头,消费者在处理消息时重新把它放回 MDC。这样一次业务从“接口请求”走到“MQ 生产者”“MQ 消费者”再到“下游处理”,整条链路都能对上号。

// 生产者:发送前把 traceId 放进消息头 MessageProperties props = new MessageProperties(); props.setHeader("traceId", MDC.get(TraceIdFilter.TRACE_ID)); Message message = MessageBuilder.createMessage(payload.getBytes(), props); rabbitTemplate.send("order-exchange", "routing-key", message);
// 消费者:处理消息前恢复 MDC @RabbitListener(queues = "order-queue") public void onMessage(Message message) { Object traceId = message.getMessageProperties().getHeaders().get("traceId"); try { MDC.put(TraceIdFilter.TRACE_ID, traceId == null ? TraceIdGenerator.generate() : traceId.toString()); // 业务处理... } finally { MDC.remove(TraceIdFilter.TRACE_ID); } }

这套做法的核心思想是:链路 ID 的传递最终都落到同一个约定上,不管是 HTTP header 还是 MQ header,只要上下游认同一个头名称,链路就能贯通。我在实际项目中经常把全链路日志按 traceId 一搜,从“用户请求进来”到“异步任务处理完”每一步都清晰可见,排查效率提升的不是一点半点。

4. 实操现场:我踩过的 MDC 坑和排查思路

4.1 常见问题速查表

MDC 方案的坑其实高度集中,大部分团队翻来覆去踩的都是下面这几个。

现象可能原因解决办法
日志完全没有 traceId过滤器没被扫描;pattern 写错;key 大小写不一致确认 @Component 生效,检查 %X{traceId} 写法,统一 key
只有部分日志有 traceId异步线程池没有传递;Filter 顺序问题配置 TaskDecorator;调整过滤器 Order
traceId 串到别的请求finally 里没清 MDC;线程池复用未清理严格 try-finally remove;装饰器里 clear
上游传了 traceId 但下游换新 ID没先取 header;header 名约定不一致Filter 优先取 header,统一头名称
日志中 traceId 大量重复生成算法随机位太短换 UUID 或雪花 ID
错误日志中 traceId 为空ERROR dispatch 没走 Filter配置 dispatcherTypes 覆盖 ERROR

4.2 日志里突然没有 traceId 了,先查这几个地方

遇到日志缺失 traceId,别急着改代码,按这个顺序排查效率最高。

第一步,确认过滤器确实执行了。加一行临时输出,或者在MDC.put处打个断点,看 traceId 有没有真正放进去。很多时候过滤器写好了,但类的包路径不在启动类扫描范围内,@Component根本没生效。

第二步,确认日志 pattern 的 key 和代码里的 key 完全一致。MDC.put("traceId", ...)却写成了%X{traceID},搜索引擎不会帮你纠错,日志框架也不会报错,只是取不到。这个坑低级但非常常见。

第三步,确认日志是在 put 之后打的。如果你在 Filter 的doFilter之前打了日志,那当然没有 traceId。这不是 bug,是先后顺序问题。

第四步,查一下项目里有没有别人定义过同名的 Filter,把你这个给覆盖了,或者多个 Filter 之间的顺序导致 traceId 被提前移除。用@Order控制过滤器的执行顺序,链路注入的过滤器尽量排在最前面。

4.3 traceId 串线问题,十有八九出在 remove

我处理过好几次线上“日志串号”的排查,最后定位到的原因几乎都是同一个:异步线程池的上下文没有清理干净。

背景是这样:请求 A 进来,提交了一个耗时的异步任务到线程池,TaskDecorator 把 A 的 MDC 放进了子线程,但任务结束后装饰器里如果只写MDC.remove("traceId"),那么其他键值对(比如某个业务方塞进去的 userId)还在子线程的 MDC 里。下一次线程池把这条线程分配给请求 B 的任务时,子线程的 MDC 里可能有残留的 userId,B 的日志里就诡异地带上了 A 的 userId。

解决的办法就是我前面提到的:在 TaskDecorator 的 finally 里用MDC.clear(),彻底清理整个上下文。这个做法可能会误删业务在子线程里主动放入的其他 MDC 键,所以最佳实践是:链路口径的 MDC 键统一管理,不要到处随手 put 大而全的上下文,保持一个请求周期内 MDC 里的内容干净可控。

4.4 traceId 重复了怎么办

还有一个容易被忽视的问题是 traceId 重复。用“时间戳 + 6位随机数”的方案,QPS 高一点就会出现重复,尤其在下游用 traceId 做唯一索引建报表或者做日志聚合时,重复 ID 会把不同请求的日志糅在一起。

我在项目里吃过一次亏:当时图省事,用System.currentTimeMillis()加六位随机数,结果压测跑到两千 QPS 就出现了重复。排查出来的原因是随机数空间只有一百万,而同一毫秒内生成的请求数量超过这个规模的零头就会碰撞。

解决办法很简单,要么用 UUID 去横线版本,要么用现成的雪花 ID 生成器,要么把随机位数提升到 8-10 位。但如果你有分布式多实例部署的需求,时间戳加随机数的方案天然不靠谱,建议直接上雪花 ID,由机器 ID 和序列号保证全局唯一。

4.5 性能到底有多大的额外开销

很多团队会担心引入 MDC 影响性能,实际上 MDC 本身的性能开销可以忽略不计。MDC.put本质是一次 Map 写入,日志输出时%X{traceId}取值本质是一次 Map 读取,这两步和请求处理中的数据库查询、远程调用、Json 序列化相比完全是数量级上的差别。

真正需要注意的性能问题有三个方向。第一,MDC 里放了大对象,比如把整个请求体存进去,这在线程池复用的场景下会拖住内存不放,GC 压力陡增。第二,traceId 的生成如果走了远程服务接口,才会有网络开销,本地生成器完全没这个问题。第三,如果公司日志体系接入的是 ES 这类搜索引擎,traceId 作为字符串字段会带来存储和索引开销,需要按实际日志量评估。前两个问题靠规范和设计规避,第三个属于可观测性投入的必要成本,不必因噎废食。

5. 日志平台聚合与未来演进

5.1 把 traceId 变成日志检索的利器

MDC 只是给日志“打标签”,真正让 traceId 发挥价值的是日志采集和检索平台。我在生产环境的标准做法是:日志输出到文件或 stdout,由采集组件统一收走,灌入日志检索平台,然后用 traceId 作为关键分组条件,一次搜索就能挑出整条链路的全部日志。

如果你的采集组件按行分割日志,最好把日志格式固定好,比如在 pattern 里让 traceId 出现的位置固定,然后配一个 grok 表达式把 traceId 解析成独立字段。这样在检索平台上就可以按字段精确过滤,而不是全文本模糊搜索。更进一步,可以考虑把关键日志输出成 JSON 格式,每行一个 JSON 对象,日志字段结构化程度越高,后续做监控、告警、看板就越省事。

我会习惯性地在统一异常处理器里把 traceId 放进错误响应返回给前端,用户报障时直接给一个“traceId: xxxx”,我拿到就能立刻去日志平台定位到他的请求。这个细节很小,但真的能大幅提升问题处理效率。

5.2 给未来接入分布式链路追踪留后路

团队慢慢变大、服务越来越多之后,你大概率会考虑引入更完整的分布式链路追踪方案。这时候不用觉得 MDC 白做了,因为成熟的链路追踪方案都会把 traceId 和 spanId 注入到 MDC 中,以便和现有日志体系打通。

从今天起就可以做两件“留后路”的事。第一,统一 MDC 的 key 命名,最好是业界通用的规范,比如trace_id、span_id,而不是自定义的traceId。这样将来切到 OpenTelemetry 时,日志 pattern 里改个 key 名就行。第二,HTTP header 的透传字段也用社区共识的命名,比如X-Trace-Id,将来和网关、外部服务对接时更容易达成一致。

换句话说,MDC 方案解决的是“日志上下文同一”这个底层问题,而不管链路 ID 是本地生成、还是将来由链路追踪框架生成,这个底层的日志携带机制都能复用。现在投入的成本,在将来演进成完整可观测性体系时,不会被推翻重来。

最后分享一个我个人的习惯:每次上线前,我都会先检查三件事,过滤器有没有在 finally 里清理、线程池有没有配 TaskDecorator、日志 pattern 里有没有正确写上%X。这三件事都对了,日志链路基本不会出问题。另外别忘了处理“上游透传优先”的策略——网关或者上游服务如果已经传了 traceId,就继续沿用,不要重新生成,否则链路在边界就断了。这些都是踩过坑之后留下的直觉,写在这里,希望对你有用。

RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进