本文介紹了一次生產環境的JVM GC相關參數的調優過程,通過參數的調整避免了GC卡頓對JAVA服務成功率的影響。
這段時間在整理jvm系列的文章,無意中發現本文,作者思路清晰通過步步分析最終解決問題。我個人特別喜歡這種實戰類的內容,經原作者的授權同意,將文章分享於此。原文鏈接:Java服務GC參數調優案例,下面為轉載此文的內容,備注部分為本人添加,主要起到說明的作用。
背景以及遇到的問題
我們的Java HTTP服務屬於OLTP類型,對成功率和響應時間的要求比較高,在生產環境中出現偶現的成功率突然下降然后又自動恢復的情況,如圖所示:
JVM和GC相關的參數如下:
-Xmx22528m -Xms22528m -XX:NewRatio=2 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled
總結來說,由於服務中大量使用了Cache,所以堆大小開到了22G。GC算法使用CMS(UseConcMarkSweepGC),開啟了降低標記停頓(CMSParallelRemarkEnabled),設置年輕代為並行收集(UseParNewGC),年輕代和老年代的比例為1:2 (NewRatio=2).
JVM GC日志相關的參數如下:
-Xloggc:/data/gc.log -XX:GCLogFileSize=10M -XX:NumberOfGCLogFiles=10 -XX:+UseGCLogFileRotation -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+DisableExplicitGC -verbose:gc
問題解決過程
排除應用程序的內存使用問題
首先使用jmap查看內存使用情況:
jmap -histo:live PID
這個命令把程序中當前的對象按照個數和占用的空間排序以后打印出來。這里沒有發現使用異常的對象。
排除Cache內容過多的問題
如果Cache內容過多也會導致JVM老年代容易被用滿導致頻繁GC,因此調出GC日志進行查看,發現每次GC以后內存使用一般是從20G降低到5G左右,因此常駐內存的Cache不是導致GC長時間卡頓的根本原因。對於GC LOG的查看有多種方式,使用VisualVM比較直觀,需要使用VisualGC:
從圖中我們可以看到伊甸園和老年代的空間分配,由於整體內存是20G,設置 -XX:NewRatio=2 因此老年代是14G,伊甸園+S0+S1=7G
調整GC時間點(成功率抖動問題加重)
如果GC需要處理的內存量比較大,執行的時間也就比較長,STW (Stop the World)時間也就更長。按照這個思路調整CMS啟動的時間點,希望提早GC,也就是讓GC變得更加頻繁但是期望每次執行的時間較少。添加了下面這兩個參數:
-XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=50
意思是說在Old區使用了50%的時候觸發GC。實驗后發現GC的頻率有所增加,但是每次GC造成的陳功率降低現象並沒有減弱,因此棄用這兩個參數。
調整對象在年輕代內存中駐留的時間(效果不明顯)
如果能夠降低老年代GC的頻率也可以達到降低GC影響的目的,因此嘗試讓對象在年輕代內存中進行更長時間的駐留,提升這些對象在年輕代GC時候被銷毀的概率。使用參數-XX:MaxTenuringThreshold=31
調整以后收效不明顯。
備注:
1、MaxTenuringThreshold 在1.5.0_05之前最大值可以設置為31 ,1.5.0_06以后最大值可以設置為15,超過15會被認為無限大。參考:Never set GC parameter -XX:MaxTenuringThreshold greater than 15
2、提升年輕代GC被銷毀的概率,只是調整這個參數效果不大,第二次age的值會重新計算,參考:說說MaxTenuringThreshold這個參數
CMS-Remark之前強制進行年輕代的GC
首先補充一下CMS的相關知識,在CMS整個過程中有兩個步驟是STW的,如圖紅色部分:
CMS並非沒有暫停,而是用兩次短暫停來替代串行標記整理算法的長暫停,它的收集周期是這樣:
- 1、初始標記(CMS-initial-mark),從root對象開始標記存活的對象
- 2、並發標記(CMS-concurrent-mark)
- 3、重新標記(CMS-remark),暫停所有應用程序線程,重新標記並發標記階段遺漏的對象(在並發標記階段結束后對象狀態的更新導致)
- 4、並發清除(CMS-concurrent-sweep)
- 5、並發重設狀態等待下次CMS的觸發(CMS-concurrent-reset)。
通過GC日志和成功率下降的時間點進行比對發現並不是每一次老年代GC都會導致成功率的下降,但是從中發現了一個規律:
前兩次GC CMS-Remark過程在4s左右造成了成功率的下降,但是第三次GC並沒有對成功率造成明顯的影響,CMS-Remark只有0.18s。Java HTTP 服務是通過Nginx進行反向代理的,nginx設置的超時時間是3s,所以如果GC卡頓在3s以內就不會對成功率造成太大的影響。
從GC日志中又發現一個信息:
在文檔和相關資料中沒有找到藍色部分的含義,猜測是remark處理的內存量,處理的越多就越慢。添加下面兩個參數強制在remark階段和FULL GC階段之前先在進行一次年輕代的GC,這樣需要進行處理的內存量就不會太多。
備注:
1、藍色部分的含義:remark標記需要清理對象的容量。關於如何分析CMS日志,可以參考這篇文章:了解 CMS 垃圾回收日志
2、FULL GC階段之前先在進行一次年輕代的GC的意義是:Yong區對象引用了Old區的對象,如果在Old區進行清理之前不進行Yong區清理,就會導致Old區被yong區引用的對象無法釋放。可以參考這篇文章:假笨說-又抓了一個導致頻繁GC的鬼–數組動態擴容
-XX:+ScavengeBeforeFullGC -XX:+CMSScavengeBeforeRemark
調優以后效果很明顯,下面是兩台配置完全相同的服務器在同一時間段的成功率和響應時間監控圖,第一個沒有添加強制年輕代GC的參數。
結論
1、在CMS-remark階段需要對堆中所有的內存對象進行處理,如果在這個階段之前強制執行一次年輕代的GC會大量減少remark需要處理的內存數量,進而降低JVM卡頓對成功率的影響。
2、對於Java HTTP服務,JVM的卡頓時間應該小於HTTP客戶端的調用超時時間,否則JVM卡頓會對成功率造成影響。