震驚，程式執行一半就不執行了

changlong2022發表於2024-07-05

近期，我們的專案在生產環境中執行時頻繁出現一個難以理解的Bug。這個問題頗為有趣，因此我決定在此記錄下整個排查過程。

首先，讓我模擬一下出問題的程式碼：

XController.java

@Resource
private XService xService;

@GetMapping("/method1")
public void method1(){
System.out.println("a");
xService.method2();
}

XService.java

@Async
public void method2() {
System.out.println("b");
}

　　

如上程式碼所示，邏輯相當簡單。在Controller中的`method1`裡，我們首先列印一個“a”，然後呼叫Service的`method2`，在`method2`中列印一個“b”。按照常理，每次呼叫`method1`都應該依次列印“a”和“b”。大多數人可能都會這樣認為，也確信結果必然如此。然而，事實卻是有時只列印了“a”，而沒有列印“b”，並且沒有任何異常日誌。

這個現象超出了我們的認知，一時間讓人感到困惑。程式為何執行一半就停止了？難道多年的認知要被推翻，全世界都錯了嗎？

仔細思考後，作為一個擁有多年CRUD經驗的程式設計師，我認為問題應該還是出在我自己身上。那麼，問題究竟在哪裡呢？

透過對比常規程式碼與這段程式碼的區別，我發現這段程式碼唯一特殊的地方在於使用了`@Async`註解。另外，這部分程式碼近期才開始顯現出問題，難道是其他地方的改動影響到了這裡？

有兩個排查方向：一是調查`@Async`的使用情況；二是檢查近期的程式碼更改。

眾所周知，`@Async`的作用是讓系統在新的執行緒中執行`method2`。但為什麼有時不執行呢？難道是系統沒有開啟新執行緒？或者是執行緒不夠用了？通常情況下，`@Async`使用的是Spring預設的執行緒池，而這個執行緒池的大小几乎是無限的。我們系統的訪問量並未達到這個級別。

會不會是`@Async`使用了其他的執行緒池？為了核實這一點，我檢視了日誌檔案，發現在列印“a”的那行日誌前面有執行緒名“myThread-1”。這個執行緒名顯然是自定義的，並非Spring自帶的。

進一步在程式碼中全域性搜尋“myThread”關鍵字，果然發現了自定義執行緒池的地方。經過檢查程式碼提交記錄，確認是其他同事最近提交的程式碼引起的問題。

再來看自定義執行緒池的配置：

executor.setMaxPoolSize(1);
executor.setQueueCapacity(50);
executor.setRejectedExecutionHandler(new ThreadPoolExecutor.DiscardPolicy());

　　

執行緒池中只有一個執行緒，佇列容量為50。這意味著同時只能有50個任務排隊等待執行。拒絕策略採用了`DiscardPolicy`，該策略會在佇列已滿時直接拋棄新任務，且不丟擲異常。

覆盤系統實際執行過程：當`method1`執行到`method2`時，會使用自定義執行緒池中的唯一一個執行緒`myThread-1`來執行。如果`myThread-1`已有任務在執行，新任務會進入佇列排隊。若任務過多超過50個，新任務就會被拋棄，不再執行。

由於任務被拋棄，這就解釋了為何沒有列印“b”。同時，由於採用了`DiscardPolicy`策略，因此沒有異常日誌產生。

知道了問題的原因，解決方案就變得清晰了。有兩種解決方法：
1. 移除自定義執行緒池，迴歸使用預設執行緒池（儘管預設執行緒池存在無限佇列問題，但我們的專案負載不會那麼大）。
2. 調整自定義執行緒池的配置，增加執行緒數至8，佇列容量擴大到幾千，並將拒絕策略改為丟擲異常的策略。

相關文章