1.問題描述
最近參與到一個新項目的開發當中,項目的大部分功能已經由另外一名同僚實作,這名同僚給我反映了一個問題,說每次部署這個項目成功之後CPU立馬飙到将近百分之百,一直沒發現問題在哪裡。
![](https://img.laitimes.com/img/9ZDMuAjOiMmIsIjOiQnIsIyN1MzNxEDNwEDOwYDM2EDMy8CX0Vmbu4GZzNmLn9Gbi1yZtl2Lc9CX6MHc0RHaiojIsJye.jpg)
2.解決過程
聽了同僚的描述之後,心想肯定是程式性能問題,由于之前一直沒碰到過這類問題,懷着濃厚的好奇心想一探究竟,解決這類問題本省也是成長,說幹就幹。
我首先想到的解決這類問題是使用性能分析工具——Java VisualVM,JDK自帶的可視化工具。
通過VisualVM可以看到,除了CPU爆表之外其他都比較正常。
再看看線程運作情況,按運作時間排序,發現占用CPU最多的線程如綠色部分,其中有RMI相關線程、I/O線程。
看到這個排名,首先懷疑是RMI遠端調用相關問題,由于項目中使用了Dubbo等架構,再加上性能分析經驗不足,一直以為問題的産生跟dubbo相關,然後就去項目中去掉dubbo相關的功能(雖然有點二,當時覺得值得試一試),花了不少功夫終于去掉dubbo可以重新部署了。
重新部署項目後,發現CPU突然又飙升上去了。顯然與dubbo關系不大,接下來的懷疑對象就是OpenapiMonitorAsyncWriteLogThread這個線程,由于并不是我寫的代碼,是以并不了解這個線程的作用。我們接着生成線程的Dump檔案:
接着看Dump檔案,找到OpenapiMonitorAsyncWriteLogThread這個線程的相關資訊,我們就可以跟蹤到相應的代碼了
到這裡我們隻是懷疑OpenapiMonitorAsyncWriteLogThread這個線程有問題,并沒有确定,那麼我們再看看抽樣器對CPU抽樣(如下圖),發現這個線程中的pollOne()方法占用CPU很多,是以我們更加懷疑這個線程,是以還是值得去仔細研究一下這個線程中的代碼。
看了代碼之後發現,這個線程實作的功能就是在項目部署後建立一個線程,這個線程不斷的向資料庫中儲存通路請求日志,這些日志對象首先放到一個隊列當中,然後線程不停的從queue當中取出對象:
/**
* 擷取待插入記錄list
* @Title: pollBatch
* @param batchSize
* @return
* @throws ParseException
* @throws InterruptedException
*/
private List<OauthLog> pollBatch(int batchSize) throws InterruptedException {
List<OauthLog> retList = Lists.newLinkedList();
int count = ;
while(count < batchSize){
OauthLog data = pollOne();
if(data != null){
retList.add(data);
}
count++;
}
return retList;
}
/**
* 擷取待插入記錄
* @Title: pollOne
* @return
* @throws InterruptedException
* @throws ParseException
*/
private OauthLog pollOne() throws InterruptedException {
return queue.poll();
}
先前我們懷疑的pollOne()方法很簡單,就是一個調用queue.poll()(這個queue是用的LinkedBlockingQueue)。我們去看看這個poll()方法的源碼有什麼特别之處呢:
經過仔細琢磨,終于發現問題。
int count = ;
while(count < batchSize){
OauthLog data = pollOne();
if(data != null){
retList.add(data);
}
count++;
}
這個循環會一直調用pollOne()這個方法,也就是上圖中的poll()方法,然而當queue為空的時候,那麼poll()方法就會直接傳回,繼續回到while循環當中,如果while循環能夠終止那麼也不會有問題,關鍵是while循環所在方法一直在運作,如下圖:
進而While循環所在方法會一直運作,是以問題就出在這裡,到此為止我們已經找到了問題所在,就是從queue中擷取日志對象的方法不管queue是否為空都會一直運作,就導緻了CPU被這個線程一直消耗。
3.問題解決
我們上面已經知道了問題之所在,現在要做的就是解決問題。既然poll()方法在隊列為空的情況下還會一直繼續運作,那麼我們就不應該用此方法來擷取隊列中的對象,而是使用take()方法。
顯然take()方法在隊列為空的情況下就會阻塞,進而避免了線程一直占用cpu的問題。
OK,将poll()方法換成take()方法,CPU瞬間正常!
大功告成?NO!然而卻出現了另外的異常現象,擷取到的日志對象并沒有儲存到資料庫。這是什麼原因呢。。。不管如何CPU爆表的問題算是解決了,至于日志對象沒有儲存到資料庫是為什麼,那就是另外的問題了,也跟線程相關,那麼且聽下回分解。