说实话干后端这几年最怕的就是半夜收到一条告警“订单接口报错了你查一下。”真要命的地方不是报错本身而是你打开日志平台后发现一个请求要经历网关、鉴权、订单、支付、异步回调好几台机器、几十个服务而你手上只有一句“用户说下单失败”。这种时候如果日志里没有TraceId排查效率基本靠“猜”先猜哪台机器出了问题再猜是哪一段服务挂掉最后猜是不是缓存、数据库、还是网络抖了一下。运气好十分钟定位运气差折腾一宿。这篇文章不聊高大上的链路追踪只聊一个特别朴素但极其提效的动作把TraceId用好。具体包括几块内容TraceId怎么生成、怎么在服务之间传递、怎么打进日志以及拿到一条形如6aa2526590ad07346b76e2b8d8d80384的ID之后怎么在Elasticsearch里把这次请求对应的完整SQL日志捞出来。这套东西没有太多新概念很多团队其实只差最后几步没做透。把这些步骤补齐以后你会发现日志排查从原来的“考古现场”变成了复制粘贴几个字就能解决的问题。1. 没有TraceId的日子日志排查到底有多痛1.1 日志像积木TraceId是拼图编号先描述一个典型场景。用户在前端点了个“提交订单”后端实际发生的事可能是Nginx接入、网关路由、鉴权服务校验token、订单服务创建订单、库存服务冻结库存、支付服务生成支付单、MQ异步通知最后可能还有定时任务对账。整个过程涉及七八个服务、二三十个日志文件。没有TraceId的时候日志记录长这样2025-01-05 14:23:01.012 INFO [http-nio-8080-exec-4] OrderServiceImpl: 创建订单成功orderId10086 2025-01-05 14:23:01.345 INFO [http-nio-8080-exec-7] InventoryClient: 调用库存服务成功单看这两行日志你完全不知道它们是不是同一次用户请求产生的。同一个用户连续下单两次第二次的日志可能会混进来看起来逻辑通顺实际上根本对不上号。你说“查一下这个用户的日志”结果搜索用户ID搜出来一屏内容还得靠时间戳、线程名、机器名去人工拼接这个过程费时费力还特别容易看错。给日志加上TraceId以后每个请求在最入口处拿到一个全局唯一的编号比如6aa2526590ad07346b76e2b8d8d80384然后这个编号跟着请求走完所有服务、所有线程、所有SQL查询。日志里记录的内容就变成这样traceId6aa2526590ad07346b76e2b8d8d80384 创建订单成功orderId10086 traceId6aa2526590ad07346b76e2b8d8d80384 调用库存服务成功一眼就能看出这两条日志属于同一次请求。排查的时候不再依赖“猜”而是直接拿TraceId去日志平台搜所有相关日志一股脑全出来。1.2 有TraceId和无TraceId的排查速度对比我做了一个比较直观的对比大家感受一下排查环节没有TraceId有TraceId定位入口机器挨个节点翻看日志或者靠负载均衡的访问日志推测直接全局搜索TraceId秒出结果判断请求调了哪些服务人工从链路顺序猜漏一个就偏了日志里同一个TraceId自动聚合查看SQL执行记录需要用时间戳和线程ID拼凑SQL日志带上TraceId后直接连业务日志一起查排查耗时少则十分钟多则几小时一般一分钟以内多人协作排查各有各的截图对不上报一个ID大家各自搜结果完全一致个人体会是TraceId带来的最大价值不是技术炫技而是让“日志”从一个只用来事后看的信息集合变成一条真正可追溯、可还原请求全过程的证据链。1.3 TraceId和分布式链路追踪是什么关系有人可能会问现在不是有SkyWalking、Jaeger、Zipkin这类链路追踪系统吗直接用它们不就行了为什么还要自己在日志里搞TraceId链路追踪工具确实能展示服务之间的调用关系但它们的定位是“拓扑视图”。比如它能看到请求从订单服务调用了库存服务耗时多少但如果你要问“这次请求里订单表到底执行了哪几条SQL、请求参数是什么、报错堆栈里的上下文变量是什么”这些信息仍然要靠日志系统来看。TraceId在日志系统里是最基础、最通用的关联键。链路追踪工具的TraceId和日志里的TraceId如果能打通那是最好的状态即使暂时不打通先把日志系统里的TraceId用起来收益也非常大。而且纯日志TraceId方案侵入性小、改造成本低适合绝大多数还没上全链路监控的团队快速提升排查效率。2. 先定好生成与传递规则TraceId才能一路跑到底2.1 生成规则不是随便拿个UUID就行TraceId的生成规则第一要求是全局唯一第二是尽可能短第三是最好能包含一些可读信息方便排错时肉眼判断。最常见的做法是直接拿UUID去掉横线生成一个32位十六进制字符串。Java里一行代码搞定public static String generateTraceId() { return UUID.randomUUID().toString().replace(-, ).toLowerCase(); }为什么不直接用带横线的UUID因为日志里已经有大量中划线、冒号、空格TraceId如果再带横线在Kibana里做字段检索时容易出边界问题也容易在复制时漏掉折行。32位纯小写十六进制字符比较干净检索效率也不错。如果服务规模比较大、调用量很高还可以在TraceId里编码时间信息比如“毫秒时间戳 机器序列 自增序号”。这种方式的好处是能从ID上直接看出大概的请求时间但实现复杂度会高一点。对绝大多数场景UUID方案足够了唯一要提醒的是生成之后统一转小写避免不同服务实现时出现大小写混用导致同一个ID在前端页面上显示两套。生成的位置也要想清楚。正确的做法是在最外层入口生成例如API网关或者第一个被请求的服务下游服务一律透传不重新生成。否则一个请求每过一个服务就换一个ID串成全链路就无从谈起。2.2 传递规则Header、RPC、MQ都要照顾到TraceId要跨服务传递HTTP场景一般是放在请求Header里。我习惯用X-Trace-Id这个自定义Header也可以根据公司规范叫traceparent或者X-Request-Id关键是全团队统一。需要覆盖的传递链路包括三类HTTP调用Feign、RestTemplate、OkHttp、WebClient等都需要在发请求时把当前TraceId塞进Header。RPC调用Dubbo、gRPC、Thrift等框架都有隐式传参或attachment机制把TraceId作为附加参数传递。MQ消息Kafka、RocketMQ、RabbitMQ发布消息时把TraceId放进消息头消费时再取出来放进MDC。这里还涉及一个细节如果有Nginx代理需要确认自定义Header透传。Nginx默认对下划线开头的Header支持不好所以Header名字最好用横线而不是下划线例如用X-Trace-Id别用X_Trace_Id。如果名字已经定了下划线还得在Nginx里配置underscores_in_headers on;不然请求到后端时TraceId会被丢掉。2.3 打印进日志MDC是Java侧的标准答案跨服务传递解决的是“TraceId跟着请求走”而要把TraceId输出到日志里Java侧最标准的做法是使用MDC。MDC全称是Mapped Diagnostic Context直译过来是“映射诊断上下文”。本质上它就是一个线程私有的Map日志框架在输出日志时会自动把MDC里的字段带进pattern。你可以把它理解成“挂在当前线程上的一个小黑板”上面写什么当前线程打印出的日志就能显示什么。Logback的pattern配置里加上%X{traceId}即可pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} [%X{traceId}] - %msg%n/pattern这个配置加在需要输出TraceId的appender里。通常建议在Root logger级别配一次避免每个业务logger单独配。MyBatis的mapper logger也要确认走的是同一个root配置否则SQL日志上就没有TraceId。使用MDC的核心动作是入口处MDC.put(traceId, traceId)出口处MDC.remove(traceId)。有put必须有remove这一点非常关键后面我会专门讲为什么。3. 实战落地从Spring Boot到SQL日志完整串起来3.1 入口Filter统一接管TraceId的生成与透传在Spring Boot项目里处理TraceId最好的位置是Filter而不是Interceptor或者AOP。原因很简单Filter是Servlet规范里最靠前的组件在请求进入Controller之前就执行可以覆盖静态资源、全局异常处理等场景。而Interceptor依赖Spring MVC一些请求可能根本走不到Interceptor就被拦下了。写一个最核心的Filter用OncePerRequestFilter保证一次请求只执行一次Component public class TraceIdFilter extends OncePerRequestFilter { private static final String TRACE_ID_HEADER X-Trace-Id; private static final String TRACE_ID_MDC_KEY traceId; private static final Pattern TRACE_ID_PATTERN Pattern.compile([0-9a-f]{32}); Override protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { String traceId request.getHeader(TRACE_ID_HEADER); if (traceId null || !TRACE_ID_PATTERN.matcher(traceId).matches()) { traceId generateTraceId(); } MDC.put(TRACE_ID_MDC_KEY, traceId); // 顺手写回响应头方便前端排查时直接拿ID response.setHeader(TRACE_ID_HEADER, traceId); try { filterChain.doFilter(request, response); } finally { MDC.remove(TRACE_ID_MDC_KEY); } } }这段代码里有几个细节值得注意。第一对传入的TraceId要做合法性校验防止外部传一个超长字符串或者非法字符进来把日志格式拖垮。第二finally里用remove而不是clear因为当前线程可能还有其它MDC字段比如用户ID、租户ID全清掉会影响后续逻辑。第三响应头里回写TraceId前端工程师拿着这个ID就能反馈给后端排查效率更高。3.2 HTTP调用透传Feign和RestTemplate拦截器Filter解决了“请求进来”的TraceId问题但服务调用下游服务时需要把TraceId放进Header。用Feign的话加一个RequestInterceptorConfiguration public class FeignTraceConfig { Bean public RequestInterceptor traceIdRequestInterceptor() { return template - { String traceId MDC.get(traceId); if (traceId ! null) { template.header(X-Trace-Id, traceId); } }; } }用RestTemplate的话加一个ClientHttpRequestInterceptorpublic class TraceIdClientInterceptor implements ClientHttpRequestInterceptor { Override public ClientHttpRequestInterceptor withRequestInterceptor(...) { return null; } Override public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { String traceId MDC.get(traceId); if (traceId ! null) { request.getHeaders().add(X-Trace-Id, traceId); } return execution.execute(request, body); } }这里最容易忽略的是时间点。拦截器执行时当前线程的MDC里必须还有TraceId。如果你在业务代码里提前手动清掉了MDC或者使用了异步线程池而没有做上下文复制Header就会丢。所以尽量在入口Filter统一维护MDC生命周期业务代码不要随意改MDC内容。3.3 线程池与异步场景别让TraceId断在半路前面提到的MDC是基于线程的一旦把任务丢给线程池执行子线程的MDC是空的。最典型的问题是业务代码里用CompletableFuture.runAsync()异步写一条日志结果这条日志没有TraceId全链路在这里断掉。方案是在提交任务时复制一次MDC上下文。可以封装一个Runnablepublic class MdcRunnable implements Runnable { private final Runnable delegate; private final MapString, String contextMap; public MdcRunnable(Runnable delegate) { this.delegate delegate; this.contextMap MDC.getCopyOfContextMap(); } Override public void run() { if (contextMap ! null) { MDC.setContextMap(contextMap); } try { delegate.run(); } finally { MDC.clear(); } } }使用的时候把原来的任务包一层executor.submit(new MdcRunnable(() - { // 这里是子线程执行日志也能带上TraceId }));如果项目里大量使用线程池更推荐在创建线程池时设置TaskDecoratorSpring的ThreadPoolTaskExecutor支持这个扩展点配置一次整个线程池所有任务都自动复制MDCThreadPoolTaskExecutor executor new ThreadPoolTaskExecutor(); executor.setTaskDecorator(MdcTaskDecorator::new);同理Spring的Async异步方法也可以通过自定义TaskDecorator统一解决。这里踩过一次坑之后你会发现只要异步入口没有包一层排查异步业务就只能靠猜。加了这个处理子线程的SQL日志也都能带上同一个TraceId。3.4 SQL日志怎么带上TraceId前面说了MyBatis日志走的是Logback配置如果根Logger的pattern里已经加上了%X{traceId}那么MyBatis打印的SQL日志自然也会带上。前提是mapper对应的包在Logback里没有单独覆盖了格式。实际中我遇到过一种情况业务日志里TraceId都有但SQL日志里没有。查到最后发现是有人把mapper包的logger单独配置了pattern覆盖了根配置里的%X{traceId}。这种问题不太显眼但影响很大。排查的时候先把配置翻一翻确认MyBatis的日志输出有没有单独指定appender或者pattern。如果用的是JDBC日志也就是jdbc:mysql之类的数据源底层打印SQL的logger是jdbc.sqlonly、jdbc.sqltiming这些同样要保证这些logger的pattern包含TraceId。很多团队在SQL看不到TraceId时第一反应是采集问题其实就卡在logger配置上。4. 接入ELK后用一条TraceId查出完整SQL日志4.1 日志格式改造从文本变成JSON省掉grok的麻烦日志要从多个服务、多台机器汇总到Elasticsearch最常用的链路是Filebeat采集日志文件发到Logstash解析再写入ES。如果是文本日志Logstash里需要写grok正则去解析traceId一旦业务日志格式稍微变动grok匹配失败字段就丢了非常脆。省心的做法是把日志输出成JSON格式。Java项目在Logback里引入logstash-logback-encoderdependency groupIdnet.logstash.logback/groupId artifactIdlogstash-logback-encoder/artifactId version7.4/version /dependency然后配置输出JSON格式的appenderappender nameJSON_FILE classch.qos.logback.core.rolling.RollingFileAppender file/data/logs/app/app.json.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePattern/data/logs/app/app.json.log.%d{yyyy-MM-dd}/fileNamePattern maxHistory30/maxHistory /rollingPolicy encoder classnet.logstash.logback.encoder.LogstashEncoder includeMdctrue/includeMdc customFields{service:trade-service}/customFields /encoder /appender这样一条日志在文件里是类似这样的结构{timestamp:2025-01-05T14:23:01.012Z,level:INFO,thread:http-nio-8080-exec-4,logger:com.example.OrderServiceImpl,message:创建订单成功,traceId:6aa2526590ad07346b76e2b8d8d80384,service:trade-service}MDC里的traceId会被带进JSON里在Elasticsearch里自动映射成独立字段。相比文本grok这种方式稳定、清晰、检索高效也少写很多解析配置。4.2 Filebeat采集与Logstash配置要点Filebeat采集JSON日志时用ndjson解析器直接展开filebeat.inputs: - type: filestream enabled: true paths: - /data/logs/app/*.json.log parsers: - ndjson: target: Logstash这层其实不用做太多事主要是加一个timestamp和索引名input { beats { port 5044 } } filter { mutate { add_field { env prod } } } output { elasticsearch { hosts [http://elasticsearch:9200] index app-log-%{YYYY.MM.dd} } }需要注意这里Filebeat的target: 表示把JSON里的所有字段直接放到顶层。如果你不设置字段可能会被包到JSON对象里Kibana检索时要写json.traceId能搜但不够爽。参考配置在项目里统一约定即可。还有一个坑如果应用打印日志时CPU和IO压力比较大JSON序列化会有一定损耗。不过相比排查问题时节省的时间这个成本完全可以接受。真遇到极端高并发场景可以只在application环境输出JSON本地开发环境仍保持纯文本格式。4.3 Kibana中按TraceId查出完整SQL日志一个真实场景现在回到开头的那个场景。我收到一条报障服务商报错运维那边丢过来一行信息java traceid:6aa2526590ad07346b76e2b8d8d80384拿到这个ID后我在Kibana的Discover页面选择对应的索引模式在搜索框输入traceId: 6aa2526590ad07346b76e2b8d8d80384搜索结果是这个ID关联的所有日志包括网关的访问日志、订单服务的业务日志、MyBatis打印的SQL日志甚至还有MQ消费端的处理日志。每条日志展开后能看到完整的时间、线程、类名、日志内容。在这个案例里我可以清晰地看到14:23:01 网关收到请求转发到订单服务14:23:01.012 订单服务创建订单14:23:01.100 MyBatis执行了一条SELECT查询库存14:23:01.200 调用支付服务14:23:01.350 支付返回超时14:23:01.355 业务抛出TimeoutException。实际上这个请求的问题在于查询库存的SQL扫描行数太高耗时到了1秒多拖垮了支付调用。以前这种问题至少排查半小时现在从拿到TraceId到定位完成五分钟以内。假如同一个TraceId既出现在应用日志索引又出现在数据库日志索引可以用通配符选择多个索引模式或者给多个日志索引建一个别名app-*这样一次搜索就能跨索引覆盖所有日志。4.4 索引生命周期日志越攒越多时的处理技巧开启TraceId之后日志量不会减少但所有字段都更结构化。Elasticsearch的存储成本要提前考虑不然日志索引只增不减一个月下来可能压垮磁盘。建议在Elasticsearch里给日志索引配置ILM策略比如7天内的索引为热阶段保持副本数大于17天后进入温阶段强制合并segment30天后进入冷阶段降低副本数或者迁移到冷节点90天后删除。这样即使业务方想回溯一个三个月前的TraceId也有冷数据可以查成本总体可控。另外每个索引只保留一个服务或一个应用类型的日志别把所有东西都塞进一个索引否则搜索时其他类型日志会干扰结果。5. 高频问题与避坑实录5.1 高频问题速查表现象原因解决方案日志里TraceId为空pattern没加%X{traceId}检查Root logger的pattern配置偶尔一条日志没有TraceId异步线程池未复制MDC使用MdcRunnable或TaskDecorator下游服务的日志没有TraceIdHeader未透传检查Feign/RestTemplate/RPC拦截器同一个请求出现多个TraceId服务重新生成了ID或者Header名不统一入口生成下游透传全局统一Header名SQL日志没有TraceIdmapper logger覆盖了pattern检查MyBatis/JDBC日志对应的appender和patternKibana搜不到某条TraceId日志格式不是JSONgrok解析失败改用logstash-logback-encoder输出JSON日志顺序看着混乱多机器时间不同步按采集时间排序统一NTP时间排序用timestamp字段这个表值得截图保存团队里谁遇到类似问题照着排查基本都能解决。5.2 日志乱序的处理思路同一个TraceId的日志来自不同服务、不同机器每台机器记录的日志时间戳可能存在几毫秒到几十毫秒的偏差。如果发现日志顺序和实际调用顺序不一致先别怀疑逻辑先检查各机器的系统时间是否统一。规范做法是所有服务器统一用NTP同步时间。在Kibana里搜索时建议按timestamp排序而不是按Filebeat采集时间排序。因为采集时间反映的是“日志被写进ES的时间”可能会有几秒延迟容易造成错觉。5.3 多索引检索和TraceId跳转Kibana的Discover页面默认只查一个索引模式如果业务日志和SQL日志分开存储搜索时记得选择多个索引模式。如果有固定域名或者固定的查询入口还可以在Kibana的Advanced Settings里配置默认tsvb或者仪表盘直接把TraceId作为URL参数透传方便运维同事快速查询。我见过一种比较实用的小工具开发方式内部运维系统里加一个搜索框输入TraceId后台调用Kibana的API或者ES的REST接口返回所有相关日志流。操作更极简适合让非技术人员也能自助排查。6. 最后说点落地建议这一套东西我前前后后改过三轮踩过最大的坑不是技术实现而是“大家没有遵守同一个Header名”。A服务用X-Trace-IdB服务用trace_idC服务干脆不透传最后全链路根本对不上。后来我把Header名、合法性校验、生成规则、日志JSON格式、索引命名全部写进组内规范并在网关强制兜底上游没带就生成带了就校验。从那以后线上排查才真正变成“复制ID搜索完事”。再分享一个经验如果你已经接了SkyWalking或者其他链路追踪系统别在日志里单独再造一套ID最好是直接把链路追踪的TraceId同步到日志MDC里。这样两边对得上链路拓扑和日志详情能交叉验证排查定位更全面。底层原理跟今天讲的完全一致只是取值来源从“自己生成”换成“从链路追踪接口取”。最后提醒一句把Filebeat采集端做一下监控。很多时候日志不是没有TraceId而是采集进程挂了ES里压根没看到最新数据。留一个“最近5分钟各服务日志量”的看板比啥都管用。