SpringBoot 系列之实现全链路日志TraceId追踪
做后端的同学应该都有过这种体验:白天业务正常,半夜被一条线上告警叫醒,登录服务器翻日志,结果发现同一时刻几百个请求的日志全部交织在一起。你明明知道用户张三在下单,日志里却同时混着李四的支付、王五的退款。想还原张三这一次请求到底走了哪些环节、在哪一步报的错,得靠猜。后来我才真正意识到,不是日志框架不给力,而是我们的日志里缺了一个东西——TraceId。
所谓全链路日志TraceId追踪,就是在一次业务请求从进入到返回的整个过程中,往日志里写入一个全局唯一的标识符,让这条请求在应用内部打出的所有日志都能被串起来。有了它,你搜一个TraceId,就能看到这个请求从Controller到Service到DAO的全部轨迹,甚至跨服务、跨消息队列也能追踪。这篇文章我会从一个SpringBoot项目的落地实践出发,把TraceId的生成、注入、透传、以及异步线程池里的坑完整地讲一遍,代码可以直接拿到项目里用。
1. 从一次线上事故说起:日志交织时的绝望感
1.1 没有TraceId的排查经历
先说一个真实场景。某个周五晚上,运营反馈有用户在下单后收不到积分到账的提示。我打开生产日志准备定位,日志大概长这样:
2025-03-14 22:13:45.213 INFO [http-nio-8080-exec-12] OrderServiceImpl : 用户2233下单成功,订单号SO20250314221345001 2025-03-14 22:13:45.214 INFO [http-nio-8080-exec-17] PointServiceImpl : 用户8891积分变更,增加100 2025-03-14 22:13:45.215 ERROR [http-nio-8080-exec-12] PointServiceImpl : 积分更新失败,用户2233,异常: DB连接池获取超时 2025-03-14 22:13:45.216 INFO [http-nio-8080-exec-17] OrderServiceImpl : 用户8891下单成功,订单号SO20250314221345002用户2233的订单操作和用户8891的订单操作穿插在一起,线程号倒是可以区分,但你要是用grep把整个时间段日志拉下来看,眼睛很容易看花。更麻烦的是,单次请求涉及的日志往往散落在不同的线程、不同的类、甚至不同的应用实例里。没有TraceId,你只能拿订单号、用户ID去逐个grep,运气好能凑出一条链路,运气不好就得人肉拼图。
后来我请教了团队里一位老前辈,他说:"你们日志里没有traceId,排查问题全靠猜,这是基建缺失。"这句话让我印象很深。他给我展示了他们系统的日志:
2025-03-14 22:13:45.213 INFO [traceId=8f2c1a3e9d4b6c7a] OrderServiceImpl : 用户2233下单成功,订单号SO20250314221345001 2025-03-14 22:13:45.215 ERROR [traceId=8f2c1a3e9d4b6c7a] PointServiceImpl : 积分更新失败,用户2233,异常: DB连接池获取超时 2025-03-14 22:13:45.687 INFO [traceId=8f2c1a3e9d4b6c7a] WebExceptionHandler : 返回错误响应: 积分服务不可用只搜8f2c1a3e9d4b6c7a这一个编号,用户2233从下单到积分失败再到统一异常处理的完整时间线就出来了,每一条日志都带同一个编号,谁也不跟谁混。这也是全链路日志TraceId在单体应用内最朴素的用法:给"单次请求"一个快递单号,顺着这个单号能把包裹完整寄送路径翻出来。
1.2 TraceId的定义与价值
TraceId的正式定义是"一次分布式调用链路的全局唯一标识"。一次用户请求从浏览器到网关、到订单服务、再到积分服务,背后可能调用十几个接口,消息也可能会发到MQ后被异步服务消费。TraceId的作用就是把这一整条调用链上的所有日志用同一个ID串起来。
它和我们熟悉的SpanId不同。在一个典型的链路追踪体系里(比如Google Dapper论文、Jaeger等),TraceId标识整条链路,SpanId标识链路中的某一次调用,ParentSpanId记录父子关系。如果你的团队已经接入了SkyWalking、Zipkin这类组件,TraceId的概念早已在用;如果你的团队还在用最原始的日志排查方式,那从日志层先把TraceId做出来,是最低成本、收益最大的一步。
从我自己的实践经验来看,TraceId至少能带来三层价值:
- 快速定位问题:拿到一个用户反馈,复制他的TraceId(通常从统一异常响应里带出来),一条
grep就能还原全过程。 - 准确的耗时分析:把同一条TraceId的日志按时间排序,能看到哪个环节慢、哪一步出错。
- 跨系统协作:多个服务都按同一套规范记录TraceId后,线上排查不用再"跨部门翻日志"。
1.3 一次请求的完整视图长什么样
在落地TraceId之后,一次出错的请求在日志系统里看起来应该是这样的:
| 时间 | TraceId | 日志内容 |
|---|---|---|
| 22:13:45.213 | 8f2c1a3e9d4b6c7a | 收到下单请求,用户2233,参数校验通过 |
| 22:13:45.215 | 8f2c1a3e9d4b6c7a | 订单创建成功,开始调用积分服务 |
| 22:13:45.215 | 8f2c1a3e9d4b6c7a | 积分更新失败,异常: DB连接池获取超时 |
| 22:13:45.687 | 8f2c1a3e9d4b6c7a | 全局异常处理器返回: 积分服务暂不可用 |
把中间那些无关请求全部滤掉,只在TraceId后面加一个grep,你就能获得一段"单请求视角"的时间线。这种体验一旦用上就回不去了。接下来我们看技术落地,第一步是理解背后的三个关键组件。
2. 核心机制拆解:MDC、Filter与日志框架如何协作
2.1 MDC到底是什么
MDC的全称是Mapped Diagnostic Context,中文常译作"映射诊断上下文",是日志框架(slf4j)提供的一个功能。它本质上是一个与当前线程绑定的Map,你可以往里放键值对,然后在日志pattern里通过%X{key}取出并输出。
以logback为例,你在日志配置里这样写:
%date %level [%X{traceId}] %logger{36} - %msg%n日志输出时,logback会自动去当前线程的MDC里找traceId这个key,找到就输出,找不到就输出空。整个过程对业务代码零侵入——你不需要在每一个日志调用里手动拼接TraceId。
需要特别注意的是,MDC底层用的是ThreadLocal,这意味着它天然和线程绑定。大部分时候我们打印日志的线程和处理请求的线程是同一个,所以"在请求进入时put,在请求结束时remove"就能生效。但一旦你用了线程池、异步注解、消息队列消费,事情就变了,后面专门有一节讲这个。
2.2 Filter为什么是注入TraceId的最佳位置
在SpringBoot里,给一个HTTP请求注入TraceId的最佳位置就是javax.servlet.Filter(Servlet 3.0以上版本更推荐OncePerRequestFilter)。
原因很简单:
- Filter在请求进入Controller之前执行,此时设置MDC,之后Controller、Service、DAO层所有日志都能拿到。
- Filter在请求响应完成之后执行清理,能保证MDC不残留,避免线程复用时TraceId串到下一个请求。
- 一个Filter就能覆盖整个Servlet容器的请求链路,不需要改动任何业务代码。
我曾经见过有同事在拦截器(HandlerInterceptor)里做这件事,也能跑通,但preHandle和afterCompletion的注册只针对SpringMVC的Handler,对于静态资源、拦截器未覆盖的路径就没法生效。Filter的覆盖面更全面,是更稳妥的选择。
2.3 数据流全景
把一次带TraceId的请求从头到尾拆开,数据流是这样的:
- 请求进入Servlet容器(Tomcat)。
TraceIdFilter.doFilter被调用,先从HTTP Header里取上游传来的TraceId;取不到就自己生成一个。- 把TraceId放入MDC:
MDC.put("traceId", id)。 - 继续执行
filterChain.doFilter(request, response),进入SpringMVC、进入业务代码。 - 业务代码打印日志时,logback自动从MDC里取
traceId并输出。 - 响应返回后,Filter在
finally里执行MDC.remove("traceId"),线程恢复干净状态。
整个流程图我不用画了,用一句话总结就是:进请求时种下种子,请求结束前回收种子。
3. 动手实现:从生成TraceId到日志输出
3.1 定义TraceId生成器
TraceId的生成方式有很多种,最简单的就是直接用UUID,然后去掉中间的横线:
public class TraceIdGenerator { public static String generate() { return UUID.randomUUID().toString().replace("-", ""); } public static boolean isValid(String traceId) { return traceId != null && !traceId.isBlank(); } }有人会纠结UUID生成的字符串有32位,日志里太长;也可以用System.currentTimeMillis()加随机数拼接成短ID,但并发高时碰撞概率会增加。如果只是日志追踪用途,UUID完全够用,性能影响可以忽略不计。
如果公司链路追踪体系比较完善,也可以接入现成的IdGenerator,比如雪花算法(Snowflake)的全局ID。但雪花算法依赖机器号和时钟,实现和运维成本高一些,单体应用做日志TraceId完全没必要上来就上雪花。我实际项目中就是先用UUID跑通的,后来要接链路追踪平台时再换成平台提供的TraceId生成和解析器,接口是现成的。
3.2 编写核心的TraceIdFilter
下面这个Filter是整套方案的心脏。它负责三件事:从上游请求头取TraceId、生成TraceId、把TraceId写入MDC并在请求结束后清理。
@Component public class TraceIdFilter extends OncePerRequestFilter { public static final String TRACE_ID_HEADER = "X-Trace-Id"; public static final String MDC_KEY = "traceId"; @Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { String incomingTraceId = request.getHeader(TRACE_ID_HEADER); // 上游有就沿用,没有就自己生成 String traceId = TraceIdGenerator.isValid(incomingTraceId) ? incomingTraceId : TraceIdGenerator.generate(); MDC.put(MDC_KEY, traceId); // 顺手把TraceId写进响应头,前端/调用方就能拿到,方便用户报障时提供 response.setHeader(TRACE_ID_HEADER, traceId); try { filterChain.doFilter(request, response); } finally { // 关键:线程复用前必须清理 MDC.remove(MDC_KEY); } } }几个细节值得展开。
首先是为什么用OncePerRequestFilter。在Servlet 2.5时代,Filter默认在同一个请求里只会执行一次,但如果你在多级代理或转发(forward)场景下,一个请求可能被Filter处理多次。OncePerRequestFilter保证了无论请求经过多少次内部转发,过滤逻辑只执行一次,避免TraceId被重复覆盖。
第二,try/finally里的MDC.remove是绝对不能省的。Tomcat的工作线程是池化复用的,如果不清理,线程执行完上一个请求后,MDC里残留的TraceId会被下一个请求读到,导致日志串线。这种问题比没有TraceId更可怕,因为它会误导排查方向。
第三,把TraceId写进响应头。这个小动作很多人会忽略,但它在线上非常实用:前端拦截到接口报错时,把响应头里的X-Trace-Id透传给用户,用户反馈问题时报一个编号,后端拿到编号直接搜日志,根本不用再去问"你什么时候操作的、操作了什么"。
3.3 日志配置里如何声明TraceId
Filter只是把TraceId放进了MDC,真正要输出到日志文件里,还得改logback配置。我用的是logback-spring.xml,核心改动就在pattern里加一个%X{traceId}:
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%X{traceId}] [%thread] %logger{36} - %msg%n</pattern> <charset>UTF-8</charset> </encoder> </appender> <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <file>${LOG_PATH:-logs}/app.log</file> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>${LOG_PATH:-logs}/app.%d{yyyy-MM-dd}.log</fileNamePattern> <maxHistory>30</maxHistory> </rollingPolicy> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %level [%X{traceId}] [%thread] %logger{36} - %msg%n</pattern> <charset>UTF-8</charset> </encoder> </appender>如果你想兼容"取不到TraceId时也能看日志",%X{traceId}缺省时输出为空,不会报错。但这里有个建议:把%X{traceId}放在线程号之前、或者紧随其后的位置,并在可见性上跟其他信息区分。我用的格式是[traceId=%X{traceId}],日志里出现了就是[traceId=8f2c1a3e...],没出现就是[traceId=],一眼能看出哪些日志没有纳入链路体系。
改完配置后记得重启验证,不要只看配置文件。验证方法很简单:本地启动项目,请求任意一个接口,看控制台和日志文件里是否都出现了同一个traceId。
3.4 老项目接入的注意事项
如果你的项目是个运行了很久的老项目,接入这套改造时要额外注意三件事:
- 日志排查工具和告警平台:如果日志采集系统(如ELK)在采集时解析了日志字段,pattern变了之后可能需要同步调整采集规则,否则
traceId不会被索引成独立字段。 - 响应头规范:
X-Trace-Id这个Header名字尽量和公司其他服务对齐。如果团队已经有一个规范,优先按团队规范来,避免一个请求从A服务进来带的是X-Trace-Id,到B服务又变成traceId。 - 网关层覆盖:如果项目的流量入口是SpringCloud Gateway,它的Filter体系和Servlet Filter不同(基于WebFlux),需要在网关单独实现一套。后面第4节会讲。
老项目尤其不建议一上来就动所有日志框架依赖,先用Filter + 日志pattern这种方式做"无侵入接入",跑通后再逐步把TraceId透传到调用链路的各个环节。
4. 跨服务传递:让TraceId沿着调用链跑起来
单体应用内部串日志只是第一步。如果项目是微服务架构,A服务调B服务、B服务调C服务,每个服务各自生成新的TraceId,链路就断了。跨服务传递的核心思路是:按约定把当前TraceId塞进HTTP请求头,下游服务优先从头里取,取不到才自建。
4.1 HTTP请求头的约定
业界其实没有统一的Header标准,常见的叫法有X-Request-Id、X-Trace-Id、traceparent(W3C标准)等。如果是自研方案,我建议统一使用X-Trace-Id,简单直观,代码里也容易搜到。在日志配置里,Header名和MDC key要全局统一,不要一个服务叫这个、另一个服务叫那个。
4.2 在RestTemplate中透传
项目还在用RestTemplate的话,可以通过ClientHttpRequestInterceptor实现。拦截器在发出HTTP请求前,从当前线程的MDC里取出TraceId,再放到请求头里:
public class TraceIdClientInterceptor implements ClientHttpRequestInterceptor { @Override public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { String traceId = MDC.get(TraceIdFilter.MDC_KEY); if (traceId != null) { request.getHeaders().set(TraceIdFilter.TRACE_ID_HEADER, traceId); } return execution.execute(request, body); } }使用时注册到RestTemplate上:
@Bean public RestTemplate restTemplate() { RestTemplate template = new RestTemplate(); template.setInterceptors(List.of(new TraceIdClientInterceptor())); return template; }这里有个关键点:上游服务的filterChain.doFilter还没执行结束,MDC里的TraceId就一定还在。所以只要在同一个请求线程里发起调用,拦截器必然能拿到。真正要小心的场景是异步调用,这个我们在第5节单独讲。
4.3 在Feign中透传
Feign做服务间调用时,可以用RequestInterceptor:
@Bean public RequestInterceptor traceIdRequestInterceptor() { return template -> { String traceId = MDC.get(TraceIdFilter.MDC_KEY); if (traceId != null) { template.header(TraceIdFilter.TRACE_ID_HEADER, traceId); } }; }这个类放到Spring容器里即可,Feign发起的每个请求都会自动带上当前线程MDC里的TraceId。写完这个,用Feign调下游的服务日志就能串起来了。
4.4 网关(Gateway)层的处理
SpringCloud Gateway基于WebFlux,是响应式编程模型,ThreadLocal在这种模型下是不生效的。所以MDC方案不能直接套用到Gateway上。
一个简单方案:在Gateway的GlobalFilter里拿到请求的TraceId(没有则生成),放入exchange.getAttributes()中,再通过响应头透传给调用方。日志打印如果用的是响应式上下文,则需要用reactor.util.context.Context来传递TraceId。对于大多数只需要"下游服务拿到同一个TraceId"的场景,在GlobalFilter里做一个ServerWebExchange级别的TraceId传递就够了。
@Component public class TraceIdGatewayFilter implements GlobalFilter, Ordered { @Override public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) { String traceId = exchange.getRequest().getHeaders() .getFirst(TraceIdFilter.TRACE_ID_HEADER); if (!TraceIdGenerator.isValid(traceId)) { traceId = TraceIdGenerator.generate(); } // 放入exchange,后续转发时可取用 exchange.getAttributes().put(TraceIdFilter.MDC_KEY, traceId); // 给下游服务透传 ServerWebExchange mutatedExchange = exchange.mutate() .request(builder -> builder.header(TraceIdFilter.TRACE_ID_HEADER, traceId)) .build(); // 响应头也加上 mutatedExchange.getResponse().getHeaders() .set(TraceIdFilter.TRACE_ID_HEADER, traceId); return chain.filter(mutatedExchange); } @Override public int getOrder() { return -100; // 尽量靠前 } }注意这段代码只做了请求头透传,并没有把TraceId打印到Gateway自身的日志里。要在WebFlux日志里输出TraceId,需要结合reactor.util.context做MDC的适配,复杂度会上升不少。我的建议是:如果Gateway选型是SpringCloud Gateway,优先评估公司是否已有统一网关平台,或者借用已有的链路中间件能力,不要在响应式环境下手写MDC透传方案,维护成本高。
5. 异步与线程池:最容易丢TraceId的重灾区
5.1 一个典型的丢失现象
把Filter、Feign透传都做完之后,我一度以为事情已经结束了。结果没过多久,线上发现某条日志链路的TraceId出现了断层:前一半日志带traceId=abc,从某个线程开始,日志的traceId变成了空。
排查后发现,业务代码里用了@Async注解。主线程在处理请求时把TraceId放进了自己的MDC,但@Async方法由Spring的线程池另起一个线程执行,新线程没有主线程的MDC副本,自然打不出来。
这就是异步场景下TraceId丢失的根因:MDC绑定的是ThreadLocal,线程池复用的线程和请求线程不是同一个线程,MDC里的数据不会自动转移。
5.2 根因:ThreadLocal的传递边界
用一句话来说,线程池隔离了主线程和工作线程的变量表,主线程的ThreadLocal数据对工作线程是不可见的。你没法直接期待"新线程自动继承主线程的MDC",必须手动"播种"。
我见过不少团队的临时方案:在@Async方法内部第一行写MDC.put("traceId", xxx),但xxx从哪来?还是要从上游传下来。如果上游没有做任何传递,新线程永远拿不到。这就是为什么异步场景必须是"传递方案",不能靠"重新生成",重新生成的TraceId和主链路对不上。
5.3 两种主流修复方式
第一种,包装Runnable/Callable,在创建异步任务时把TraceId带进去。核心思路是:在主线程提交任务时,把MDC里的值快照出来,在任务执行前恢复,执行后清理。
public class TraceIdRunnableWrapper implements Runnable { private final Runnable delegate; private final String traceId; public TraceIdRunnableWrapper(Runnable delegate) { this.delegate = delegate; this.traceId = MDC.get(TraceIdFilter.MDC_KEY); } @Override public void run() { if (traceId != null) { MDC.put(TraceIdFilter.MDC_KEY, traceId); } try { delegate.run(); } finally { MDC.remove(TraceIdFilter.MDC_KEY); } } }使用的时候,把原来提交给线程池的Runnable包一层:
executorService.submit(new TraceIdRunnableWrapper(() -> { // 业务逻辑 }));第二种,实现Spring的TaskDecorator接口。这种方式对业务代码侵入更小,只需要在定义线程池时加一个装饰器:
@Bean("asyncExecutor") public Executor asyncExecutor() { ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor(); executor.setCorePoolSize(8); executor.setMaxPoolSize(16); executor.setQueueCapacity(200); executor.setThreadNamePrefix("async-"); executor.setTaskDecorator(runnable -> { Map<String, String> contextMap = MDC.getCopyOfContextMap(); return () -> { Map<String, String> previous = MDC.getCopyOfContextMap(); if (contextMap != null) { MDC.setContextMap(contextMap); } try { runnable.run(); } finally { if (previous != null) { MDC.setContextMap(previous); } else { MDC.clear(); } } }; }); executor.initialize(); return executor; }这段代码的核心就两个动作:提交任务前把主线程的MDC整个复制一份;任务执行时先恢复主线程的MDC,执行完再恢复现场。比单个key的包装更健壮,因为MDC里可能不止TraceId一个值,将来加UserId、SpanId时都一并传递了。
如果项目里大量依赖线程池和异步编程,还可以考虑引入阿里巴巴的TransmittableThreadLocal(TTL),它对ThreadLocal的传递做了更完善的支持,能兼容各种线程池场景。不过对大多数业务系统来说,TaskDecorator已经足够。
5.4 @Async场景的单独处理
如果你的项目在配置了TaskDecorator之后,@Async方法还是拿不到TraceId,记得检查两点:
@EnableAsync和线程池Bean的配置是否生效,SpringBoot下@Async默认使用SimpleAsyncTaskExecutor,它不是复用线程池,每次新建线程,当然也不会继承MDC——很多人以为配了线程池就生效了,其实Spring默认线程池根本没换。- 自定义线程池Bean名称是否是
applicationTaskExecutor或taskExecutor。如果线程池Bean名字不对,Spring还是用默认的。可以在@EnableAsync上显式指定@EnableAsync("asyncExecutor")。
我自己的项目中,解决@Async丢TraceId之后,还有一类隐蔽场景:Redis订阅、MQ消费者在消费消息时没有TraceId。消息队列不像HTTP请求,没有响应头可以透传。两块落地方案大概是:生产者在发送消息前从MDC取TraceId,塞进消息Header;消费者在接收消息时从Header取TraceId,塞进自己的MDC。Kafka的ProducerRecord、RocketMQ的Message都支持自定义Header,思路是同一个。
6. 从"能跑"到"用好":采样、耗时与排查示例
6.1 通过TraceId还原一次完整调用
前面几步做完,Logback里已经能稳定输出TraceId了。假设现在线上用户反馈"下单后积分没到账",运维或开发要做的操作就变得非常标准:
- 在统一响应结构中把TraceId返回给前端(或在网关响应头中带上)。
- 用户提供TraceId(比如
8f2c1a3e9d4b6c7a)。 - 用日志平台的搜索框输入
traceId=8f2c1a3e9d4b6c7a,看到整个链路的全部日志。 - 按时间正序排列,逐条阅读,标记出异常点。
我在实际排查中还发现一个很实用的技巧:每个Filter、中间件在链路入口处打印一条"请求开始"的日志,在出口处打印一条"请求结束"的日志,把这两条日志里的时间戳一减,就能快速算出整个请求的耗时。
long start = System.currentTimeMillis(); try { filterChain.doFilter(request, response); } finally { MDC.remove(MDC_KEY); long cost = System.currentTimeMillis() - start; log.info("请求结束,cost={}ms", cost); }同样的TraceId在入口和出口都打印一遍,耗时数据就天然挂在了链路上,不需要额外埋点。
6.2 采样率的取舍
日志里带上TraceId之后,数据量会上升,但要说大多少,其实取决于日志的体量。如果用ELK做日志采集,traceId作为字段被索引后,占用的磁盘空间和ES存储成本是要同步评估的。
一些高并发系统会做采样记录:比如只记录100%的ERROR日志,但INFO日志只采样10%。这样能在"保留问题定位能力"和"控制存储成本"之间做个平衡。我一般建议先从全量开始,跑一个月观察日志量,真的扛不住再逐步降采样。TraceId本身成本很低(32位字符串),真正占大头的是日志条数。
6.3 后续进阶方向
日志级TraceId跑通后,有几个自然的演进方向:
- 接入SkyWalking/Zipkin/Jaeger:它们提供的是分布式链路追踪的可视化看板,可以直接看到一次请求经过哪些服务、每个服务耗时多少。TraceId日志方案可以作为它的基础能力,二者不冲突。
- 在每个链路节点上补充SpanId:想做更细粒度的调用树分析时,需要额外生成SpanId和ParentSpanId,日志里同时输出。
- 规范异常日志链路:在所有异常打印的日志里,确保ERROR第一行就带TraceId,方便监控系统直接按TraceId聚合。
我个人经验是:如果团队连日志级TraceId都没有,不要直接跳到引入SkyWalking,先把基础日志串起来。因为链路追踪平台虽然强大,但日常排障时大家最常用最习惯的仍然是"搜索同一段时间的日志",这一点日志级TraceId能解决90%的问题。
7. 落地半年后的几点心得体会
这套方案从最初的一个TraceIdFilter加日志pattern,到后来逐步补齐Feign透传、线程池装饰、MQ消息透传、Gateway适配,前后迭代了好几轮。一些很细节的教训值得分享。
一个典型的坑是Filter的顺序问题。如果你的项目里有多个Filter(比如用户认证Filter、灰度Filter),TraceIdFilter要尽量放在最前面。否则用户认证Filter先执行并打了日志,TraceId还没放进去,这部分日志会丢失。在SpringBoot里可以通过FilterRegistrationBean的setOrder控制:
@Bean public FilterRegistrationBean<TraceIdFilter> traceIdFilterRegistration(TraceIdFilter filter) { FilterRegistrationBean<TraceIdFilter> registration = new FilterRegistrationBean<>(filter); registration.addUrlPatterns("/*"); registration.setOrder(Ordered.HIGHEST_PRECEDENCE); registration.setName("traceIdFilter"); return registration; }第二个坑是删除日志中的[traceId=]空值。有些日志平台会为空字段折腾你,你可以用logback的DefaultIfEmpty变量默认值来规避,比如[traceId=%X{traceId:-}],这样没值的时候就输出一个横线,至少在视觉上能明确区分。
第三个坑是压测时的性能影响。MDC的get/put本身性能损耗极低,UUID生成一秒钟可以生成几百万个,完全不用担心。真正影响性能的点是异步线程池里MDC.getCopyOfContextMap()做了Map复制,但只要不是每个业务操作都复制一次,影响可忽略不计。
如果非要给一个建议,那就是:把TraceId当成项目的"日志标配"来对待,而不是"排障工具"。一旦所有的日志输出都天然携带TraceId,你就不需要再加任何思维负担,任何时候拿一个ID就能把整个请求的前因后果拉出来。我落地这套方案后,团队线上排障的平均用时从小时级降到了分钟级,这是最实打实的收益。