背景:
一個上線了很久但是請求量很低(平均每天一兩次)的歷史功能突然出現空指針報錯:
我們翻開代碼定位到對應的報錯代碼:
結合堆棧和代碼可以確定是由於bdIdJobMap的值為null導致往bdIdEmployeeJobMap這個map中putAll的時候空指針了。
而bdIdJobMap又取自employeeJobMapThread.get(); 那麼這個employeeJobMapThread又是何物?
哦豁,employeeJobMapThread居然是個InheritableThreadLocal。
梳理一下報錯代碼的上下文邏輯如下:
是否和最近的上線有關?
相信大家都有這樣的共識:線上出現報錯,首先懷疑是否和最近的上線有關係。
我們做的第一件事情也是排查了近期的上線功能,從上線的功能點和相關代碼上來看都和這次報錯的代碼沒什麼關係,
因此初步排除了這個原因。所以接下來只能進一步瞭解代碼來排查原因了。
要搞清楚當前報錯的根因,毫無疑問肯定是要翻過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年上線之後功能一定是有問題的,前面説過,該功能上線之後沒人反饋過異常,所以也可以排除該原因。
從這些已知的信息來推斷,可以推斷出這段歷史代碼寫法雖然有隱患,但是不是引發當前空指針的的原因。
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:
排查代碼的時候發現異步任務代碼沒有做任何的異常處理,這其實是很坑的。
有經驗的同學應該知道,線程池裏面提交異步任務如果沒有做異常處理,出現異常的話不會有任何的日誌信息。
本地運行的時候會打印到控制枱,但是線上控制枱的信息可不會記錄到日誌裏面。
所以經常遇到異步任務執行結果不符合預期,但是線上沒有任何相關日誌就是這個原因。
我們這裏有日誌是因為使用的線程池是二次封裝過的,裏面對異步任務做了兜底的異常記錄。
總結:
前面分析到了導致空指針的原因是線程池共用導致的老代碼報錯,而共用這個線程池的代碼是新上線的功能引入的。
這就打臉了開頭我們檢查了上線的功能與此無關,實則有關。
只是我們評估複用線程池的影響時,很難想到會有這樣的影響,通常我們會考慮:
針對InheritableThreadLocal,我個人的建議是:
針對如何有效的應對業務研發遇到的一些“疑難雜症”,我的建議是:
最後,願天下沒有故障,沒有線上問題,沒有bug。