又是一個程式設計師粗心的程式碼引起頻繁FullGC的案例
這是笨神JVMPocket群裡一位名為" 云何*住 "的同學提出來的問題,問題現象是 CPU飆高 並且 頻繁FullGC 。
重現問題
這位同學的業務程式碼比較複雜,為了簡化業務場景,筆者將其程式碼壓縮成如下的程式碼片段:
說明,為了更好的還原問題, FutureContract.java 的定義建議儘量與問題程式碼保持一致:
-
16個BigDecimal型別屬性
-
3個Long型別屬性
-
3個String型別屬性
-
4個Integer型別屬性
-
2個Date型別屬性
問題程式碼執行時的JVM引數如下(JDK8):
你也可以先自己獨立思考一下這塊程式碼問題何在。
CPU飆高
這是第一個現象,top命令就能看到,找到我們的程序ID,例如91782。然後執行命令 top-H-p91782
檢視程序裡的執行緒情況:
由這段結果可知執行緒91784和91785很消耗CPU。將91784和91785分別轉為16進位制,得到16688和16689。接下來通過執行命令命令 jstack-l91782>91782.log
匯出執行緒棧資訊(命令中是程序ID),並在執行緒dump檔案中尋找16進位制數16688和16689,得到如下兩條資訊:
由這兩行結果可知,消耗CPU的是ParallelGC執行緒。因為問題程式碼搭配的JVM引數沒有指定任何垃圾回收期,所以用的是預設的PS垃圾回收,所以這個JVM例項應該在頻繁FullGC,通過命令 jstat-gcutil917825s
檢視GC表現可以驗證,由這段結果可知,Eden和Old都佔滿了,且不再發生YGC,但是卻在頻繁FGC,此時的應用已經不能處理任務,相當於假死了,好可怕:
揪出真凶
到這裡基本可以確認是有物件沒有釋放導致即使發生FullGC也回收不了引起的,準備dump進行分析看看Old區都是些什麼妖魔鬼怪,執行命令 jmap-dump:format=b,file=91782.bin91782
,用MAT分析時,強烈建議開啟 keep unreachable objects
:

接下來點選Actions下的 Histogram ,查詢大物件:

下面貼出的是原圖,而不是筆者的Demo程式碼跑出來的:

由這段程式碼可知,大量的FutureContract和BigDecimal(說明:因為FutureContract中有多達16個BigDecimal型別的屬性),FutureContract佔了120MB,BigDecimal佔了95MB。那麼就可以斷定問題是與FutureContract相關的程式碼造成的,如果是正常的JVM示例, Histogram 試圖最佔記憶體的是byte[]和char[]兩個陣列,兩者合計一般會佔去80%左右的記憶體,遠遠超過其他物件佔用的記憶體。
接下來通過FutureContract就找到上面這塊buildBar方法程式碼,那麼為什麼是這塊程式碼無法釋放呢?單獨把這塊程式碼擰出來看看,這裡用到了 ScheduledThreadPoolExecutor 定時排程,且每3秒執行一次,然而定時器中需要的引數來自外面的 List<FutureContract>
,這就會導致 List<FutureContract>
這個物件一致被一個定時任務引用,永遠無法回收,從而導致FutureContract不斷晉升到Old區,直到佔滿Old區然後頻繁FullGC。
那麼為什麼會出現這種情況呢?我相信一個程式員不應該犯這樣的低階錯誤,後來看到原生程式碼,我做出一個比較合理的猜測,其本意可能是想通過呼叫 Executorexecutor
來非同步執行,誰知小手一抖,在紅色框那裡輸入了taskExecutor,而不是executor:

解決問題
OK,知道問題的根因,想解決問題就比較簡單了,將taskExecutor改成executor即可:
或者將這一塊直接改成同步處理,不需要執行緒池:
原文釋出時間為: 2018-11-08 本文作者: Java技術驛站 本文來自雲棲社群合作伙伴“ofollow,noindex" target="_blank">
Java技術驛站
”,瞭解相關資訊可以關注“
Java技術驛站
”。