1. 程式人生 > >又是一個程式設計師粗心的程式碼引起頻繁FullGC的案例

又是一個程式設計師粗心的程式碼引起頻繁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即可:

或者將這一塊直接改成同步處理,不需要執行緒池:

工作一到五年的java 開發工程師朋友可以加入我們Java架構交流群:760940986 群內提供 高可用,高併發,spring原始碼,mybatis原始碼,JVM,大資料,Netty等多個技術知識的架構視訊資料 還有大把大牛在群內交流以及解答面試指導,問題答疑~~