作者:京东零售 田超辉

背景:

一个上线了很久但是请求量很低(平均每天一两次)的历史功能突然出现空指针报错:


在这里插入图片描述



我们翻开代码定位到对应的报错代码:

在这里插入图片描述



结合堆栈和代码可以确定是由于bdIdJobMap的值为null导致往bdIdEmployeeJobMap这个map中putAll的时候空指针了。

而bdIdJobMap又取自employeeJobMapThread.get(); 那么这个employeeJobMapThread又是何物?



在这里插入图片描述



哦豁,employeeJobMapThread居然是个InheritableThreadLocal。

梳理一下报错代码的上下文逻辑如下:

1.首先在当前主线程中对InheritableThreadLocal类型变量employeeJobMapThread进行赋值

2.把耗时操作提交到线程池中异步执行,在异步任务中去获取employeeJobMapThread的值(其中线程池配置的coreSize/maxSize均为4,queue大小为3000)

3.在主线程中执行employeeJobMapThread.remove(),在异步任务完成之后没有执行employeeJobMapThread.remove()

4.最后在异步任务中通过employeeJobMapThread获取到的值为null导致后续操作空指针



是否和最近的上线有关?

相信大家都有这样的共识:线上出现报错,首先怀疑是否和最近的上线有关系。

我们做的第一件事情也是排查了近期的上线功能,从上线的功能点和相关代码上来看都和这次报错的代码没什么关系,

因此初步排除了这个原因。所以接下来只能进一步了解代码来排查原因了。

要搞清楚当前报错的根因,毫无疑问肯定是要翻过InheritableThreadLocal这座小山啦。



简单聊下InheritableThreadLocal:

提起ThreadLocal,大家应该相对都比较熟悉了,比如存放登录用户信息到ThreadLocal变量中,然后在接口层可以比较方便的获取登录用户,帮助开发提效。

但是对于InheritableThreadLocal,有不少同学都不太了解。

挑重点来说,InheritableThreadLocal相比ThreadLocal多一个能力:在创建子线程Thread时,子线程Thread会自动继承父线程的InheritableThreadLocal信息到子线程中,进而实现在在子线程获取父线程的InheritableThreadLocal值的目的。

举个简单的栗子对比下InheritableThreadLocal和ThreadLocal:


public class InheritableThreadLocalTest {

    private static final ThreadLocal<String> threadLocal = new ThreadLocal<>();
    private static final InheritableThreadLocal<String> inheritableThreadLocal = new InheritableThreadLocal<>();

    public static void main(String[] args) {
        testThreadLocal();
        testInheritableThreadLocal();
    }

    /**
     * threadLocal测试
     */
    public static void testThreadLocal() {
        // 在主线程中设置值到threadLocal
        threadLocal.set("我是父线程threadLocal的值");

        // 创建一个新线程并启动
        new Thread(() -> {
            // 在子线程里面无法获取到父线程设置的threadLocal,结果为null
            System.out.println("从子线程获取到threadLocal的值: " + threadLocal.get());
        }).start();
    }

    /**
     * inheritableThreadLocal测试
     */
    public static void testInheritableThreadLocal() {
        // 在主线程中设置一个值到inheritableThreadLocal
        inheritableThreadLocal.set("我是父线程inheritableThreadLocal的值");

        // 创建一个新线程并启动
        new Thread(() -> {
            // 在子线程里面可以自动获取到父线程设置的inheritableThreadLocal
            System.out.println("从子线程获取到inheritableThreadLocal的值: " + inheritableThreadLocal.get());
        }).start();
    }

}

执行结果:



在这里插入图片描述



可以看到子线程中可以获取到父线程设置的inheritableThreadLocal值,但不能获取到父线程设置的threadLocal值。

为什么InheritableThreadLocal能够做到这点呢?

是因为在父线程创建子线程Thread的时候,Thread的构造器内部会自动继承父线程的InheritableThreadLocal到子线程。

Thread源码这两处地方解释了原因:



在这里插入图片描述



init方法内部实现:



在这里插入图片描述



通过这个简单的介绍可以帮助对于InheritableThreadLocal不了解的同学有一个初步的了解,本文不是专门介绍InheritableThreadLocal的深入原理,所以就不展开聊了,大家感兴趣可以自己进一步探索。

验证InheritableThreadLocal+线程池:

前面介绍了InheritableThreadLocal可以自动把父线程的InheritableThreadLocal信息继承到子线程Thread中。

但是在业务项目中真正需要用到子线程的时候正经人谁自己new Thread,咱可是用线程池的。

当然了,就像文章开头说明的,这次报错的代码里面也用线程池来执行异步任务。

那么InheritableThreadLocal+线程池的组合会摩擦出什么样的火花呢?

我把这次报错的代码精简之后得到下面的示例(实际代码中往InheritableThreadLocal赋的值类型不是字符串,后面会提到):

package com.dada.bd.data.service;

import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

public class InheritableThreadLocalWithThreadPoolTest {

    private static final InheritableThreadLocal<String> inheritableThreadLocal = new InheritableThreadLocal<>();
    private static final ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(
            2,
            2,
            0L,
            TimeUnit.MILLISECONDS,
            new LinkedBlockingQueue<Runnable>(3000),
            new ThreadPoolExecutor.CallerRunsPolicy()
    );

    public static void main(String[] args) {
        testInheritableThreadLocalWithThreadPool();
        threadPoolExecutor.shutdown();
    }

    /**
     * inheritableThreadLocal+线程池测试
     */
    public static void testInheritableThreadLocalWithThreadPool() {
        // 1. 在主线程中设置一个值到inheritableThreadLocal
        inheritableThreadLocal.set("我是父线程inheritableThreadLocal的值");

        // 2. 提交异步任务到线程池
        threadPoolExecutor.execute(() -> {
            // 3. 在线程池-子线程里面可以获取到父线程设置的inheritableThreadLocal吗?
            System.out.println("从线程池-子线程获取到inheritableThreadLocal的值: " + inheritableThreadLocal.get());
        });

        // 4. 清除inheritableThreadLocal
        inheritableThreadLocal.remove();
    }

}



在这里插入图片描述



执行结果如图所示,可以看到在线程池里面也可以获取到父线程设置的inheritableThreadLocal值。

接下来我们来分析下InheritableThreadLocal+线程池的执行过程:



在这里插入图片描述



也就说只有在以下这两个场景下才会继承父线程的InheritableThreadLocal:

1.线程池当前线程数 < 核心线程数

2.线程池当前线程数 >= 核心线程数 && 队列已满 && 线程数 < 最大线程数(本次线上报错的代码使用的线程池设置的coreSize和maxSize一致,所以走不到该场景)

其他情况都是在复用线程池现有的Thread,自然也就不会继承父线程的InheritableThreadLocal。

我们提交多个异步任务到线程池来验证下:

package com.dada.bd.data.service;

import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

public class InheritableThreadLocalWithThreadPoolTest {

    private static final InheritableThreadLocal<String> inheritableThreadLocal = new InheritableThreadLocal<>();
    private static final ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(
            2,
            2,
            0L,
            TimeUnit.MILLISECONDS,
            new LinkedBlockingQueue<Runnable>(3000),
            new ThreadPoolExecutor.CallerRunsPolicy()
    );

    public static void main(String[] args) {
        testInheritableThreadLocalWithThreadPool("张三");
        testInheritableThreadLocalWithThreadPool("李四");
        testInheritableThreadLocalWithThreadPool("王五");
        testInheritableThreadLocalWithThreadPool("赵六");
        testInheritableThreadLocalWithThreadPool("孙七");
        threadPoolExecutor.shutdown();
    }

    /**
     * inheritableThreadLocal+线程池测试
     */
    public static void testInheritableThreadLocalWithThreadPool(String param) {
        // 1. 在主线程中设置一个值到inheritableThreadLocal
        inheritableThreadLocal.set(param);

        // 2. 提交异步任务到线程池
        threadPoolExecutor.execute(() -> {
            // 3. 在线程池-子线程里面可以获取到父线程设置的inheritableThreadLocal吗?
            System.out.println("线程名: " + Thread.currentThread().getName() + ", 父线程设置的inheritableThreadLocal值: " + param + ", 子线程获取到inheritableThreadLocal的值: " + inheritableThreadLocal.get());
        });

        // 4. 清除inheritableThreadLocal
        inheritableThreadLocal.remove();
    }

}



在这里插入图片描述

执行结果用表格形式展示如下:

步骤使用线程池结果解释说明
提交第一个异步任务值为【张三】创建Thread:pool-1-thread-1自动继承父线程的InheritableThreadLocal值【张三】到pool-1-thread-1
提交第二个异步任务值为【李四】创建Thread:pool-1-thread-2自动继承父线程的InheritableThreadLocal值【李四】到pool-1-thread-2
提交第三个异步任务值为【王五】复用Thread:pool-1-thread-1没有自动继承父线程的InheritableThreadLocal值【王五】,所以拿到了第一个任务提交时Thread继承下来的值【张三】
提交第四个异步任务值为【赵六】复用Thread:pool-1-thread-2没有自动继承父线程的InheritableThreadLocal值【赵六】,所以拿到了第一个任务提交时Thread继承下来的值【李四】

可以看到InheritableThreadLocal+线程池的组合,会面临InheritableThreadLocal污染的问题,即异步任务可能取到其他父线程设置的InheritableThreadLocal值。

有同学会提到我们不是在代码里面加了inheritableThreadLocal.remove()来清除inheritableThreadLocal的吗?为什么没有清除掉呢?

这是因为此时我们清除的只是父线程的inheritableThreadLocal,而没有清除子线程的inheritableThreadLocal的缘故。



为什么InheritableThreadLocal污染对线上没有产生影响?

既然InheritableThreadLocal+线程池的组合,会存在InheritableThreadLocal污染的问题,那岂不是线上报错的这段代码也存在这个问题?

再次检查代码,确认历史代码的确存在这个问题,

但是,这个代码上线2年多为啥一直稳定运行且没有用户反馈过功能有问题?只有最近突然出现报错?一时之间脑袋懵懵的。

在这里插入图片描述

仔细检代码之后发现:

这段代码在父子线程之间通过InheritableThreadLocal类型变量employeeJobMapThread传递的值是【全量的<人员Id, 该人员基本信息>结构的map】,可以近乎看做是一个不变的常量,所以虽然异步任务会拿到污染的数据,也是正常可以用的,没有产生业务影响。

这种感觉怎么说呢,只能说感叹前人的智慧,把几乎不可能做到了可能\~

好了,到这里我们解释了为什么这段代码上线这么久一直没问题,因为代码确实有InheritableThreadLocal污染问题,但被污染了也不影响使用。。。所以从最终结果来看确实可以正常运行。



在这里插入图片描述





什么原因导致子线程获取到的InheritableThreadLocal值是null?

但是。。。说了这么多,还是不能解释为什么线上代码获取到的inheritableThreadLocal值会是null。

1.难道父线程设置的inheritableThreadLocal值可能会是null?

检查代码发现父线程设置的inheritableThreadLocal不可能为null,顶多会是空集合:



在这里插入图片描述



2.难道是线程池创建之后通过prestartAllCoreThreads初始化了核心线程,在执行异步任务的时候,都是复用的已有线程导致的?

检查了对应线程池的初始化代码,发现并没有初始化核心线程,也排除了这个可能。而且如果真的是该原因22年上线之后功能一定是有问题的,前面说过,该功能上线之后没人反馈过异常,所以也可以排除该原因。



•该功能22年上线之间2年多一直没人反馈,大概率该功能之前很长时间是正常的,近期由于某个原因导致功能异常

•虽然历史代码的用法存在子任务中获取到的InheritableThreadLocal被污染的问题,但是被污染的值也能用,不影响正确性

•只要线程池中的线程初始化的时候继承了正确的InheritableThreadLocal值,后续就不会被清除掉,也就可以正常运行功能

从这些已知的信息来推断,可以推断出这段历史代码写法虽然有隐患,但是不是引发当前空指针的的原因。

3.剩下的只有一种可能:存在线程池的共用。

在执行这个报错的异步任务的时候,复用了某个已有的线程A,并且当时创建该线程A的时候,没有继承InheritableThreadLocal,进而导致后面复用该线程的时候,从InheritableThreadLocal获取到的值为null。

而只要是通过这段历史代码创建的线程一定是没问题的,所以一定是存在其他业务共用了这个线程池,并且这个业务优先执行进而初始化了线程池的线程,导致线程池的线程没有继承InheritableThreadLocal。

如下代码示例:

package com.dada.bd.data.service;

import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

public class InheritableThreadLocalWithThreadPoolTest {

    private static final InheritableThreadLocal<String> inheritableThreadLocal = new InheritableThreadLocal<>();
    // 这里线程池core/max数量都只有2
    private static final ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(
            2,
            2,
            0L,
            TimeUnit.MILLISECONDS,
            new LinkedBlockingQueue<Runnable>(3000),
            new ThreadPoolExecutor.CallerRunsPolicy()
    );

    public static void main(String[] args) {
        // 先执行了不涉及InheritableThreadLocal的子任务初始化线程池线程
        testAnotherFunction();
        testAnotherFunction();
        // 后执行了本次的历史代码,其涉及InheritableThreadLocal
        testInheritableThreadLocalWithThreadPool("张三");
        testInheritableThreadLocalWithThreadPool("李四");
        threadPoolExecutor.shutdown();
    }

    /**
     * inheritableThreadLocal+线程池测试
     */
    public static void testInheritableThreadLocalWithThreadPool(String param) {
        // 1. 在主线程中设置一个值到inheritableThreadLocal
        inheritableThreadLocal.set(param);

        // 2. 提交异步任务到线程池
        threadPoolExecutor.execute(() -> {
            // 3. 在线程池-子线程里面可以获取到父线程设置的inheritableThreadLocal吗?
            System.out.println("线程名: " + Thread.currentThread().getName() + ", 父线程设置的inheritableThreadLocal值: " + param + ", 子线程获取到inheritableThreadLocal的值: " + inheritableThreadLocal.get());
        });

        // 4. 清除inheritableThreadLocal
        inheritableThreadLocal.remove();
    }

    /**
     * 模拟另一个独立的功能
     */
    public static void testAnotherFunction() {
        // 提交异步任务到线程池
        threadPoolExecutor.execute(() -> {
            // 在线程池-子线程里面可以获取到父线程设置的inheritableThreadLocal吗?
            System.out.println("线程名: " + Thread.currentThread().getName() + ", 线程池-子线程摸个鱼");
        });
    }

}

执行结果:

在这里插入图片描述

在项目里面搜一下看看,果真如此,有2出地方在用这个线程池,并且另外的一处代码中提交的异步任务不涉及inheritableThreadLocal:

在这里插入图片描述

示意图如下:

逻辑执行顺序为:创建线程池 - 执行功能A - 执行功能A - 执行功能B

其中:

功能A全流程均不涉及InheritableThreadLocal

功能B对应报错的代码,主线程设置InheritableThreadLocal并且在子线程使用

在这里插入图片描述



至此,线上报错的根因确定了:就是因为InheritableThreadLocal + 线程池共用导致。



扩展一下:

假如执行顺序是这样呢:创建线程池 - 执行功能B - 执行功能B - 执行功能A
在这里插入图片描述


结局居然是一切安好。



假如执行顺序是这样呢:创建线程池 - 执行功能B - 执行功能A - 执行功能B

在这里插入图片描述



发现了吗?如果应用启动之后功能B先执行并且初始化了线程池所有核心线程,那么一切正常,否则就可能报错。

也就是说功能B是否正常还看运气的,运气好就正常执行,运气不好就报空指针的错。



这你敢信?

在这里插入图片描述



小插曲:

这个问题的排查当中还遇到了2个小插曲:

插曲1:

最初怀疑是线程池复用导致的,但是在IDEA里面搜代码的时候粗心大意没有看到其他地方在复用线程池。

因此期间一度自我怀疑见鬼了,导致本来可以一两个小时确定根因的,结果饶了弯路多花了两个小时才确定根因。

所以说排查问题的时候每一步都要保持细心,得出的每一个结论都应该是证据确凿,理由充分

否则会让自己兜兜转转浪费宝贵的时间。



插曲2:

排查代码的时候发现异步任务代码没有做任何的异常处理,这其实是很坑的。

有经验的同学应该知道,线程池里面提交异步任务如果没有做异常处理,出现异常的话不会有任何的日志信息。

本地运行的时候会打印到控制台,但是线上控制台的信息可不会记录到日志里面。

所以经常遇到异步任务执行结果不符合预期,但是线上没有任何相关日志就是这个原因。

我们这里有日志是因为使用的线程池是二次封装过的,里面对异步任务做了兜底的异常记录。



总结:

前面分析到了导致空指针的原因是线程池共用导致的老代码报错,而共用这个线程池的代码是新上线的功能引入的。

这就打脸了开头我们检查了上线的功能与此无关,实则有关。

只是我们评估复用线程池的影响时,很难想到会有这样的影响,通常我们会考虑:

1.是否会影响共用该线程池的老功能响应时间边长

2.是否存在父子任务共用线程池导致可能产生死锁

针对InheritableThreadLocal,我个人的建议是:

1.InheritableThreadLocal(其实ThreadLocal也一样)不适合应用于业务代码中,因为他们都是隐式的参数传递,而业务系统中好维护的代码应当是显式的参数传递(我们这个线上问题就采用该方式)

2.框架类代码才是InheritableThreadLocal和ThreadLocal主要发光发热的地方,因为对应的研发水平通常较高,且代码经过严格测试验证,并且较少变动。而业务系统研发水平参差不齐,且经常会发生同步操作变异步等

3.虽然InheritableThreadLocal不建议在业务代码中使用,但是我们还是需要掌握它,不为别的,只有掌握它的优缺点才能告诉自己和他人为什么应该在业务代码中放弃使用它



针对如何有效的应对业务研发遇到的一些“疑难杂症”,我的建议是:

1.大胆提出合理的假设,小心谨慎进行验证

2.没有充足理由,不要轻易下结论

3.没有头绪时,休息一下,或找合适的人一起探讨,给自己打开新的思路



最后,愿天下没有故障,没有线上问题,没有bug。


京东云开发者
3.3k 声望5.4k 粉丝

京东云开发者(Developer of JD Technology)是京东云旗下为AI、云计算、IoT等相关领域开发者提供技术分享交流的平台。