InheritableThreadLocal遇到线程池出现的问题分析及解决方案

最新推荐文章于 2025-11-14 15:55:37 发布

原创

最新推荐文章于 2025-11-14 15:55:37 发布 · 1.7k 阅读

22 ·

CC 4.0 BY-SA版权

文章标签：

#java #spring #xxl-job #多线程 #ThreadLocal

2、实现Runnable、Callable

3、继承ThreadPoolExecutor，重载execute方法、重写beforeExecute、afterExecute方法

四、参考链接

一、背景与问题复现

1、背景

在开发xxl-job定时任务时，由于在定时任务中使用了线程池进行子任务处理并且打印日志，发现存在子任务日志打印位置错乱问题，比如，定时任务1中线程池执行的子任务日志被记录到了定时任务2的日志文件中。

2、问题复现

xxl-job自行从github中下载及配置使用，这里只贴上用于复现问题的两个任务

1）创建两个任务

@Component
public class LogTestHandler {

    private final ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(
            Runtime.getRuntime().availableProcessors(),
            Runtime.getRuntime().availableProcessors(),
            0,
            TimeUnit.SECONDS,
            new ArrayBlockingQueue<>(1024),
            Executors.defaultThreadFactory(),
            new ThreadPoolExecutor.AbortPolicy()
    );


    @XxlJob("logTestHandler01")
    public void logTestHandler01() {
        XxlJobHelper.log("logTestHandler01 main thread...");

        // 执行Runtime.getRuntime().availableProcessors()次，每次休眠一秒，确保线程池所有线程在该主线程中被创建出来
        for(int i = 0;i < Runtime.getRuntime().availableProcessors(); i++) {
            threadPoolExecutor.execute(new Runnable() {
                @Override
                public void run() {
                    XxlJobHelper.log("logTestHandler01 child thread...");
                    try {
                        Thread.sleep(1500);
                    } catch (InterruptedException e) {
                        throw new RuntimeException(e);
                    }
                }
            });
        }

    }

    @XxlJob("logTestHandler02")
    public void logTestHandler02() {
        XxlJobHelper.log("logTestHandler02...");

        // 此时线程池中所有线程已经被创建了，提交多次任务，查看日志打印情况
        for(int i = 0;i < Runtime.getRuntime().availableProcessors(); i++) {
            threadPoolExecutor.execute(new Runnable() {
                @Override
                public void run() {
                    XxlJobHelper.log("logTestHandler02 child thread...");
                    try {
                        Thread.sleep(1500);
                    } catch (InterruptedException e) {
                        throw new RuntimeException(e);
                    }
                }
            });
        }
    }

}

2）在xxl-job端任务管理中进行两个任务配置

3）执行logTestHandler01一次，日志打印如下

2024-07-17 09:12:43 [com.xxl.job.core.thread.JobThread#run]-[133]-[xxl-job, JobThread-4-1721178763497] <br>----------- xxl-job job execute start -----------<br>----------- Param:
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler#logTestHandler01]-[32]-[xxl-job, JobThread-4-1721178763497] logTestHandler01 main thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-4] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-2] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.core.thread.JobThread#run]-[179]-[xxl-job, JobThread-4-1721178763497] <br>----------- xxl-job job execute end(finish) -----------<br>----------- Result: handleCode=200, handleMsg = null
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-1] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-3] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-5] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-6] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.core.thread.TriggerCallbackThread#callbackLog]-[197]-[xxl-job, executor TriggerCallbackThread] <br>----------- xxl-job job callback finish.

4）执行logTestHandler02一次，日志打印如下，此时可以发现，logTestHandler02线程池中执行的子任务的日志不见了！那么它的子任务日志跑哪去了？请接着往下看

2024-07-17 09:13:17 [com.xxl.job.core.thread.JobThread#run]-[133]-[xxl-job, JobThread-5-1721178797698] <br>----------- xxl-job job execute start -----------<br>----------- Param:
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler#logTestHandler02]-[52]-[xxl-job, JobThread-5-1721178797698] logTestHandler02...
2024-07-17 09:13:17 [com.xxl.job.core.thread.JobThread#run]-[179]-[xxl-job, JobThread-5-1721178797698] <br>----------- xxl-job job execute end(finish) -----------<br>----------- Result: handleCode=200, handleMsg = null
2024-07-17 09:13:17 [com.xxl.job.core.thread.TriggerCallbackThread#callbackLog]-[197]-[xxl-job, executor TriggerCallbackThread] <br>----------- xxl-job job callback finish.

5）刷新logTestHandler01的日志文件，内容如下，可以发现，logTestHandler02子任务的日志都跑到了logTestHandler01的日志文件中。

tips: 由于每执行一次任务，会生成对应的日志文件，logTestHandler02子任务缺失的日志定位，需要确认线程池中哪个线程执行，获得它的ThreadLocal查看记录日志的信息。由于先执行的是logTestHandler01，所以线程池中的所有线程是由执行logTestHandler01任务的线程进行创建的，线程池中所有线程拷贝的也是该线程的ThreadLocal（包含了日志文件位置信息），后面执行logTestHandler02，我们可以定位logTestHandler02缺失的日志在logTestHandler01首次执行的日志文件中。

2024-07-17 09:12:43 [com.xxl.job.core.thread.JobThread#run]-[133]-[xxl-job, JobThread-4-1721178763497] <br>----------- xxl-job job execute start -----------<br>----------- Param:
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler#logTestHandler01]-[32]-[xxl-job, JobThread-4-1721178763497] logTestHandler01 main thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-4] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.executor.service.jobhandler.LogTestHandler$1#run]-[38]-[pool-2-thread-2] logTestHandler01 child thread...
2024-07-17 09:12:43 [com.xxl.job.core.thread.JobThread#run]-[179]-[x

最低0.47元/天解锁文章