1. 程式人生 > >一次 HashSet 所引起的併發問題

一次 HashSet 所引起的併發問題

背景
上午剛到公司,準備開始一天的摸魚之旅時突然收到了一封監控中心的郵件。

心中暗道不好,因為監控系統從來不會告訴我應用完美無 bug,其實系統挺猥瑣。

開啟郵件一看,果然告知我有一個應用的執行緒池佇列達到閾值觸發了報警。

由於這個應用出問題非常影響使用者體驗;於是立馬讓運維保留現場 dump 執行緒和記憶體同時重啟應用,還好重啟之後恢復正常。於是開始著手排查問題。
分析
首先了解下這個應用大概是做什麼的。

簡單來說就是從 MQ 中取出資料然後丟到後面的業務執行緒池中做具體的業務處理。

而報警的佇列正好就是這個執行緒池的佇列。

跟蹤程式碼發現構建執行緒池的方式如下:

ThreadPoolExecutor executor = new ThreadPoolExecutor(coreSize, maxSize,
 0L, TimeUnit.MILLISECONDS,
 new LinkedBlockingQueue<Runnable>());;
 put(poolName,executor);

採用的是預設的 LinkedBlockingQueue 並沒有指定大小(這也是個坑),於是這個佇列的預設大小為 Integer.MAX_VALUE。

由於應用已經重啟,只能從僅存的執行緒快照和記憶體快照進行分析。
記憶體分析

先利用 MAT 分析了記憶體,的到了如下報告。

一次 HashSet 所引起的併發問題
一次 HashSet 所引起的併發問題
其中有兩個比較大的物件,一個就是之前執行緒池存放任務的 LinkedBlockingQueue,還有一個則是 HashSet。

當然其中佇列佔用了大量的記憶體,所以優先檢視,HashSet 一會兒再看。

由於佇列的大小給的夠大,所以結合目前的情況來看應當是執行緒池裡的任務處理較慢,導致佇列的任務越堆越多,至少這是目前可以得出的結論。
執行緒分析

再來看看執行緒的分析,這裡利用 fastthread.io 這個網站進行執行緒分析。

因為從表現來看執行緒池裡的任務遲遲沒有執行完畢,所以主要看看它們在幹嘛。

正好他們都處於 RUNNABLE 狀態,同時堆疊如下:
一次 HashSet 所引起的併發問題
發現正好就是在處理上文提到的 HashSet,看這個堆疊是在查詢 key 是否存在。通過檢視 312 行的業務程式碼確實也是如此。

這裡的執行緒名字也是個坑,讓我找了好久。

定位
分析了記憶體和執行緒的堆疊之後其實已經大概猜出一些問題了。

這裡其實有一個前提忘記講到:

這個告警是凌晨三點發出的郵件,但並沒有電話提醒之類的,所以大家都不知道。

到了早上上班時才發現並立即 dump 了上面的證據。

所有有一個很重要的事實:這幾個業務執行緒在查詢 HashSet 的時候運行了 6 7 個小時都沒有返回。

通過之前的監控曲線圖也可以看出:
一次 HashSet 所引起的併發問題
作業系統在之前一直處於高負載中,直到我們早上看到報警重啟之後才降低。

同時發現這個應用生產上執行的是 JDK1.7 ,所以我初步認為應該是在查詢 key 的時候進入了 HashMap 的環形連結串列導致 CPU 高負載同時也進入了死迴圈。

為了驗證這個問題再次 review 了程式碼。

整理之後的虛擬碼如下:

//執行緒池
private ExecutorService executor;
private Set<String> set = new hashSet();
private void execute(){

while(true){
//從 MQ 中獲取資料
String key = subMQ();
executor.excute(new Worker(key)) ;
}
}
public class Worker extends Thread{
private String key ;
public Worker(String key){
this.key = key;br/>}
@Override
private void run(){
if(!set.contains(key)){
//資料庫查詢
if(queryDB(key)){
set.add(key);
return;
}
}
//達到某種條件時清空 set
if(flag){
set = null ;
}
}
}
大致的流程如下:

源源不斷的從 MQ 中獲取資料。
將資料丟到業務執行緒池中。
判斷資料是否已經寫入了 Set。
沒有則查詢資料庫。
之後寫入到 Set 中。
這裡有一個很明顯的問題,那就是作為共享資源的 Set 並沒有做任何的同步處理。

這裡會有多個執行緒併發的操作,由於 HashSet 其實本質上就是 HashMap,所以它肯定是執行緒不安全的,所以會出現兩個問題:

Set 中的資料在併發寫入時被覆蓋導致資料不準確。
會在擴容的時候形成環形連結串列。
第一個問題相對於第二個還能接受。

通過上文的記憶體分析我們已經知道這個 set 中的資料已經不少了。同時由於初始化時並沒有指定大小,僅僅只是預設值,所以在大量的併發寫入時候會導致頻繁的擴容,而在 1.7 的條件下又可能會形成環形連結串列。

不巧的是程式碼中也有查詢操作(contains()),觀察上文的堆疊情況:
一次 HashSet 所引起的併發問題
發現是執行在 HashMap 的 465 行,來看看 1.7 中那裡具體在做什麼:
一次 HashSet 所引起的併發問題
已經很明顯了。這裡在遍歷連結串列,同時由於形成了環形連結串列導致這個 e.next 永遠不為空,所以這個迴圈也不會退出了。

到這裡其實已經找到問題了,但還有一個疑問是為什麼執行緒池裡的任務佇列會越堆越多。我第一直覺是任務執行太慢導致的。

仔細查看了程式碼發現只有一個地方可能會慢:也就是有一個數據庫的查詢。

把這個 SQL 拿到生產環境執行發現確實不快,檢視索引發現都有命中。

但我一看錶中的資料發現已經快有 7000W 的資料了。同時經過運維得知 MySQL 那臺伺服器的 IO 壓力也比較大。

所以這個原因也比較明顯了:

由於每消費一條資料都要去查詢一次資料庫,MySQL 本身壓力就比較大,加上資料量也很高所以導致這個 IO 響應較慢,導致整個任務處理的就比較慢了。

但還有一個原因也不能忽視;由於所有的業務執行緒在某個時間點都進入了死迴圈,根本沒有執行完任務的機會,而後面的資料還在源源不斷的進入,所以這個佇列只會越堆越多!

這其實是一個老應用了,可能會有人問為什麼之前沒出現問題。

這是因為之前資料量都比較少,即使是併發寫入也沒有出現併發擴容形成環形連結串列的情況。這段時間業務量的暴增正好把這個隱藏的雷給揪出來了。所以還是得信墨菲他老人家的話。

總結
至此整個排查結束,而我們後續的調整措施大概如下:

HashSet 不是執行緒安全的,換為 ConcurrentHashMap同時把 value 寫死一樣可以達到 set 的效果。
根據我們後面的監控,初始化 ConcurrentHashMap 的大小盡量大一些,避免頻繁的擴容。
MySQL 中很多資料都已經不用了,進行冷熱處理。儘量降低單表資料量。同時後期考慮分表。
查資料那裡調整為查快取,提高查詢效率。
執行緒池的名稱一定得取的有意義,不然是自己給自己增加難度。
根據監控將執行緒池的佇列大小調整為一個具體值,並且要有拒絕策略。
升級到 JDK1.8。
再一個是報警郵件酌情考慮為電話通知。
HashMap 的死迴圈問題在網上層出不窮,沒想到還真被我遇到了。現在要滿足這個條件還是挺少見的,比如 1.8 以下的 JDK 這一條可能大多數人就碰不到,正好又證實了一次墨菲定律。