
全链路日志排障这件事早做早省命。你一定经历过这种场景线上一个接口偶发超时报障群里的消息炸了你登录服务器翻日志结果发现这个请求在入口服务打了一条日志在订单服务打了两条在支付回调又打了几条日志倒是都打了可你根本没法把它们串在一起。你只能靠时间戳估靠关键词猜靠多台机器来回切运气好十分钟定位运气不好半小时起步而每次排查的时候客户的电话还在催。后来我在SpringBoot项目里引入了TraceId日志追踪机制这个问题算是从根上解决了。今天就把这套方案的原理、代码、坑一次性讲透。TraceId做的事情一句话就能说清每次业务请求进来时生成或透传一个全局唯一的ID这个ID随请求一直往下游传递同时每一行日志都把它输出出来。这样出了任何问题只需拿这个ID在日志平台里一搜散落在各个服务、各个实例上的日志全部自动归拢成一条时间线不用再靠肉眼和玄学排障。这套方案适合谁已经做了微服务拆分、日志分散在多个应用里的SpringBoot项目不想花大力气引入昂贵复杂的链路追踪系统想用最低成本解决“日志能搜但串不起来”的团队以及正准备做日志规范想顺手把追踪基础打好的同学。它不需要额外部署独立平台不依赖具体中间件核心代码量两三百行看完这篇文章你就能直接抄进项目里。1. 先想清楚TraceId到底解决了什么问题1.1 没有TraceId时排查日志的真实痛点我给你还原一个特别典型的场景。某订单系统用户反馈“下单后偶尔收不到回调通知”。你去查日志入口网关服务里有一条“下单请求收到”订单服务里有一条“创建订单成功”支付服务里有一条“支付回调处理中”仓库服务里有一条“库存扣减失败”。这些日志分布在四台机器上时间戳从下午3点31分24秒到3点31分26秒。你怎么确定它们属于同一次请求你不会确定的你只能反复确认那个时间窗口里没有其他类似请求然后赌一把。这种情况在低并发系统里还能忍一旦请求量上来同一个接口同一秒可能有几十次调用时间戳完全线性重叠你再也没法靠“碰巧时间对得上”来定位了。另一个痛点是跨服务调用发生时中间只要有一次超时重试整个日志时序就会错乱你看到的是A服务调B服务超时了但B服务的日志上根本看不到这次失败的调用——因为B服务压根就没进到业务方法就超时返回了。没有TraceId这类问题就是死局。还有一类问题更阴间用户报障时只提供一个模糊的订单号可订单号在入口日志里根本不是检索字段你得先找到这个订单对应的接口请求长什么样再顺着时间反查运气成分极高。1.2 TraceId背后的链路追踪思想正经的链路追踪系统核心就是围绕全局唯一ID做“上下文传递”。一个完整的调用链上第一个服务生成一个全局唯一的ID叫TraceId链路ID用来标识一整条调用链每经过一次服务调用还会生成一个SpanId spans段ID标识当前这一段调用同时带一个ParentId指向调用来源的Span。有的系统还要上传耗时、状态、业务标签等数据最终汇聚成一张因果树。但在日志追踪这个诉求上很多人忽略了一点你根本不需要把那一整套重量级模型搬进来只需要把最核心的TraceId用起来就已经能解决80%的日志串不起来问题。Span信息可以用“服务名方法名耗时”的形式在日志自然文本里输出连结构化的都省了。你只要保证所有服务、所有线程、所有中间件透传的过程中TraceId不断、不乱、不重整条日志链就是完整的。我见过有些团队一上来就上一套完整的APM系统反而因为链路数据量太大、存储成本高、页面复杂没人愿意看最后变成了一个“假装在监控”的摆设。而基于MDC打TraceId的方案轻巧直接每台机器上的日志原本就留着只是多了一列索引字段所有现有日志分析手段照常可用成本几乎为零。1.3 为什么我选MDC而不是自己写ThreadLocal在SpringBoot里往日志里塞TraceId正统做法是利用日志框架SLF4J自带的MDC机制。MDC全称是Mapped Diagnostic Context映射诊断上下文它本质上就是当前线程上的一个ThreadLocal只不过ThreadLocal里存的不是单个值而是一个Map。你可以在任何时刻往这个Map里put键值对然后在日志pattern里用%X{traceId}把这个值取出来输出到每一行日志。为什么不自己写ThreadLocal原因很现实第一日志输出是在Logback内部发生的你没法在自己代码里把值传进logger.info()的调用栈里必须在日志框架的渲染环节拿到值MDC是日志框架原生支持的取数入口自己写ThreadLocal还得想办法和Logback沟通平白增加复杂度第二MDC天然支持父子线程上下文快照就算某些场景出现线程切换它也有标准扩展方案第三MDC是SLF4J层面的能力无论底层绑定的是Logback还是Log4j2全都通用未来切换日志库不伤筋骨。2. 搭好基础日志模板改造与TraceId生成策略2.1 先把Logback的pattern改了TraceId要输出到每一行日志关键就在logback.xml里的日志输出格式。以Logback为例原来常见的日志pattern大概是这样pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n/pattern把TraceId加上去之后变成这样pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} [%X{traceId:-}] - %msg%n/pattern这里面%X{traceId:-}的意思是从MDC里取key为traceId的值输出如果没有值就用空字符串填充。注意这个:-很重要我曾经见过有同事图省事直接写[%X{traceId}]结果在没经过过滤器的日志——比如启动日志、定时任务日志、系统内部日志——里面输出了一堆[null]看着特别刺眼而且在日志平台上想用空白筛选都困难。改完pattern后记得先在本机跑一个接口验证一下保证每一行打出来的日志确实带着traceId。这里有个小细节很多人会问TraceId放到日志的什么位置比较好我的建议是紧跟在线程名后面因为日志排障时第一眼关注的就是时间和线程traceId放在这个视觉层级扫日志时非常自然。当然也有人喜欢放到最后这个看团队偏好关键是全公司统一。2.2 生成TraceId的方式别无脑UUID接下来面临一个选型问题TraceId用什么样的ID生成策略我见过不少项目直接拿UUID.randomUUID()短平快。但在真实追踪场景里一个纯随机UUID对排障是不友好的原因你搜日志时感受最深一堆ID甩在你脸上你根本分辨不出哪个是哪个只能机械地一条条比对。好的TraceId至少要包含三个信息时间、来源标识、随机因子。我在项目里用的是这样一套组合逻辑高位取当前毫秒级时间戳的36进制表示中间拼一个服务实例标识从配置中心下发或本机IP加端口算出来低位用该进程内自增序列加随机数填充。这样生成的ID长下面这个风格含时间因子格式示例L1I7X3N9-1A2B3C4D-7F3E9A2B这个格式有几个实打实的好处。第一排障时你拿ID就能看出这个请求大概发生在几点几分在日志平台里先凭时间因子圈定范围再全词匹配检索速度更快。第二进程内并发量大的时候即使随机数部分碰撞时间戳实例标识也能保证全局不太容易重复。第三实例标识能定位到具体哪台机器处理了这个请求这对分布式环境里“负载均衡绕圈”的问题有奇效。当然你也没必要自己造轮子市面上很多框架内置了类似的ID生成器比如雪花算法的变体直接调就行。还有一点必须强调TraceId是有长度控制的。如果你塞一个64位的UUID进日志一行日志被拉得老长本地console看着难受不说日志平台存储也会膨胀。我一般把TraceId限制在32到40个字符之间既能承载足够信息又不会影响日志可读性。2.3 哪些日志不该带TraceId这个问题经常被忽略。TraceId是为“请求处理链路”服务的但项目里不是所有日志都属于请求链路。启动日志、定时任务日志、MQ消费者拉取消息但还没进入具体业务处理的日志、健康检查探活日志这些场景如果强行带TraceId反而会产生垃圾数据——它们没有上游也没有下游每个任务打的TraceId都是孤岛排障时只会干扰视线。我的处理方式是只有通过HTTP入口或MQ消息入口进入业务处理时才会注入TraceId系统级日志保持原样不带这样日志里带TraceId的一定是业务请求链路语义干净筛检高效。3. 实操从请求入口到线程池的完整链路打通3.1 入口过滤器生成、透传、清理一步到位SpringBoot里注入一次请求级别的上下文最合适的组件是OncePerRequestFilter。为什么不直接实现Filter接口因为Servlet规范里的Filter在请求发生转发forward时有可能会被再次执行一旦重复执行TraceId就可能被二次生成或二次put标准成熟的做法就是继承Spring提供的这个基类保证一次请求只执行一次过滤器逻辑。核心代码如下Component public class TraceIdFilter extends OncePerRequestFilter { public static final String TRACE_ID_HEADER X-Trace-Id; public static final String TRACE_ID_MDC_KEY traceId; Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { try { String traceId request.getHeader(TRACE_ID_HEADER); if (StringUtils.isBlank(traceId)) { traceId TraceIdGenerator.generate(); } MDC.put(TRACE_ID_MDC_KEY, traceId); response.setHeader(TRACE_ID_HEADER, traceId); filterChain.doFilter(request, response); } finally { MDC.remove(TRACE_ID_MDC_KEY); } } }这里头有几个设计细节说清楚。第一如果请求头里带着上游传过来的TraceId你必须直接复用不能自己再生成一个否则整条链路就断了。第二把traceId写到响应头里这是给调用方和前端看的联调时抓个包一看就知道自己是走的那条链路。第三finally里必须MDC.remove这一点极其重要我们后面讲坑的时候会重点展开。另外如果你用的是SpringMVC且希望Controller层也能拿到traceId不需要额外处理因为过滤器执行在Controller之前同一个线程内MDC直接可见在Controller里加一行MDC.get(traceId)就能拿到。3.2 微服务之间怎么把TraceId传下去现在一个请求进来了TraceId在A服务里正常打着可是A服务调用B服务的时候如果不用特殊手段B服务那边是拿不到这个TraceId的。原因也很直白HTTP请求头是服务之间传参的唯一桥梁MDC再神奇也只活在当前进程当前线程里跨服务传递必须显式做。如果你的服务间调用用的是RestTemplate写一个ClientHttpRequestInterceptorpublic class TraceIdRestTemplateInterceptor implements ClientHttpRequestInterceptor { Override public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { String traceId MDC.get(TraceIdFilter.TRACE_ID_MDC_KEY); if (traceId ! null) { request.getHeaders().set(TraceIdFilter.TRACE_ID_HEADER, traceId); } return execution.execute(request, body); } }然后把拦截器挂到RestTemplate上Bean public RestTemplate restTemplate() { RestTemplate restTemplate new RestTemplate(); restTemplate.setInterceptors(Collections.singletonList(new TraceIdRestTemplateInterceptor())); return restTemplate; }如果你用的是Feign那就更简单了用一个RequestInterceptor在请求发出前从MDC取traceId塞进headerBean public RequestInterceptor traceIdFeignInterceptor() { return template - { String traceId MDC.get(TraceIdFilter.TRACE_ID_MDC_KEY); if (traceId ! null) { template.header(TraceIdFilter.TRACE_ID_HEADER, traceId); } }; }这套逻辑的本质是“上游从MDC取塞进HTTP头下游从HTTP头取塞进自己的MDC”。每经过一跳这个动作重复一次链路就自动延续下去了。注意路由网关层也需要处理透传不管是Spring Cloud Gateway还是自研网关都要在转发前从请求头里取出TraceId继续set到转发请求头上千万别在网关层又重新生成一个。3.3 线程池和异步任务里的TraceId丢失怎么破这是一个极容易踩坑的地方也是这套方案里技术含量最高的一环。前面说了MDC依赖ThreadLocal那一切线程切换的场景都得特殊处理。项目里最常见的场景有三个Async异步方法、ThreadPoolTaskExecutor线程池、MQ消费线程池。这些场景下子线程里MDC是空的你打出来的日志就没有traceId整条链路在这里就断了。先说ThreadPoolTaskExecutor给TaskDecorator的解法。Spring的ThreadPoolTaskExecutor支持给每个任务包一层装饰器在任务执行前把主线程的MDC内容拷贝进子线程执行完再清理掉Bean(traceIdThreadPoolTaskExecutor) public ThreadPoolTaskExecutor traceIdThreadPoolTaskExecutor() { ThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); executor.setCorePoolSize(8); executor.setMaxPoolSize(16); executor.setQueueCapacity(1024); executor.setThreadNamePrefix(trace-id-exec-); executor.setTaskDecorator(runnable - { MapString, String contextMap MDC.getCopyOfContextMap(); return () - { if (contextMap ! null) { MDC.setContextMap(contextMap); } try { runnable.run(); } finally { MDC.clear(); } }; }); executor.initialize(); return executor; }getCopyOfContextMap()是MDC提供的一个特殊API它能把你当前线程MDC里的所有键值对拷贝成一个快照而不是引用——这样就避免了子线程和主线程之间共享可变对象导致数据互相污染。这段代码建议你直接抄项目里所有线程池只要换成这个traceIdThreadPoolTaskExecutor异步日志就自动带traceId了。Async的解法思路一致在自定义的AsyncConfigurer里给ThreadPoolTaskExecutor同样配置TaskDecorator就能覆盖所有通过Async启动的任务。至于MQ消费者你在消费消息时人为把消息头里的traceId解析出来put到MDC里再进入业务处理流程就完事了。注意一点线程池里千万记得“用完即还原”。上面的装饰器里用的是finally { MDC.clear(); }清掉的是这个子线程本次跑业务时放进去的内容不会影响主线程的上下文。如果你图省事只put不清理线程池里的线程又是复用的下一个任务看到一个残留的traceId直接把两条不相干的业务日志串到一条链路上了问题排障时能被你带到沟里去。3.4 响应头里回传TraceId联调体验直接提升通过上面的过滤器我们已经在响应头里设置了X-Trace-Id。这个设计在联调阶段有奇效。前端说“我调你接口报错了”以前你得问“哪个接口什么时间请求体给我一下”现在你只需要说“浏览器F12打开Network看那个接口的Response Headers里X-Trace-Id是什么”截图一发你拿这个ID去日志平台一搜整个处理过程一目了然。这个头跨域时有一个坑如果你的前端是独立域名调接口比如前端在www.a.com调后端api.b.com后端设置了Access-Control-Allow-Origin但浏览器默认只能让页面读到一部分简单响应头自定义的X-Trace-Id头是不在默认暴露范围内的。你需要额外配置CORS把这个响应头暴露出去Component public class CorsFilter implements Filter { Override public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain) throws IOException, ServletException { HttpServletResponse response (HttpServletResponse) res; response.setHeader(Access-Control-Allow-Origin, *); response.setHeader(Access-Control-Allow-Methods, GET, POST, PUT, DELETE, OPTIONS); response.setHeader(Access-Control-Allow-Headers, X-Trace-Id, Content-Type); response.setHeader(Access-Control-Expose-Headers, X-Trace-Id); chain.doFilter(req, res); } }关键是Access-Control-Expose-Headers这一行不加它前端js拿不到响应头里的TraceId就只能靠接口返回体里的冗余字段了。4. 踩过的坑性能、误用与排查实录4.1 线程复用引发的MDC串号事故这个坑我记忆太深刻了。有段时间业务同事反馈日志里出现了完全无法理解的traceId一次下单请求的日志里traceId变了三次而且其中一段日志明显属于另一个订单。查了两天才定位到根因某业务代码里用了共享的线程池但没配TaskDecorator子线程从线程池拿出来时残留了上一个任务放进去的traceId业务代码又没有覆盖于是一条请求的日志里就混进了别人的ID。从那次之后我定了一条团队铁律任何情况下异步任务执行前必须重新设值执行完必须清理。4.2 网关层重新生成TraceId导致全链路断链另一个高频事故发生在网关。自研网关的话核心逻辑很简单从header里取取不到再生成。但Spring Cloud Gateway这种响应式框架默认的过滤器链路和传统Servlet过滤器长得不一样很多人在网关里图省事直接新生成一个ID塞进转发请求到了下游服务整条链路的traceId就和上游对不上了。这个问题的典型表现是网关日志里一个traceId业务服务日志里另一个traceId你搜网关的traceId只能搜到网关那几条业务服务里的日志全成了孤儿。排查思路也很简单用一条测试请求把网关日志和业务服务日志全拉出来对比两边的traceId是否一致不一致就看网关转发逻辑里有没有遭遇“取header”这一步。4.3 Header大小写与网络框架的兼容问题HTTP头部字段名按规范是不区分大小写的但某些HTTP客户端框架在底层实现时对header读写的大小写处理并不完全一致。我们曾经碰到过一个问题A服务用OkHttp发请求设置的header key是x-trace-id全小写B服务用Tomcat接收后request.getHeader(X-Trace-Id)居然取不到值因为Tomcat在某些版本的解析里对header的索引是精确匹配的。后来统一约定所有服务里header的key固定为X-Trace-Id只允许用这一个大小写写法彻底规避了这个坑。4.4 TraceId到底有没有性能开销这是每次给团队讲这套方案时必然被问到的问题。我直接给出结论日志系统里加一个traceId字段性能开销小到可以忽略。核心的开销分摊在三个地方ID生成、MDC写入、日志多打印一串字符。ID生成用雪花算法或变体单机每秒百万级别的生成毫无压力MDC写入本质是一次ThreadLocal Map的put操作纳秒级日志多输出几十个字符IO开销对吞吐量的影响基本可以忽略。真正需要警惕的不是TraceId本身而是你在日志pattern里加的冗余计算比如%X{traceId:-}里的MDC取值如果每行日志都企取一次高并发下频繁的ThreadLocal访问确实会有细微开销所以pattern里取一次就好别画蛇添足。我自己做过一个对比实验一个简单的查询接口平均耗时约30ms QPS大概500加上TraceId之后平均耗时30.2msQPS略有波动但基本持平。所以完全不用因为性能焦虑而犹豫。4.5 日志平台的TraceId查询技巧ID生成之后怎么在日志平台里用好它同样重要。我建议把TraceId作为日志的一个独立字段上报而不是只混在message文本里这样在Elasticsearch或类似平台里就能直接对traceId字段建索引查询时秒出。如果在文本里查日志量大了会慢得多。具体做法是日志里用keyvalue的格式输出traceIdL1I7X3N9-1A2B3C4D-7F3E9A2B采集端解析出来后自动提取字段。这个习惯越早规范越好因为后面日志量上来再改格式历史数据就得重新洗了。5. 一套可落地的扩展TraceId还能用来干这些事5.1 把TraceId变成“会话回放”的检索键当你的所有服务日志都带上了TraceId之后可以做一件很好用的事按TraceId做一次全链路日志回放。不依赖任何APM系统你在日志平台里输入一个TraceId把所有命中的日志按时间排序就是那次请求从头到尾的完整时间线GPU。我排查线上问题时最常用的方式登录日志平台搜TraceId然后从第一条日志读到最后一条整个请求的走向、每一步耗时、在哪一步异常一目了然。我甚至可以在回复群里时直接贴一条日志全文让同事自己看比在聊天里文字描述高效太多。5.2 把TraceId埋进数据库和中间件有时候问题出在数据库层或消息队列里服务日志里看不出端倪。比如一条数据被覆盖了你需要确认是哪次请求干的。如果只在应用日志里埋了TraceId数据库里查不到就追踪不到根因。现在的做法是业务表里增加一个trace_id字段写操作执行时把当前MDC里的traceId一并写入中间件消费消息时把消息体里带上的TraceId继续往下游传。这样从数据库操作日志到消息投递记录再到下游消费日志整条链路全部串通哪儿出了差错拿着一个ID就能查穿全链路。代价只是多存了三十几个字符但这种“一次请求全链路留痕”的收益做过的团队都懂。5.3 预留升级到完整链路追踪系统的能力最后聊一个长线话题。有些团队以后发展壮大了可能想正式引入商业级APM上全链路可视化平台。那时你会发现今天做的这套TraceId埋点并不是白做它天然兼容链路追踪的全局链路ID概念。很多开源链路追踪系统的ID下发格式和你现在生成的TraceId格式可以统一共用上报时直接把现有TraceId映射成链路ID即可应用层代码不用返工。这就是我在设计ID生成策略时不随便拼个UUID的原因眼光稍微放远一点现在的几百行代码能成为未来整个可观测性体系的地基。结尾一些个人经验最后分享一点我的体会。在真正把TraceId落地之前我一直以为日志排障的痛点在于日志打得太少信息不够。做了这套方案之后才明白大部分排查慢的根源是日志之间没有关联键。加了一个TraceId做的事情不是变多而是让每一条日志都找到了它所属的那次请求从此排障从“大海捞针”变成“按图索骥”。顺便说个实用技巧生产环境的服务日志一定要把traceId排在整行日志比较靠前的位置方便人肉扫的时候不离焦也方便日志平台切分字段。这个细节看着小在日志量爆炸的时候就是救命稻草。