上午剛到公司，準備開始一天的摸魚之旅時突然收到了一封監控中心的郵件。
心中暗道不好，因為監控系統從來不會告訴我應用完美無 bug，其實系統挺猥瑣。
打開郵件一看，果然告知我有一個應用的線程池隊列達到門檻值觸發了報警。
背景
心中暗道不好，因為監控系統從來不會告訴我應用完美無
bug
，其實系統挺猥瑣。
由于這個應用出問題非常影響使用者體驗；于是立馬讓運維保留現場
dump
線程和記憶體同時重新開機應用，還好重新開機之後恢複正常。于是開始着手排查問題。
分析
首先了解下這個應用大概是做什麼的。
簡單來說就是從
MQ
中取出資料然後丢到後面的業務線程池中做具體的業務處理。
而報警的隊列正好就是這個線程池的隊列。
跟蹤代碼發現建構線程池的方式如下：
ThreadPoolExecutor executor = new ThreadPoolExecutor(coreSize, maxSize,
0L, TimeUnit.MILLISECONDS,
new LinkedBlockingQueue<Runnable>());;
put(poolName,executor);
采用的是預設的
LinkedBlockingQueue
并沒有指定大小（這也是個坑），于是這個隊列的預設大小為
Integer.MAX_VALUE
。
由于應用已經重新開機，隻能從僅存的線程快照和記憶體快照進行分析。
記憶體分析
先利用
MAT
分析了記憶體，的到了如下報告。
其中有兩個比較大的對象，一個就是之前線程池存放任務的
LinkedBlockingQueue
，還有一個則是
HashSet
當然其中隊列占用了大量的記憶體，是以優先檢視，
HashSet
一會兒再看。
由于隊列的大小給的夠大，是以結合目前的情況來看應當是線程池裡的任務處理較慢，導緻隊列的任務越堆越多，至少這是目前可以得出的結論。
線程分析
再來看看線程的分析，這裡利用 fastthread.io 這個網站進行線程分析。
因為從表現來看線程池裡的任務遲遲沒有執行完畢，是以主要看看它們在幹嘛。
正好他們都處于 RUNNABLE 狀态，同時堆棧如下：
發現正好就是在處理上文提到的
HashSet
，看這個堆棧是在查詢
key
是否存在。通過檢視 312 行的業務代碼确實也是如此。
這裡的線程名字也是個坑，讓我找了好久。
定位
分析了記憶體和線程的堆棧之後其實已經大概猜出一些問題了。
這裡其實有一個前提忘記講到：
這個告警是
淩晨三點
發出的郵件，但并沒有電話提醒之類的，是以大家都不知道。
到了早上上班時才發現并立即
dump
了上面的證據。
所有有一個很重要的事實：這幾個業務線程在查詢
HashSet
的時候運作了 6 7 個小時都沒有傳回。
通過之前的監控曲線圖也可以看出：
作業系統在之前一直處于高負載中，直到我們早上看到報警重新開機之後才降低。
同時發現這個應用生産上運作的是
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;
}
@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()
）,觀察上文的堆棧情況：
發現是運作在
HashMap
的 465 行，來看看 1.7 中那裡具體在做什麼：
已經很明顯了。這裡在周遊連結清單，同時由于形成了環形連結清單導緻這個
e.next
永遠不為空，是以這個循環也不會退出了。
到這裡其實已經找到問題了，但還有一個疑問是為什麼線程池裡的任務隊列會越堆越多。我第一直覺是任務執行太慢導緻的。
仔細檢視了代碼發現隻有一個地方可能會慢：也就是有一個資料庫的查詢。
把這個 SQL 拿到生産環境執行發現确實不快，檢視索引發現都有命中。
但我一看表中的資料發現已經快有 7000W 的資料了。同時經過運維得知
MySQL
那台伺服器的
IO
壓力也比較大。
是以這個原因也比較明顯了：
由于每消費一條資料都要去查詢一次資料庫，MySQL 本身壓力就比較大，加上資料量也很高是以導緻這個 IO 響應較慢，導緻整個任務處理的就比較慢了。
但還有一個原因也不能忽視；由于所有的業務線程在某個時間點都進入了死循環，根本沒有執行完任務的機會，而後面的資料還在源源不斷的進入，是以這個隊列隻會越堆越多！
這其實是一個老應用了，可能會有人問為什麼之前沒出現問題。
這是因為之前資料量都比較少，即使是并發寫入也沒有出現并發擴容形成環形連結清單的情況。這段時間業務量的暴增正好把這個隐藏的雷給揪出來了。是以還是得信墨菲他老人家的話。
總結
至此整個排查結束，而我們後續的調整措施大概如下：
-
HashSet
ConcurrentHashMap
value
set
- 根據我們後面的監控，初始化
ConcurrentHashMap
-
MySQL
- 查資料那裡調整為查緩存，提高查詢效率。
- 線程池的名稱一定得取的有意義，不然是自己給自己增加難度。
- 根據監控将線程池的隊列大小調整為一個具體值，并且要有拒絕政策。
- 更新到
JDK1.8
- 再一個是報警郵件酌情考慮為電話通知😂。
HashMap
的死循環問題在網上層出不窮，沒想到還真被我遇到了。現在要滿足這個條件還是挺少見的，比如 1.8 以下的
JDK
這一條可能大多數人就碰不到，正好又證明了一次墨菲定律。
同時我會将文章更到這裡，友善大家閱讀和查詢。
https://crossoverjie.top/JCSprout/
你的點贊與分享是對我最大的支援
作者：
crossoverJie
出處：
https://crossoverjie.top
歡迎關注部落客公衆号與我交流。
本文版權歸作者所有，歡迎轉載，但未經作者同意必須保留此段聲明，且在文章頁面明顯位置給出,
如有問題， 可郵件（crossoverJie#gmail.com）咨詢。
![Java小案例——随機數猜測随機數猜測[圖]](data:image/gif;base64,R0lGODlhAQABAIAAAP///wAAACwAAAAAAQABAAACAkQBADs=)