title: traceId 一进线程池就丢InheritableThreadLocal 为什么只在第一次生效tags: [Java, ThreadLocal, InheritableThreadLocal, 线程池, 链路追踪]从「日志串不起来」开始我们的日志规范是每条日志前面带 traceId出问题时用 traceId 一搜就能把一次请求经过的所有服务、所有异步分支全捞出来。这套东西平时很好用直到有一次排查订单状态不一致我搜 traceId 只搜到了 6 条日志——而按代码逻辑那次请求至少该有 20 多条。丢掉的那些日志有个共同特征全是在线程池里执行的异步任务打的。它们的 traceId 字段是空的或者更糟——是别的请求的 traceId。拿着别人的 traceId 打日志比没有 traceId 更可怕。那意味着排查时我会把两次不相干的请求当成一次来分析。当时的实现和它为什么「看起来能用」traceId 存取用的是这么一个工具类public class TraceContext { // 用 Inheritable 版本本意是让子线程能继承父线程的 traceId private static final InheritableThreadLocalString TRACE_ID new InheritableThreadLocal(); public static void set(String traceId) { TRACE_ID.set(traceId); } public static String get() { return TRACE_ID.get(); } public static void clear() { TRACE_ID.remove(); } }写这段代码的同学思路是对的普通ThreadLocal在子线程里拿不到父线程的值所以换成InheritableThreadLocal。他还专门写了个 demo 验证确实能传下去TraceContext.set(trace-001); new Thread(() - System.out.println(TraceContext.get())).start(); // 输出 trace-001验证通过问题是这个 demo 用的是new Thread()而线上用的是线程池。关键源码继承发生在线程创建那一刻InheritableThreadLocal的传递是在Thread构造函数里完成的只此一次。看Thread.init的核心几行private void init(ThreadGroup g, Runnable target, String name, long stackSize, AccessControlContext acc, boolean inheritThreadLocals) { // ... Thread parent currentThread(); // 只有父线程的 inheritableThreadLocals 非空才做一次拷贝 if (inheritThreadLocals parent.inheritableThreadLocals ! null) this.inheritableThreadLocals ThreadLocal.createInheritedMap(parent.inheritableThreadLocals); // ... }逐句拆开看Thread parent currentThread()这里的「父线程」指的是执行 new Thread() 这行代码的那个线程不是逻辑上的调用方。createInheritedMap做的是一次浅拷贝把父线程 map 里的键值对复制到新线程自己的 map 里。拷贝完两者就没关系了父线程后续改值不会同步给子线程。整个逻辑写在init里也就是说继承只在线程被创建的瞬间发生一次。线程池的特点恰恰是线程复用。一个核心线程在池子启动时或者第一次提交任务时被创建那一刻它继承了当时那个提交者的 traceId然后这个线程活几天几个月处理成千上万个不同请求的任务inheritableThreadLocals里躺着的永远是最初那一次继承来的值。这就完美解释了线上两种现象任务打不出 traceId线程创建时提交者还没 set或者打出别人的 traceId线程创建时继承了那一次请求的值之后一直用它。用一段代码把这个现象钉死public class InheritableInPoolDemo { private static final InheritableThreadLocalString CTX new InheritableThreadLocal(); public static void main(String[] args) throws Exception { ExecutorService pool Executors.newFixedThreadPool(1); // 只有 1 个线程 CTX.set(request-A); pool.submit(() - System.out.println(task1 sees: CTX.get())).get(); CTX.set(request-B); pool.submit(() - System.out.println(task2 sees: CTX.get())).get(); pool.shutdown(); } }输出是task1 sees: request-A task2 sees: request-A第二个任务明明是在CTX.set(request-B)之后提交的却看到了request-A。因为池里那唯一的线程是在 task1 提交时创建的那一刻继承了 A之后再也不会重新继承。我把这段代码贴到团队群里比讲十分钟原理有效——好几个人当场去翻自己的代码。三种解法我们最后选了哪个解法一手动传递最笨但最可靠提交任务前把 traceId 抓出来在任务里手动 setfinally里清理public static Runnable wrap(Runnable task) { final String traceId TraceContext.get(); // 在提交线程父线程抓取 return () - { String backup TraceContext.get(); // 备份池线程原有值 TraceContext.set(traceId); try { task.run(); } finally { if (backup null) TraceContext.clear(); else TraceContext.set(backup); // 还原避免污染下一个任务 } }; }这段的三个要点traceId必须在 lambda 外面取否则取到的是池线程的值finally必须还原而不是简单 remove嵌套提交时会把外层的值也清掉backup为 null 时要clear而不是set(null)否则 map 里会留一个 null 值的 entry虽然不致命但没必要。解法二TransmittableThreadLocal阿里开源的 TTLTransmittableThreadLocal的思路是在任务提交时捕获快照、在任务执行前回放、执行后恢复正好补上线程池复用这个缺口private static final TransmittableThreadLocalString TRACE_ID new TransmittableThreadLocal(); // 用 TtlExecutors 包装原有线程池即可业务代码不用改 ExecutorService pool TtlExecutors.getTtlExecutorService( new ThreadPoolExecutor(8, 16, 60L, TimeUnit.SECONDS, new ArrayBlockingQueue(200)));我们用的是transmittable-thread-local2.14.2。它还提供 javaagent 方式连包装线程池这一步都能省掉对存量项目改动最小。解法三换成 MDC 框架埋点如果你已经在用 SkyWalking、OpenTelemetry 这类 APM它们的 agent 通常自带线程池的跨线程上下文传播直接用MDC.get(traceId)就行不需要自己维护 ThreadLocal。方案侵入性线程池复用是否正确嵌套提交是否正确适合谁手动 wrap高每处提交都要包正确需自己备份还原异步点少、不想引依赖TTL 包装线程池低只改建池处正确正确大多数存量 Java 项目APM agent MDC最低无代码改动正确正确已有完整 APM 体系InheritableThreadLocal低错误错误只适合 new Thread 的场景我们选了 TTL。理由很实在项目里有 40 多处线程池创建点但异步任务提交点有 300 多处。改 40 处建池代码比改 300 处提交代码划算得多而且以后新增提交点不会漏。Spring 项目里还有个更省事的口子TaskDecorator如果你的异步任务走的是 Spring 的Async或ThreadPoolTaskExecutor其实不用包装每个任务Spring 提供了TaskDecorator扩展点专门用来做上下文传递public class TraceTaskDecorator implements TaskDecorator { Override public Runnable decorate(Runnable runnable) { // 这行在【提交线程】执行能拿到正确的上下文 String traceId TraceContext.get(); MapString, String mdc MDC.getCopyOfContextMap(); return () - { // 这里已经在【池线程】了 try { TraceContext.set(traceId); if (mdc ! null) MDC.setContextMap(mdc); runnable.run(); } finally { TraceContext.clear(); MDC.clear(); // 必须清否则污染这个池线程的下一个任务 } }; } } Bean(bizExecutor) public ThreadPoolTaskExecutor bizExecutor() { ThreadPoolTaskExecutor exec new ThreadPoolTaskExecutor(); exec.setCorePoolSize(8); exec.setMaxPoolSize(16); exec.setQueueCapacity(200); exec.setThreadNamePrefix(biz-async-); exec.setTaskDecorator(new TraceTaskDecorator()); // 关键一行 exec.initialize(); return exec; }decorate方法的执行时机是理解它的关键它在submit/execute被调用时、由提交线程同步执行所以在这里取上下文是安全的。返回的那个 lambda 才是真正跑在池线程里的部分。这个先后顺序如果搞反——比如把TraceContext.get()写进 lambda 内部——那就等于什么都没做。我们的 MDC 也一起在这里传了否则 logback 的%X{traceId}在异步日志里还是空的。这一点很多人只处理了自己的 ThreadLocal 却忘了 MDC日志里依然缺失。别忘了泄漏这件事顺带说一个容易被忽略的点。ThreadLocalMap的 key 是WeakReferenceThreadLocalvalue 是强引用。如果 ThreadLocal 对象本身被回收了但线程还活着就会留下一个 key 为 null、value 还在的 entry这就是经典的泄漏点。线程池里这个问题格外严重因为线程几乎不死。虽然get/set时expungeStaleEntry会顺手清理一部分但那是概率性的不能依赖。所以上面 wrap 的finally里那句还原不只是为了正确性也是为了不让 value 长期挂在池线程上。我们上线 TTL 之后专门看了一下堆修复前 dump 里能看到某个池线程的ThreadLocalMap里挂着 17 个 entry其中 5 个 key 已为 null修复后稳定在 3 个 entry无 null key。复盘数字问题存在时长从功能上线算起约 4 个月期间无人发现因为大部分排查场景只看主线程日志。抽样统计异步任务日志中 traceId 缺失占 62%串到其他请求 traceId 的占 9%。这 9% 是真正危险的部分。改造范围40 处线程池创建点包装 TTL耗时约 1.5 天包含回归测试。改造后异步日志 traceId 正确率抽样 100%1000 条采样。我的判断InheritableThreadLocal这个类的名字有很强的误导性它容易让人以为「只要用了它上下文就能跨线程传」。实际上它的适用面窄得多——只在「显式 new Thread 且创建时刻上下文已就绪」时才对。在有线程池的项目里我基本不建议用它因为它会给你一种「已经处理好了」的错觉而错误的 traceId 比没有 traceId 危害更大。如果非要给个简单判断标准你的异步任务是不是跑在复用线程上只要是就别指望 InheritableThreadLocal。思考题假设有嵌套提交的场景线程池 A 里的任务又往线程池 B 提交了任务。用 TTL 时上下文能正确传两层吗如果 A 里的任务在提交给 B 之前修改了 traceIdB 拿到的是修改前还是修改后的值建议你写段代码亲手验证一遍这个细节在做全链路压测标记比如染色流量时会直接决定标记会不会漏。