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

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,佇列容量擴大到幾千,並將拒絕策略改為丟擲異常的策略。

相關文章