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

明天再去学习

于 2024-07-18 10:38:19 发布

阅读量461

点赞数 6

分类专栏： java 文章标签： java spring xxl-job 多线程 ThreadLocal

本文链接：https://blog.csdn.net/Staba/article/details/140484964

版权

java 专栏收录该内容

11 篇文章 3 订阅

订阅专栏

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]-[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.
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler$2#run]-[58]-[pool-2-thread-1] logTestHandler02 child thread...
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler$2#run]-[58]-[pool-2-thread-3] logTestHandler02 child thread...
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler$2#run]-[58]-[pool-2-thread-2] logTestHandler02 child thread...
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler$2#run]-[58]-[pool-2-thread-6] logTestHandler02 child thread...
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler$2#run]-[58]-[pool-2-thread-4] logTestHandler02 child thread...
2024-07-17 09:13:17 [com.xxl.job.executor.service.jobhandler.LogTestHandler$2#run]-[58]-[pool-2-thread-5] logTestHandler02 child thread...

二、问题分析

接下来我们进行分析，给大家讲解为什么会出现这样子的问题。

1）首先，我们从xxl-job记录日志的方法入手

XxlJobHelper.log("logTestHandler01 main thread...");

2）进入log方法，查看实现细节

public static boolean log(String appendLogPattern, Object ... appendLogArguments) {

        FormattingTuple ft = MessageFormatter.arrayFormat(appendLogPattern, appendLogArguments);
        String appendLog = ft.getMessage();

        /*appendLog = appendLogPattern;
        if (appendLogArguments!=null && appendLogArguments.length>0) {
            appendLog = MessageFormat.format(appendLogPattern, appendLogArguments);
        }*/

        StackTraceElement callInfo = new Throwable().getStackTrace()[1];
        return logDetail(callInfo, appendLog);
    }

进入log方法之后，我们发现其余地方没什么重点，只有logDetail有点东西，进入看看。代码很简单，稍微看看，就知道文件名从XxlJobContext.getJobContext()中来。

private static boolean logDetail(StackTraceElement callInfo, String appendLog) {
        XxlJobContext xxlJobContext = XxlJobContext.getXxlJobContext();
        if (xxlJobContext == null) {
            return false;
        }

        /*// "yyyy-MM-dd HH:mm:ss [ClassName]-[MethodName]-[LineNumber]-[ThreadName] log";
        StackTraceElement[] stackTraceElements = new Throwable().getStackTrace();
        StackTraceElement callInfo = stackTraceElements[1];*/

        StringBuffer stringBuffer = new StringBuffer();
        stringBuffer.append(DateUtil.formatDateTime(new Date())).append(" ")
                .append("["+ callInfo.getClassName() + "#" + callInfo.getMethodName() +"]").append("-")
                .append("["+ callInfo.getLineNumber() +"]").append("-")
                .append("["+ Thread.currentThread().getName() +"]").append(" ")
                .append(appendLog!=null?appendLog:"");
        String formatAppendLog = stringBuffer.toString();

        // appendlog
        String logFileName = xxlJobContext.getJobLogFileName();

        if (logFileName!=null && logFileName.trim().length()>0) {
            XxlJobFileAppender.appendLog(logFileName, formatAppendLog);
            return true;
        } else {
            logger.info(">>>>>>>>>>> {}", formatAppendLog);
            return false;
        }
    }

3）接下来看XxlJobContext.getJobContext()实现细节，点击进去，可以看到相关的细节如下：

// ---------------------- tool ----------------------

    private static InheritableThreadLocal<XxlJobContext> contextHolder = new InheritableThreadLocal<XxlJobContext>(); // support for child thread of job handler)

    public static void setXxlJobContext(XxlJobContext xxlJobContext){
        contextHolder.set(xxlJobContext);
    }

    public static XxlJobContext getXxlJobContext(){
        return contextHolder.get();
    }

此处可以看到，日志文件位置相关信息是从InheritableThreadLocal拿到的，关于ThreadLocal，如果有不清楚的小伙伴，自行查阅资料去了解。这里只简单说一下InheritableThreadLocal作用，如果父线程创建了一个子线程，在创建子线程时，会从将父线程的inheritableThreadLocals属性深拷贝给子线程的inheritableThreadLocals。具体看Thread类的init方法，以下只拷贝出关键部分：

if (inheritThreadLocals && parent.inheritableThreadLocals != null)
            this.inheritableThreadLocals =
                ThreadLocal.createInheritedMap(parent.inheritableThreadLocals);

根据该代码，得出结论：线程在被创建出来的时候，在进行初始化时，会深拷贝父线程的inheritableThreadLocals属性，该行为只在线程初始化时进行深拷贝一次，后续不再进行拷贝。

4）接下来将InheritableThreadLocal结合线程池进行分析说明。

先简单说一下ThreadLocalPool提交任务执行并执行的步骤流程：

向线程池提交一个任务
如果线程池中当前运行的线程数小于核心线程数，那么就会由提交任务的线程给线程池创建一个子线程，并将任务交由子线程进行执行，结束。
否则的话，也就是线程池中当前运行的线程数达到核心线程池，就判断任务队列是否满了，如果没有满的话，就将任务放入到任务队列中，结束。
否则的话，也就是任务队列满了，就判断最大线程池是否已经满了，如果没满的话，那么就会由提交任务的线程给线程池创建一个子线程，并将任务交由子线程进行执行，结束。
否则的话，也就是当前运行的线程已达到最大线程数，将会触发任务决绝策略。

InheritableThreadLocal作用：

在上面也说过了，就是：如果父线程创建了一个子线程，在创建子线程时，会从将父线程的inheritableThreadLocals属性深拷贝给子线程的inheritableThreadLocals。子线程在被创建出来的时候，在进行初始化时，会深拷贝父线程的inheritableThreadLocals属性，该行为只在子线程初始化时进行深拷贝一次，后续不再进行拷贝。

通过上诉线程池提交任务流程、InheritableThreadLocal作用以及线程初始化，目的就是想告诉大家，结合线程池使用的话，如果一开始线程池中没有任何线程时，提交任务的线程进行任务提交时，就会由该任务线程进行创建子线程，这个子线程会深拷贝提交任务线程的inheritableThreadLocals属性，并且只初始化这一次，如果后续提交任务线程对inheritableThreadLocals属性进行修改，将与子线程无关，线程池中的线程没有任何感知。

结合上诉xxl-job例子来再进一步讲解，加深理解：

由于我们将线程的核心线程数和最大线程数都设置成了系统可用的处理器核数，所以线程池中的线程一旦创建，线程数量将保持不变。
首次执行logTestHandler01任务，我们提交了对应处理器核数的任务，并且休眠1.5s，确保执行logTestHandler01任务的线程将线程池所有的子线程都创建出来，此时，线程池中所有子线程的inheritableThreadLocals属性与执行logTestHandler01任务的线程的inheritableThreadLocals属性内容一致（注意，是内容值一致，不是引用一致）。也就是说，线程池中所有的子线程持有跟执行logTestHandler01任务的线程的一样的日志位置信息XxlJobContext(假设文件id是35)
由于执行logTestHandler01任务的线程和线程池中所有线程持有相同的日志位置信息（文件id是35），所以当logTestHandler01任务向线程池提交任务时，文件id为35的日志内容显示正确，没有缺失
执行logTestHandler02任务，我们提交了对应处理器核数的任务，并且休眠1.5s，打印日志。会给logTestHandler02任务的线程设置日志文件位置（假设文件id是36），所以该线程中打印的日志正确。但是，当线程池线程进行日志打印时，由于线程池中的所有线程持有的是文件id为35的日志文件信息，所以在logTestHandler02任务线程池中执行的子任务中的所有日志信息都被打印到了文件id为35的日志文件中。
后续不管是反复执行logTestHandler01任务还是logTestHandler02任务，线程池中执行所有的子任务的日志都将被打印到文件id为35的日志文件中，而不是logTestHandler01任务最新的日志文件（假设为日志文件id为37）中。

三、解决方案

由上述分析可以得知，如果我们想要让日志打印不错乱，那么我们需要每次向线程池中提交任务时，将提交任务线程的inheritableThreadLocals（包含了XxlJobContext）属性传递给执行了子任务的线程池中的线程。以下提供三种解决方法

1、手动传入上下文

该方案主要是获取到提交任务线程中的inheritableThreadLocals中保存的XxlJobContext信息，再手动传入到任务中，当线程池线程执行该任务时，再将XxlJobContext信息设置到自己的inheritableThreadLocals中，从而达到日志不错乱的目的。

任务代码如下：

@Component
public class LogTestHandler02 {

    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...");

        // 手动将该线程的XxlJobContext获取到
        XxlJobContext xxlJobContext = XxlJobContext.getXxlJobContext();

        // 执行Runtime.getRuntime().availableProcessors()次，每次休眠一秒，确保线程池所有线程在该主线程中被创建出来
        for(int i = 0;i < Runtime.getRuntime().availableProcessors(); i++) {

            // 深拷贝一份，避免线程之间持有相同引入，导致ThreadLocal语义变味。由于该类属性都是简单String、Long，可以直接赋值使用
            XxlJobContext childXxlJobContext = new XxlJobContext(
                    xxlJobContext.getJobId(),
                    xxlJobContext.getJobParam(),
                    xxlJobContext.getJobLogFileName(),
                    xxlJobContext.getShardIndex(),
                    xxlJobContext.getShardTotal()
            );

            threadPoolExecutor.execute(new Runnable() {

                @Override
                public void run() {
                    // 运行前将childXxlJobContext设置进ThreadLocal中
                    XxlJobContext.setXxlJobContext(childXxlJobContext);


                    XxlJobHelper.log("logTestHandler01 child thread...");
                    try {
                        Thread.sleep(1500);
                    } catch (InterruptedException e) {
                        throw new RuntimeException(e);
                    }
                }
            });
        }

    }

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

        // 手动将该线程的XxlJobContext获取到
        XxlJobContext xxlJobContext = XxlJobContext.getXxlJobContext();


        // 此时线程池中所有线程已经被创建了，提交多次任务，查看日志打印情况
        for(int i = 0;i < Runtime.getRuntime().availableProcessors(); i++) {

            // 深拷贝一份，避免线程之间持有相同引入，导致ThreadLocal语义变味。由于该类属性都是简单String、Long，可以直接赋值使用
            XxlJobContext childXxlJobContext = new XxlJobContext(
                    xxlJobContext.getJobId(),
                    xxlJobContext.getJobParam(),
                    xxlJobContext.getJobLogFileName(),
                    xxlJobContext.getShardIndex(),
                    xxlJobContext.getShardTotal()
            );

            threadPoolExecutor.execute(new Runnable() {
                @Override
                public void run() {
                    // 运行前将childXxlJobContext设置进ThreadLocal中
                    XxlJobContext.setXxlJobContext(childXxlJobContext);

                    XxlJobHelper.log("logTestHandler02 child thread...");
                    try {
                        Thread.sleep(1500);
                    } catch (InterruptedException e) {
                        throw new RuntimeException(e);
                    }
                }
            });
        }
    }

}

多次执行logTestHandler01和logTestHandler02，检查每次执行的日志，发现都能够记录正确

2024-07-17 15:04:54 [com.xxl.job.core.thread.JobThread#run]-[133]-[xxl-job, JobThread-4-1721199806597] <br>----------- xxl-job job execute start -----------<br>----------- Param:
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02#logTestHandler01]-[36]-[xxl-job, JobThread-4-1721199806597] logTestHandler01 main thread...
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$1#run]-[61]-[pool-2-thread-3] logTestHandler01 child thread...
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$1#run]-[61]-[pool-2-thread-6] logTestHandler01 child thread...
2024-07-17 15:04:54 [com.xxl.job.core.thread.JobThread#run]-[179]-[xxl-job, JobThread-4-1721199806597] <br>----------- xxl-job job execute end(finish) -----------<br>----------- Result: handleCode=200, handleMsg = null
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$1#run]-[61]-[pool-2-thread-1] logTestHandler01 child thread...
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$1#run]-[61]-[pool-2-thread-2] logTestHandler01 child thread...
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$1#run]-[61]-[pool-2-thread-4] logTestHandler01 child thread...
2024-07-17 15:04:54 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$1#run]-[61]-[pool-2-thread-5] logTestHandler01 child thread...
2024-07-17 15:04:54 [com.xxl.job.core.thread.TriggerCallbackThread#callbackLog]-[197]-[xxl-job, executor TriggerCallbackThread] <br>----------- xxl-job job callback finish.

2024-07-17 15:04:51 [com.xxl.job.core.thread.JobThread#run]-[133]-[xxl-job, JobThread-5-1721199853548] <br>----------- xxl-job job execute start -----------<br>----------- Param:
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02#logTestHandler02]-[75]-[xxl-job, JobThread-5-1721199853548] logTestHandler02...
2024-07-17 15:04:51 [com.xxl.job.core.thread.JobThread#run]-[179]-[xxl-job, JobThread-5-1721199853548] <br>----------- xxl-job job execute end(finish) -----------<br>----------- Result: handleCode=200, handleMsg = null
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$2#run]-[99]-[pool-2-thread-6] logTestHandler02 child thread...
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$2#run]-[99]-[pool-2-thread-1] logTestHandler02 child thread...
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$2#run]-[99]-[pool-2-thread-5] logTestHandler02 child thread...
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$2#run]-[99]-[pool-2-thread-3] logTestHandler02 child thread...
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$2#run]-[99]-[pool-2-thread-2] logTestHandler02 child thread...
2024-07-17 15:04:51 [com.xxl.job.executor.service.jobhandler.LogTestHandler02$2#run]-[99]-[pool-2-thread-4] logTestHandler02 child thread...
2024-07-17 15:04:51 [com.xxl.job.core.thread.TriggerCallbackThread#callbackLog]-[197]-[xxl-job, executor TriggerCallbackThread] <br>----------- xxl-job job callback finish.

2、实现Runnable、Callable

该方案是实现Runnable、Callable类，在创建Runnable或Callable实例对象时，将线程的inheritableThreadLocals进行深拷贝，当线程池线程执行该任务时，会先将深拷贝出来的inheritableThreadLocals赋值给自己的inheritableThreadLocals属性，从而达到的目的。

以下以Runnable为例，Callable同样修改方式：

public abstract class InheritableRunnable implements Runnable {

    private static volatile Field inheritableThreadLocalsField;

    private static volatile Class threadLocalMapType;

    private static volatile Method createInheritedMapMethod;

    private Object parentInheritableThreadLocals;

    /**
     * @Title: InheritableRunnable
     * @Description: 构造函数，在创建任务时，深拷贝提交任务线程的inheritableThreadLocals
     */
    public InheritableRunnable() {
        // 任务还没运行时，当前线程为提交任务的线程
        Thread parentThread = Thread.currentThread();

        // 通过反射获取线程的inheritableThreadLocals属性
        Field field = getInheritableThreadLocalsField();
        
        // 获取提交任务线程的inheritableThreadLocals属性的内容
        try {
            Object inheritableThreadLocals = field.get(parentThread);

            // 如果提交任务线程的inheritableThreadLocals不为空，则深拷贝一份出来
            if(inheritableThreadLocals != null) {
                Method method = getCreateInheritedMapMethod();

                parentInheritableThreadLocals = method.invoke(ThreadLocal.class, inheritableThreadLocals);
            }

        } catch (Exception e) {
            throw new RuntimeException(e);
        }

    }

    /**
     * @Title: run
     * @Description: 重写doRun方法即可，不要重写run
     */
    @Override
    public void run() {
        // 执行任务前对线程进行初始化
        beforeDoRun();

        doRun();
    }

    /**
     * @Title: doRun
     * @Description: 重写该方法即可，不要重写run
     */
    public abstract void doRun();

    /**
     * @Title: beforeDoRun
     * @Description: 在执行任务前，将threadLocal设置给线程
     */
    private void beforeDoRun() {

        if(parentInheritableThreadLocals == null) {
            return;
        }

        Field field = getInheritableThreadLocalsField();

        if(field == null) {
            return;
        }

        // 此处的thread是执行任务的线程
        Thread currentThread = Thread.currentThread();

        try {
            field.set(currentThread, parentInheritableThreadLocals);
        } catch (IllegalAccessException e) {
            throw new RuntimeException(e);
        }

    }

    /**
     * @Title: getInheritableThreadLocalsField
     * @Description: 获取Thread线程的inheritableThreadLocals字段，避免重复反射获取
     */
    private Field getInheritableThreadLocalsField() {
        // 由于Thread没有提供访问inheritableThreadLocals属性的方法，此处只能通过反射进行获取
        if(inheritableThreadLocalsField == null) {
            synchronized (InheritableRunnable.class) {
                if(inheritableThreadLocalsField == null) {
                    try {
                        Field field = Thread.class.getDeclaredField("inheritableThreadLocals");
                        field.setAccessible(true);
                        inheritableThreadLocalsField = field;

                        threadLocalMapType = field.getType();
                    } catch (NoSuchFieldException e) {
                        throw new RuntimeException(e);
                    }
                }
            }
        }
        return inheritableThreadLocalsField;
    }

    /**
     * @Title: getCreateInheritedMapMethod
     * @Description: 获取ThreadLocal的createInheritedMap方法，避免重复反射获取
     */
    private Method getCreateInheritedMapMethod() {
        // 由于Thread没有提供访问inheritableThreadLocals属性的方法，此处只能通过反射进行获取
        if(createInheritedMapMethod == null) {
            synchronized (InheritableRunnable.class) {
                if(createInheritedMapMethod == null) {
                    try {
                        Method method = ThreadLocal.class.getDeclaredMethod("createInheritedMap", threadLocalMapType);
                        method.setAccessible(true);
                        createInheritedMapMethod = method;
                    } catch (NoSuchMethodException e) {
                        throw new RuntimeException(e);
                    }
                }
            }
        }
        return createInheritedMapMethod;
    }

}

任务类：

@Component
public class LogTestHandler03 {

    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 InheritableRunnable() {
                @Override
                public void doRun() {
                    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 InheritableRunnable() {
                @Override
                public void doRun() {
                    XxlJobHelper.log("logTestHandler02 child thread...");
                    try {
                        Thread.sleep(1500);
                    } catch (InterruptedException e) {
                        throw new RuntimeException(e);
                    }
                }
            });
        }
    }

}

多次执行logTestHandler01和logTestHandler02，检查每次执行的日志，发现都能够记录正确

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

该方案实现思路主要是从线程池下手，线程进行任务提交（重载execute）时，线程池会将提交任务的线程的inheritableThreadLocals属性进行拷贝，在线程执行任务前，会执行beforeExecute，在该方法中，我们需要将inheritableThreadLocals属性赋值给当前执行任务的线程。然后线程会执行run方法，开始执行任务，最后执行beforeExecute方法，进行线程上下文清除。

源码解析（如果不想看这部分，拉到下面具体实现代码处即可）：

首先，在给出具体实现代码之前，先简单讲讲为何继承继承ThreadPoolExecutor，重载execute方法、重写beforeExecute、afterExecute方法，就可以实现我们的目的：

1）、重载execute方法

为了避免修改到ThreadPoolExecutor提供的原有的提交任务功能，我们选择重载execute或submit方法，使我们继承的线程池能够兼容原有的任务提交功能，也就是不改动原有的任务提交功能。

2）、重写beforeExecute、afterExecute方法

熟悉线程池的小伙伴都知道，线程池将运行的线程封装成了Worker类型，如下：

以下只摘贴部分代码，首先从类名我们可以得知，Worker是一个Runnable的实现类，也就是说，把Worker传入Thread中，即可运行run方法中的内容，也就是runWorker方法；其次再看构造函数，发现创建了Thread实例对象，并将当前这个Worker实例对象传入了，也就是说，该Thread实例对象调用start方法时，这个Worker任务就开始执行了。

private final class Worker
        extends AbstractQueuedSynchronizer
        implements Runnable
    {

        /** Thread this worker is running in.  Null if factory fails. */
        final Thread thread;

        Worker(Runnable firstTask) {
            setState(-1); // inhibit interrupts until runWorker
            this.firstTask = firstTask;
            this.thread = getThreadFactory().newThread(this);
        }

        /** Delegates main run loop to outer runWorker  */
        public void run() {
            runWorker(this);
        }
}

上面简单了分析了Worker，接下来看看这个Worker是怎么开始运行的，从ThreadPoolExecutor类中找到addWorker方法(只贴上关键代码)，可以看到，在addWoker方法中，创建了Worker，并且启动了Worker中的线程，至于addWorker在哪里调用到了，自行去看提交任务的execute或submit方法，此处不讲：

...
w = new Worker(firstTask);
final Thread t = w.thread;
...
...
...
if (workerAdded) {
    t.start();
    workerStarted = true;
}

到了这里，我们知道了线程被启动后，会调用Worker中的run方法，而run方法中调用了runWorker方法，这就是我们最关注的（同样只贴上关键代码），从代码中可以看出，线程启动之后，会循环从任务队列中获取任务，如果获取到了，在执行任务run方法之前，执行了beforeExecute方法，在执行完run方法之后，最终执行了afterExecute方法，而在ThreadPoolExecutor类中，这两个方法都是空实现，我们可以重写这两个方法：

while (task != null || (task = getTask()) != null) {
                w.lock();
                // If pool is stopping, ensure thread is interrupted;
                // if not, ensure thread is not interrupted.  This
                // requires a recheck in second case to deal with
                // shutdownNow race while clearing interrupt
                if ((runStateAtLeast(ctl.get(), STOP) ||
                     (Thread.interrupted() &&
                      runStateAtLeast(ctl.get(), STOP))) &&
                    !wt.isInterrupted())
                    wt.interrupt();
                try {
                    beforeExecute(wt, task);
                    Throwable thrown = null;
                    try {
                        task.run();
                    } catch (RuntimeException x) {
                        thrown = x; throw x;
                    } catch (Error x) {
                        thrown = x; throw x;
                    } catch (Throwable x) {
                        thrown = x; throw new Error(x);
                    } finally {
                        afterExecute(task, thrown);
                    }
                } finally {
                    task = null;
                    w.completedTasks++;
                    w.unlock();
                }
            }

protected void beforeExecute(Thread t, Runnable r) { }

protected void afterExecute(Runnable r, Throwable t) { }

具体实现代码：

好了，到了这一步，我们知道了为啥继承ThreadPoolExecutor，重载execute方法、重写beforeExecute、afterExecute方法，接下来就不废话了，直接给出具体的实现代码。

1）将上诉方法二中的getInheritableThreadLocalsField和getCreateInheritedMapMethod抽取成工具类，这里就不把代码贴上了，自行从方法二中的代码中抽取下，节省点文章篇幅。

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

public class ThreadPoolExecutorPlus extends ThreadPoolExecutor {

    private final Logger logger = LoggerFactory.getLogger(ThreadPoolExecutorPlus.class);

    private final Map<Runnable, Object> inheritableThreadLocalsMap = new ConcurrentHashMap<>();

    public ThreadPoolExecutorPlus(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
    }

    public ThreadPoolExecutorPlus(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory);
    }

    public ThreadPoolExecutorPlus(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, handler);
    }

    public ThreadPoolExecutorPlus(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler);
    }

    public void execute(Runnable command, boolean copyInheritableThreadLocals) throws IllegalAccessException, InvocationTargetException {

        if(copyInheritableThreadLocals) {

            Thread parentThread = Thread.currentThread();

            // 通过反射获取线程的inheritableThreadLocals属性
            Field field = InheritableThreadLocalReflectUtil.getInheritableThreadLocalsField();

            // 获取提交任务线程的inheritableThreadLocals属性的内容
            Object inheritableThreadLocals = field.get(parentThread);
            Object newInheritableThreadLocals = null;

            // 如果提交任务线程的inheritableThreadLocals不为空，则深拷贝一份出来
            if(inheritableThreadLocals != null) {
                Method method = InheritableThreadLocalReflectUtil.getCreateInheritedMapMethod();
                newInheritableThreadLocals = method.invoke(ThreadLocal.class, inheritableThreadLocals);
            }

            if(newInheritableThreadLocals != null) {
                inheritableThreadLocalsMap.put(command, newInheritableThreadLocals);
            }
        }

        execute(command);
    }

    @Override
    protected void beforeExecute(Thread t, Runnable r) {
        Object inheritableThreadLocals = inheritableThreadLocalsMap.get(r);

        if(inheritableThreadLocals != null) {

            Field field = InheritableThreadLocalReflectUtil.getInheritableThreadLocalsField();

            if(field == null) {
                return;
            }

            try {
                field.set(t, inheritableThreadLocals);
            } catch (IllegalAccessException e) {
                throw new RuntimeException(e);
            } finally {
                // 取完之后需要及时清除map保存的内容，避免后续忘记清理
                inheritableThreadLocalsMap.remove(r);
            }

        }

    }

    @Override
    protected void afterExecute(Runnable r, Throwable t) {
        // 用完可以手动将inheritableThreadLocals置为空，避免下次使用到旧的数据
        Field field = InheritableThreadLocalReflectUtil.getInheritableThreadLocalsField();

        if(field == null) {
            return;
        }

        try {
            Thread thread = Thread.currentThread();
            logger.debug("thread:" + thread);
            // 置为空，参考Thread的exit方法
            field.set(thread, null);
        } catch (IllegalAccessException e) {
            throw new RuntimeException(e);
        }

    }
}

3）修改xxl-job任务代码

@Component
public class LogTestHandler04 {

    private final ThreadPoolExecutorPlus threadPoolExecutor = new ThreadPoolExecutorPlus(
            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++) {
            try {
                threadPoolExecutor.execute(new Runnable() {
                    @Override
                    public void run() {
                        XxlJobHelper.log("logTestHandler01 child thread...");
                        try {
                            Thread.sleep(1500);
                        } catch (InterruptedException e) {
                            throw new RuntimeException(e);
                        }
                    }
                }, true);
            } catch (IllegalAccessException | InvocationTargetException e) {
                throw new RuntimeException(e);
            }
        }

    }

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

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

}

4）多次执行logTestHandler01和logTestHandler02，检查每次执行的日志，发现都能够记录正确

四、参考链接

https://zhuanlan.zhihu.com/p/473659523

明天再去学习

关注

6
点赞
踩
13

收藏

觉得还不错? 一键收藏
0
评论
InheritableThreadLocal遇到线程池出现的问题分析及解决方案

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

扫一扫