當小白遇到FullGC | 京東雲技術團隊詳情 - gc,full-stack,後端,java 京東雲開發者博客

起初沒有人在意這場GC,直到它影響到了每一天!

前言

本文記錄了一次排查FullGC導致的TP99過高過程,介紹了一些排查時思路,線索以及工具的使用,希望能夠幫助一些新手在排查問題沒有很好的思路時,提供一些思路,讓小白也能輕鬆解決FullGC問題,文中實際提到的參數配置不一定適合其他業務場景,在調優自己的項目時還是需要實際試驗過才能得出最佳參數配置

我也是小白,如有不合理的地方,歡迎大佬們進行指正

因為線上服務器,我們大部分是沒有SSH權限的,沒有辦法直接執行命令獲取容器信息,所以排查過程中只能藉助平台提供的工具,平台提供的工具還是挺全的,本文主要用到的工具有: JDOS容器智能監控,JDOS進程查詢,SGM容器監控信息,SGM方法調用查詢

以下幾個工具簡單介紹:

http://sgm-server.jd.com/
http://jagile.jd.com/jdosCD/jdt/apps
JDOS容器智能監控: 查看容器的CPU,內存,磁盤,IO等信息
JDOS進程查詢: 查看Java進程編號,執行常用的Java內存進程查看命令
SGM容器監控信息: 查看JVM虛擬機內存變更歷史記錄
SGM方法調用查詢: 查看某一次關鍵接口調用的上下依賴,時間分佈

起因 - 偶爾出現接口超時

一開始偶爾會收到報警郵件,顯示有些接口調用時間比較長,抽查了一些接口,發現大部分都是調用下游JSF時間比較長,導致響應比較慢,這時候就沒太在意,接下來繼續觀察了幾天,發現一個規律,大部分郵件都是每天10點

排查定位問題

首先確認了10點這個時間點有沒有定時任務之類的操作,經過詢問確定這個時間點是倉庫出庫高峯期,導致業務量出現峯值(調用量變大可能是激發FullGC問題,成為問題暴漏的導火線)
第二部就是確認是數據庫原因,還是業務代碼,還是JSF下游接口達到極限原因,到這一步還是未知的,在這用到了SGM的接口調用查詢工具,下圖中我們看到,這次調用JSF也是挺高的(這個沒有太好辦法,除非讓下游優化,所以暫時忽略),但是還有一個是logic,這個就是邏輯處理,如果沒有那個FullGC提示,就需要去分析代碼的處理是否有問題,這通過那行紅色字體的提示,很顯然我們確定了是FullGC導致的問題
我們去查看一下容器的FullGC情況,確實發現這個時間點的FullGC特別頻繁,到此已經把問題範圍定位到就是FullGC導致的

FullGC問題排查

Full GC 觸發條件：

到這裏我們需要確定一個問題 : “觸發FullGC的條件是什麼？”，新手可以去博客搜索，當然最好是能記住這個知識點。注意這不是確定“什麼原因導致的FullGC？”，因為這個問題原因太多了，我們要一步一步排查。下面是我查到的資料，粘到這裏供參考.

Minor GC觸發條件：當Eden區滿時，觸發Minor GC。
Full GC觸發條件：

（1）調用System.gc()時，系統建議執行Full GC，但是不必然執
（2）老年代空間不足
（3）方法區空間不足
（4）通過Minor GC後進入老年代的平均大小大於老年代的可用內存
（5）由Eden區、From Space區向To Space區複製時，對象大小大於To Space可用內存，則把該對象轉存到老年代

這裏在代碼中並沒有找到System.gc()的顯示調用,一般我們也不會調用這個方法,所以我們直接看第二種情況,到SGM中查看老年代變化,結果發現老年代頻繁達到90%,而這個時間正好可以跟上面GC時間對上.

對象進入老年代的幾種情況

我們都知道,老年代的對象應該是存活時間很長的對象,但是我們發現這些對象都在FullGC時被釋放掉了,他們為什麼到了老年代呢? 這時候我們需要確定的第二個問題是:“什麼情況下對象會進入老年代？” 查資料後有以下幾種情況

年齡夠了: 躲過15次(默認配置是15次) minorGC 之後從新生代進入老年代；
大對象: 大對象直接進入老年代。有一個 JVM 參數 '-XX:PretenureSizeThreshold' 設置值為字節數，創建超過該大小的對象直接進入老年代,如果沒有配置這個參數,這個值好像默認是1M。
動態年齡判斷：當前放對象的 Survivor 區，相同年齡的一批對象（以及小於該年齡）的總內存大於該區的內存的50%，大於該年齡的其他老對象，就會進入老年代（例如1,2,3歲年齡的對象佔了 S 區的50%以上，就會把大於3歲的對象移動到老年代去。所以儘量讓 S 區中的對象，佔比儘量少於 50%）；
剩的總量太多: Eden 區存活對象太多，超過了 Survivor 的大小，就直接把這些對象都轉移到老年代去。（JDK1.8 空間擔保機制）

首先分析第一種情況,如果出現大批量這樣的對象,代碼中出現了長時間引用(例如:靜態Map只加不刪),但是我們可以看到,這些對象在每次FullGC都被釋放掉了,説明這批對象存活的時間並不長, 而且代碼排查也沒發現這種代碼,暫時排除這種情況(這的代碼因為是工具包的代碼,所以沒有太深糾,這為續集留個伏筆). 第二種情況,大對象,我們到JDOS下載下來JMap-dump內存快照和JMap-Histo對象統計信息,經過對FullGC錢dump分析,結合GC前GC後對象統計結果,並沒有發現大量的大對象,這個基本也排除

通過JMAT(Eclipse Memory Analysis Tools)導入dump文件進行分析，內存泄漏問題一般我們直接選Leak Suspects即可，mat給出了內存泄漏的建議。另外也可以選擇Top Consumers來查看最大對象報告。和線程相關的問題可以選擇thread overview進行分析。除此之外就是選擇Histogram類概覽來自己慢慢分析，大家可以搜搜mat的相關教程。

接下來就是第三種和第四種情況,這時候我們需要取查看年輕代三塊區域的變化,尤其是Survivor區域,下圖是當時一個情況,S區大小一直在變化,而且基本一致保持在50%以上,這時候想到了一個JVM高版本特性,會自動打開UseAdaptiveSizePolicy(動態調整),查資料後發現,好多人反應這個參數會導致對象跨過S區,直接跑到老年代的情況,我們看到在調用量持續很高的情況,盡然調整到了17M,這肯定會導致容納不下當時存活的對象

UseAdaptiveSizePolicy開關參數-XX:+UseAdaptiveSizePolicy是一個開關參數，當這個參數打開之後，虛擬機會根據當前系統的運行情況收集性能監控信息，動態調整這些參數以提供最合適的停頓時間或最大的吞吐量，這種調節方式稱為GC自適應的調節策略（GC Ergonomics）。

定位到UseAdaptiveSizePolicy問題

既然這有問題,我們嘗試關閉一下這個參數看下效果,下面是老年代,S區和FullGC,在關閉前和關閉後的效果,關閉之後S區大多數時間有充足的空間,而且,老年代和FullGC圖也安穩了很多關閉AdaptiveSizePolicy的方式

開啓：-XX:+UseAdaptiveSizePolicy(JDK1.8 Parallel Scavenge收集器默認)
關閉：-XX:-UseAdaptiveSizePolicy

發現新的問題

上圖中雖然已經安穩了很多,但是還是有一點小問題,頻繁FullGC雖然沒有了,但是一個小時還是會出現一次FullGC,而且這時候老年代還沒有滿,這種頻率的FullGC,理論上也是不允許的. 我們回到第一個問題,FullGC觸發條件,第三個,我們趕緊看了下永久代,也就是元空間,如下圖,這一看不得了,元空間也在頻繁變動,而且達到300M左右時會觸發一次FullGC釋放掉.

tips: 這裏是沒有配置元空間的大小的,也沒有配置元空間的理論上元空間無限大,不會滿,查詢資料後解釋是,元空間也會根據當前已使用進行動態調整,當達到上次調整值90%後就會FullGC,所以每次FullGC元空間大小在200M到500M不等

元空間內存排查

這時猜測可能是代碼中出現了大量的動態類的聲明,想要定位哪些類需要jvm啓動參數加上打印類加載和卸載的參數,順帶把GC日誌開關也打開

-XX:+TraceClassUnloading -XX:+TraceClassLoading -XX:+PrintGCDetails

打開後查看日誌發現一個頻繁加載和卸載的類[com.googlecode.aviator.Expression], 經查詢資料,這個是aviator 工具的一個規則引擎類,在加載規則時會動態加載一個類,默認不使用緩存,可以打開緩存防止頻繁聲明新類

修改代碼後重新部署,一小時一次的FullGC也沒了,如下圖

總結

發現的問題: 問題一: AdaptiveSizePolicy導致對象提前進入老年代,老年代增長速度快,導致頻繁FullGC 解決方式: 關閉：-XX:-UseAdaptiveSizePolicy

問題二: 元空間不斷增長,導致一小時一次FullGC 解決方式: 修改邏輯代碼防止頻繁加載新類

在排查問題時儘可能先找直接原因,縮小排查跨度,不要一步就想知道根本原因,每個線索都要問個為什麼,不正常的現象肯定是有原因的.

下面是FullGC排查思路參考腦圖

作者：京東保險陳林輝

來源：京東雲開發者社區轉載請註明來源

京東雲開發者博客

京東雲開發者博客

博客 / 詳情