線程池異常黑洞及其防范策略
1. 問題&分析
迭代剛上線，小艾同學(xué)又接到了一線業(yè)務(wù)的投訴，一起看下本次遇到的又是什么問題。
1.1. 案例
上周接到一個需求，需要對系統(tǒng)中的核心操作增加操作日志，也就是在操作完成后對操作人、操作時間等信息進行詳細記錄。核心包括：創(chuàng)建訂單、取消訂單、刪除訂單、修改價格等。
在需求分析時，小艾做了深度思考：記錄操作日志不能影響正常的業(yè)務(wù)操作，比如創(chuàng)建訂單，哪怕是操作日志記錄失敗，也不能導(dǎo)致下單失敗。
當然，方案1便是，記錄日志的邏輯使用 try-catch 進行處理，哪怕是拋出異常也不能影響原來的主流程。
圖片
這樣做確實能控制住異常，但由于是在主線程中運行，這樣會導(dǎo)致整個流程的處理時間加長。這時，小艾想起了線程池的異常操作，整體如下：
圖片
這個方案好處多多：
- 可以非常好對異常進行隔離，任務(wù)執(zhí)行發(fā)生異常也不會影響主流程
- 操作日志在線程池中異步處理，不會占用主線程的時間，整體操作時間變化不大
核心代碼如下：
@GetMapping("createOrder")
public RestResult<String> createOrder(Integer taskId){
log.info("begin to create Order {}", taskId);
// 創(chuàng)建訂單
doCreateOrder(taskId);
log.info("end to create Order {}", taskId);
// 異步保存操作日志
log.info("Begin to Submit Task {}", taskId);
this.executorService.execute(new SaveOperationLogTask(taskId));
log.info("Success to Submit Task {}", taskId);
return RestResult.success("提交成功");
}
// 保存操作日志 Task
@Slf4j
public class SaveOperationLogTask implements Runnable {
// 省略部分代碼
@Override
public void run() {
log.info("Begin to save operation");
// 保存日志
saveLog();
log.info("Success to Run task {}", this.taskId);
}
private void saveLog() {
// 實際執(zhí)行業(yè)務(wù)邏輯，保存到數(shù)據(jù)庫
}
}在收到業(yè)務(wù)反饋時，小艾第一時間查看日志，居然沒有找到任何異常信息。難道是業(yè)務(wù)反饋信息有問題？根據(jù)業(yè)務(wù)提供的訂單號，在數(shù)據(jù)庫中確實沒有找到操作記錄，好奇怪呀。
從日志中提取出 正常 和 異常 信息，分別如下：
正常日志：
圖片
可以看出：
- 在主線程中完成創(chuàng)建訂單和提交任務(wù)操作
- 在線程池線程中完成操作日志保存操作
- 在數(shù)據(jù)庫中能看到詳細的操作信息
異常日志：
圖片
可以看出少了些信息：
- 主線程操作沒有變化，完成了創(chuàng)建訂單和提交任務(wù)操作
- 線程池線程只打印了開始執(zhí)行的日志，未見到執(zhí)行成功日志
- 數(shù)據(jù)中也沒有操作信息
對比日志可見，==保存操作日志的任務(wù)執(zhí)行失敗，同時系統(tǒng)沒有拋出任何異常！！！==
1.2. 問題分析
核心還是對 線程池的核心 API 不熟悉，當使用 `execute()` 方法提交任務(wù)時，異常信息不會直接拋出給調(diào)用者。這是因為線程池處理任務(wù)的方式是，將這些任務(wù)封裝到一個 `Runnable` 中去執(zhí)行。`Runnable.run()` 方法沒有任何拋出異常的聲明，所以在運行 `Runnable` 時產(chǎn)生的異常只會被內(nèi)部捕獲，不會拋出。
線程池中提供兩者函數(shù)：
- `execute()` 方法用于提交不需要返回值的任務(wù)，所以無法判斷任務(wù)是否被線程池成功執(zhí)行。
- `submit()` 方法用于提交需要返回值的任務(wù)。線程池會返回一個 future 類型的對象，通過這個 future 對象可以判斷任務(wù)是否執(zhí)行成功。
2. 解決方案
最大困擾原因是：出問題后沒有任何信息。所以對應(yīng)的解決方案便是：讓系統(tǒng)能夠打印異常棧暴露異常原因。
2.1. 手工拋出異常
最簡單方式便是，在Task代碼中通 try-catch 手工捕獲并打印異常日志。
詳細代碼如下：
@Slf4j
public class SaveOperationLogTask1 implements Runnable {
// 省略非核心代碼
@Override
public void run() {
try {
int result = RandomUtils.nextInt() / this.taskId;
log.info("Success to Run task {}", this.taskId);
}catch (Exception e) {
log.error("failed to run task {}", taskId, e);
}
}
}當出現(xiàn)異常數(shù)據(jù)時，日志如下：
圖片
可以看出，從 SaveOperationLogTask1 類中清楚的打印異常信息。
2.2. 封裝 Runnable 統(tǒng)一管理異常
每個 Task 都手工添加 try-catch 邏輯，不僅工作量大也非常容易出現(xiàn)遺漏場景，我們需要一個更好的方案。
可以構(gòu)建一個 Runnable 的封裝類來對異常進行統(tǒng)一處理，詳細代碼如下：
@Slf4j
public class LogBasedTaskWrapper implements Runnable {
private final Runnable runnable;
public LogBasedTaskWrapper(Runnable runnable) {
this.runnable = runnable;
}
@Override
public void run() {
try {
this.runnable.run();
}catch (Exception e) {
log.error("Filed to run task {}", runnable, e);
}
}
}
// 在提交任務(wù)時，使用 LogBasedTaskWrapper 對 Task 進行封裝即可
log.info("Begin to Submit Task {}", taskId);
Runnable task = new SaveOperationLogTask(taskId);
this.executorService.execute(new LogBasedTaskWrapper(task));
log.info("Success to Submit Task {}", taskId);當出現(xiàn)異常數(shù)據(jù)時，日志如下：
圖片
可以看出，從 LogBasedTaskWrapper 類中清楚的打印異常信息。
2.3. 定制化線程工廠
Wrapper 機制不錯，但需要對 Task 進行封裝操作，還是容易被遺漏，我們還需要更簡單的方式。
可以對線程池的線程工廠進行定制，對為捕獲異常進行特殊處理，詳細代碼如下：
executorServiceV2 = new ThreadPoolExecutor(4, 4,
0L, TimeUnit.MILLISECONDS,
new LinkedBlockingQueue<Runnable>(20),
new BasicThreadFactory.Builder()
.namingPattern("BlackHole_thread-%d")
// 設(shè)置為捕獲異常處理器
.uncaughtExceptionHandler((t, e) -> log.error("Failed to run task", e))
.build(),
new ThreadPoolExecutor.AbortPolicy());
// 然后使用 executorServiceV2 即可
// 異步保存操作日志
log.info("Begin to Submit Task {}", taskId);
this.executorServiceV2.execute(new SaveOperationLogTask(taskId));
log.info("Success to Submit Task {}", taskId);核心代碼就一句：.uncaughtExceptionHandler((t, e) -> log.error("Failed to run task", e))。當出現(xiàn)未捕獲異常時，會統(tǒng)一被 UncaughtExceptionHandler 處理。詳細日志如下：
圖片
從日志中看到，從 ExceptionBlackHoleFixController 類中對異常進行處理。
這是一勞永逸的方法，也是最鼓勵的方法。
2.4. 使用 CompletableFuture
當使用 submit 提交任務(wù)時，會返回 Futrue 對象，通過 Future 的 get 方法便可以獲取任務(wù)運行的異常信息，但這樣會阻塞主線程導(dǎo)致接口響應(yīng)時間過長。
這種情況下，可以使用更高級的 CompletableFuture，向 CompletableFuture 設(shè)置異常處理器后，出現(xiàn)異常時會自動調(diào)用處理器，核心代碼如下：
// 異步保存操作日志
log.info("Begin to Submit Task {}", taskId);
CompletableFuture<Void> completableFuture = CompletableFuture.runAsync(new SaveOperationLogTask(taskId), this.executorService);
completableFuture.exceptionally(e -> {
log.error("Failed to Submit Task", e);
return null;
}
);
log.info("Success to Submit Task {}", taskId);當出現(xiàn)異常數(shù)據(jù)時，日志如下：
圖片
image
從日志中看到，從 ExceptionBlackHoleFixController 類中對異常進行處理。
3. 示例&源碼
代碼倉庫：https://gitee.com/litao851025/learnFromBug
代碼地址：https://gitee.com/litao851025/learnFromBug/tree/master/src/main/java/com/geekhalo/demo/thread/exceptionblackhole
