Java 线程池日志,如何用 traceId 关联同一次请求?
开篇
接口收到请求后,常会把耗时任务交给线程池。若任务日志没带上接口里的请求编号,排查问题时就很难把两边日志对起来。这个编号叫 traceId,下面看怎样把它传给异步任务,并在任务结束后正确清理。
环境:JDK 21、Spring Boot 3(Spring Framework 6)、SLF4J 2、Logback 1。示例使用应用自有的线程池和上下文工具,展示关键方法与调用,不是只依赖 JDK 的完整程序。
坑点
坑点一:接口里有请求编号,换个线程就读不到了
这里的 ThreadContext 用 ThreadLocal 保存每个线程的数据。MDC 则负责给日志附带编号等字段;Logback 中的 MDC 也按线程保存,换个线程不会自动带过去。Logback MDC 说明
下面给请求设置编号,再用普通线程池读取。两处输出都是空:
// 对照示例:普通线程池没有配置上下文传递。
try (ExecutorService pool = Executors.newSingleThreadExecutor()) {
ThreadContext.setTraceId("req-A");
pool.submit(() -> {
System.out.println(ThreadContext.getTraceId());
// null
System.out.println(MDC.get(ThreadContext.TRACE_ID));
// null
}).get(5, TimeUnit.SECONDS);
ThreadContext.clear();
}
坑点二:不分线程地清理,接口后续日志也丢了编号
配置了 CallerRunsPolicy 时,线程池忙满且未关闭,会让提交任务的线程自己执行。此时若清理编号,清掉的就是接口当前还在用的那份。JDK 拒绝策略说明
用直接执行任务的方式,就能看出这个问题:
// 对照示例:模拟任务直接在提交线程执行,却仍然清理上下文。
ThreadContext.setTraceId("req-A");
Runnable wrong = () -> {
try {
System.out.println(ThreadContext.getTraceId());
// req-A
} finally {
ThreadContext.clear();
}
};
wrong.run();
System.out.println(ThreadContext.getTraceId());
// null,后续请求日志丢了编号
正确写法
避坑一:提交时复制编号,让线程池统一传递
接入位置在线程池创建处。ThreadPoolManager.createThreadPool 在初始化执行器之前,设置了下面这行:
// 任务装饰器(如传递 MDC 上下文)
executor.setTaskDecorator(RunnableWrapper::of);
任务装饰器就是给原任务包一层,在执行前后补充处理,业务代码仍然正常提交任务。RunnableWrapper 是这里的任务包装类,创建时记住当前线程,并复制当时的数据:
private Runnable runnable;
private Thread mainThread;
private Map<String, String> threadContextMap;
public RunnableWrapper(Runnable runnable) {
this.runnable = runnable;
this.mainThread = Thread.currentThread();
// 在任务提交线程中创建独立快照,不能延迟到工作线程执行时再读取
this.threadContextMap = ThreadContext.getCopyOfContextMap();
}
mainThread 指创建包装器的线程,不一定是 Java 的 main 线程。包装器要在提交任务时创建,进入工作线程后再复制就晚了。
复制方法返回独立 Map,因此提交后再修改请求线程里的编号,不会改掉已保存的值:
public static Map<String, String> getCopyOfContextMap() {
// 创建独立Map作为异步任务快照;当前所有value均为不可变String,浅拷贝即可安全跨线程
return new HashMap<>(CONTEXT.get());
}
这里的字段值都是不可变的 String。若以后放入可变对象,仅复制 Map 不能隔离对象内部的修改。
业务怎么用:提交任务,不用每次手动传编号
下面调用已经配置好装饰器的工厂。任务里的编号和请求线程一致,登录用户 ID 也能读取:
// 调用示例:工厂已配置装饰器,业务任务不需要再手动包装。
ThreadPoolTaskExecutor pool = ThreadPoolManager.createThreadPool(
"trace-demo", 1, 8, RejectedPolicyEnum.ABORT_POLICY);
try {
ThreadContext.setTraceId("req-A");
ThreadContext.setLoginUserId("user-7");
pool.submit(() -> {
System.out.println(ThreadContext.getTraceId());
// req-A
System.out.println(MDC.get(ThreadContext.TRACE_ID));
// req-A
System.out.println(ThreadContext.getLoginUserId());
// user-7
}).get(5, TimeUnit.SECONDS);
System.out.println(ThreadContext.getTraceId());
// req-A,提交线程未被清理
} finally {
ThreadContext.clear();
pool.shutdown();
}
ThreadPoolManager、ThreadContext、RunnableWrapper 和 RejectedPolicyEnum 都是应用自有类;ThreadPoolTaskExecutor 和 setTaskDecorator 来自 Spring。接入已有工程时,要同时具备包装器、上下文工具及相关依赖,不能只复制配置行。
示例创建和关闭线程池是为了观察结果;业务中应复用已配置的线程池,不要每来一个请求就创建一次。get(5, TimeUnit.SECONDS) 只用于等待并核对输出,不是异步业务必须阻塞等待的写法。
避坑二:工作线程用完清理,请求线程继续保留
编号复制好了,什么时候放回去?run() 先判断实际执行任务的是哪个线程:
@Override
public void run() {
// CallerRunsPolicy 可能直接在提交线程执行,此时沿用线程上已有的同一份上下文,且不能执行清理
if (Objects.equals(mainThread, Thread.currentThread())) {
runnable.run();
} else {
workerRun();
}
}
/**
* 线程池中的工作线程执行
*/
private void workerRun() {
try {
// 恢复提交任务时捕获的完整上下文
ThreadContext.putContextMap(threadContextMap);
runnable.run();
} finally {
// 线程池会复用工作线程,任务结束后必须清理,避免污染下一个任务
ThreadContext.clear();
threadContextMap.clear();
threadContextMap = null;
runnable = null;
mainThread = null;
}
}
工作线程先恢复数据,再执行任务,最后清理。线程池会复用线程,清理能避免下一项任务沿用这次请求的编号;finally 让业务抛异常时也走这一步。
清理同时移除上下文和日志字段:
public static void clear() {
MDC.clear();
CONTEXT.remove();
}
如果任务就在创建包装器的线程执行,则沿用该线程当前的值,不恢复快照,也不额外清理。接口本身结束时,再由请求入口清理。
同线程执行后,编号仍在:
// 调用示例:只验证同线程分支,线程池饱和的情况另做实测。
ThreadContext.setTraceId("req-A");
Runnable task = RunnableWrapper.of(() -> {
System.out.println(ThreadContext.getTraceId());
// req-A
});
task.run();
System.out.println(ThreadContext.getTraceId());
// req-A,调用后仍然保留
ThreadContext.clear();
日志里怎样显示这个编号
恢复方法识别约定的四个字段,其中 traceId 会调用 setTraceId:
public static void putContextMap(Map<String, String> contextMap) {
if (null != contextMap && !contextMap.isEmpty()) {
contextMap.forEach((k, v) -> {
if (Strings.CS.equals(k, TRACE_ID)) {
setTraceId(v);
} else if (Strings.CS.equals(k, LOGIN_USER_ID)) {
setLoginUserId(v);
} else if (Strings.CS.equals(k, APP_ID)) {
setAppId(v);
} else if (Strings.CS.equals(k, SEATA_XID)) {
setSeataXid(v);
}
});
}
}
setTraceId 一边保存编号,方便业务读取,一边写入 MDC,供日志输出:
public static void setTraceId(String traceId) {
MDC.put(TRACE_ID, traceId);
CONTEXT.get().put(TRACE_ID, traceId);
}
Logback 的日志格式还要包含 %X{X-Trace-Id},否则 MDC 中有编号,日志里也不会显示。它与代码中的键名对应,不能随意改成另一个名字。
另三个字段恢复到 ThreadContext 供业务读取。其中 XID 只恢复一个值,不等于绑定Seata事务;本文不展开事务传播。
使用时还要注意什么
工厂方法遇到已包装任务,会直接返回原对象:
/**
* 创建RunnableWrapper实例的工厂方法
*
* @param runnable 需要包装的Runnable对象
*/
public static Runnable of(Runnable runnable) {
paramNotNull(runnable, "runnable");
// 如果传入的runnable已经是RunnableWrapper类型,直接返回
if (runnable instanceof RunnableWrapper) {
return runnable;
}
// 否则创建新的RunnableWrapper实例
return new RunnableWrapper(runnable);
}
所以它只避免重复包装,不会重新复制数据。工作线程执行完后,包装器还会将任务和快照置空;每次提交要使用新包装器,不能缓存同一个实例反复执行。
还有三个影响使用的条件:
- 工作线程不能混入遗留数据。putContextMap 只写入传来的键,不先清空旧值;如果其他任务留下了用户 ID,这次又没传该字段,仍可能读到旧用户。使用这个线程池的任务都要遵守清理约定,它也不负责保存并恢复外层任务的数据。
- 额外的 MDC 字段不会自动传递。直接用 MDC.put 添加的其他键不在快照里,而清理会移除全部MDC字段;与其他日志组件共用时要明确由谁管理。
- 同线程执行不回滚业务修改。任务若改了请求线程里的编号,返回后修改仍在;这一分支避免的是额外清理,不提供数据隔离。
普通 CompletableFuture 调用不会自动经过这个线程池;需要传递编号时,应显式传入配置了装饰器的执行器。编号能让日志关联起来,不保证任务一定成功或通知一定送达。
总结
先在线程池入口接入包装器,让业务正常提交任务。包装器在提交时复制数据,在工作线程执行前恢复、结束后清理;任务退回请求线程执行时,保留请求还在使用的编号。
使用前检查两处:日志格式是否包含正确的 MDC 键,以及同一线程池里的任务是否都遵守清理约定。
如果这篇文章对您有用,欢迎关注。后续会继续拆解 Java 后端的实用代码,讲清写法、原理和使用时要注意的细节。
网硕互联帮助中心






评论前必须登录!
注册