JVM GC耗时频频升高，这次排查完想说：还有谁？
點擊上方?好好學java?，選擇?星標?公眾號
重磅資訊、干貨，第一時間送達
今日推薦：硬剛一周，3W字總結，一年的經驗告訴你如何準備校招！
個人原創100W+訪問量博客：點擊前往，查看更多
1. 背景
多個業務線的應用出現LongGC告警
最近一段時間，經常收到CAT報出來的Long GC告警（配置為大于3秒的為Longgc）。
2. 知識回顧
2.1 JVM堆內存劃分
新生代（Young Generation）
新生代內被劃分為三個區：Eden，from survivor，to survivor。大多數對象在新生代被創建。Minor GC針對的是新生代的垃圾回收。
老年代（Old Generation）
在新生代中經歷了幾次Minor GC仍然存活的對象，就會被放到老年代。Major GC針對的是老年代的垃圾回收。本文重點分析的CMS就是一種針對老年代的垃圾回收算法。另外Full GC是針對整堆（包括新生代和老年代）做垃圾回收的。
永久代（Perm）
主要存放已被虛擬機加載的類信息，常量，靜態變量等數據。該區域對垃圾回收的影響不大，本文不會過多涉及。
2.2 CMS垃圾回收的6個重要階段
1、initial-mark 初始標記（CMS的第一個STW階段），標記GC Root直接引用的對象，GC Root直接引用的對象不多，所以很快。
2、concurrent-mark 并發標記階段，由第一階段標記過的對象出發，所有可達的對象都在本階段標記。
3、concurrent-preclean 并發預清理階段，也是一個并發執行的階段。在本階段，會查找前一階段執行過程中,從新生代晉升或新分配或被更新的對象。通過并發地重新掃描這些對象，預清理階段可以減少下一個stop-the-world 重新標記階段的工作量。
4、concurrent-abortable-preclean 并發可中止的預清理階段。這個階段其實跟上一個階段做的東西一樣，也是為了減少下一個STW重新標記階段的工作量。增加這一階段是為了讓我們可以控制這個階段的結束時機，比如掃描多長時間（默認5秒）或者Eden區使用占比達到期望比例（默認50%）就結束本階段。
5、remark 重標記階段（CMS的第二個STW階段），暫停所有用戶線程，從GC Root開始重新掃描整堆，標記存活的對象。需要注意的是，雖然CMS只回收老年代的垃圾對象，但是這個階段依然需要掃描新生代，因為很多GC Root都在新生代，而這些GC Root指向的對象又在老年代，這稱為“跨代引用”。
6、concurrent-sweep ，并發清理。
3. 分析
下面先看看出現LongGC時發生了什么。
選取其中一個應用分析其GC日志，發現LongGC發生在CMS 的收集階段。
箭頭1 顯示abortable-preclean階段耗時4.04秒。箭頭2 顯示的是remark階段，耗時0.11秒。
雖然abortable-preclean階段是concurrent的，不會暫停其他的用戶線程。就算不優化，可能影響也不大。但是天天收到各個業務線的gc報警，長久來說也不是好事。
在調優之前先看下該應用的GC統計數據，包括GC次數，耗時：
統計期間內(18天)發生CMS GC 69次，其中 abortable preclean階段平均耗時2.45秒，final remark階段平均112ms,最大耗時170ms.
4. 優化目標
降低abortable preclean 時間，而且不增加final remark的時間（因為remark是STW的）。
5. JVM參數調優
5.1 第一次調優
先嘗試調低abortable preclean階段的時間，看看效果。
有兩個參數可以控制這個階段何時結束：
-XX:CMSMaxAbortablePrecleanTime=5000
默認值5s，代表該階段最大的持續時間
-XX:CMSScheduleRemarkEdenPenetration=50
默認值50%，代表Eden區使用比例超過50%就結束該階段進入remark
調整為最大持續時間為1s，Eden區使用占比10%，如下：
-XX:CMSMaxAbortablePrecleanTime=1000
-XX:CMSScheduleRemarkEdenPenetration=10
為什么調整成這樣兩個值，我們是這樣考慮的：首先每次CMS都發生在老年代使用占比達到80%時，因為這是由下面兩個參數決定的：
-XX:CMSInitiatingOccupancyFraction=80
-XX:+UseCMSInitiatingOccupancyOnly
而老年代的增長是由于部分對象在Minor GC后仍然存活，被晉升到老年代，導致老年代使用占比增長的，也就是在每次CMS GC發生之前剛剛發生過一次Minor GC，所以在那一刻新生代的使用占比是很低的。那么我們預計這個時候盡快結束abortable preclean階段，在remark時就不需要掃描太多的Eden區對象，remark STW的時間也就不會太長。
調整的思路是這樣了，那到底效果如何呢？
第一次調整的的結果
在統計期間（17小時左右）內，發生過2次CMS GC。Abortable Preclean 平均耗時835ms，這是預期內的。但是Final Remark 平均耗時495ms（調整前是112ms），其中一次是80ms，另一次是910ms！將近1秒鐘！Remark是STW的！對于要求低延時的應用來說這是無法接受的！
對比這兩次CMS GC的詳細GC日志，我們發現了一些對分析問題非常有用的東西。
remark耗時80ms的那次GC日志
[YG occupancy: 181274 K (1887488 K)]?- 年輕代當前占用情況和總容量
耗時80ms的這次remark發生時（早上9點，非高峰時段），新生代（YG）占用181.274M。
remark耗時910ms的那次GC日志
[YG occupancy: 773427 K (1887488 K)]
耗時910ms的這次remark發生時（晚上10點左右，高峰時段），新生代（YG）占用773.427M。因為這個時候高峰期，新生代的占用量上升的非常快，幾乎同樣的時間內，非高峰時段僅上升到181M，但是高峰時段就上升到773M。
這里能得出一個有用的結論：如果abortale preclean階段時間太短，隨后在remark時，新生代占用越大，則remark持續的時間（STW）越長。
這就陷入了兩難了，不縮短abortale preclean耗時會報longgc；縮短的話，remark階段又會變長，而且是STW，更不能接受。
對于這種情況，CMS提供了CMSScavengeBeforeRemark參數，嘗試在remark階段之前進行一次Minor GC，以降低新生代的占用。
-XX:+CMSScavengeBeforeRemark
Enables scavenging attempts before the CMS remark step. By default, this option is disabled.
5.2 第二次調優
調優前的考慮：
增加-XX:+CMSScavengeBeforeRemark?不是沒有代價的，因為這會增加一次Minor GC停頓。所以這個方案好或者不好的判斷標準就是：增加CMSScavengeBeforeRemark參數之后的minor GC停頓時間 + remark 停頓時間如果比增加之前的remark GC停頓時間要小，這才是好的方案。
第二次調整的結果
在統計期間（20小時左右）內，發生3次CMS GC。Abortable preclean 平均耗時693ms。Final remark平均耗時50ms，最大耗時60ms。Final remark的時間比調優前的平均時間（112ms）更低。
那么CMS GC前的Minor GC停頓時間又如何呢？來看看詳細的GC日志。
3次CMS GC remark前的Minor GC日志分析
第1次是非高峰時段的表現，Minor GC 耗時 0.01s + remark耗時 0.06s = 0.07s = 70ms，如下
第2次是高峰時段，Minor GC 耗時 0.01s + remark耗時 0.05s = 0.06s = 60ms，如下
第3次是非高峰時段，Minor GC 耗時 0.00s + remark耗時 0.04s = 0.04s = 40ms，如下
所以，3次Minor GC + remark耗時的平均耗時 < 60ms,這比第一次調優時remark平均耗時495ms好得多了。
6.優化結果
至此，我們最初的目標- 降低abortable preclean 時間，而且不增加final remark的時間 ，已經達到了。甚至remark的時間也縮短了。
7. 小結
解決abortable preclean 時間過長的方案可以歸結為兩步：
縮短abortable preclean 時長，通過調整這兩個參數：
-XX:CMSMaxAbortablePrecleanTime=xxx
-XX:CMSScheduleRemarkEdenPenetration=xxx
調整為多少的一個判斷標準是：abortable preclean階段結束時，新生代的空間占用不能大于某個參考值。?在前面第一次調優后，新生代（YG）占用181.274M，remark耗時80ms；新生代（YG）占用773.427M時，remark耗時910ms。所以這個參考值可以是300M。而如果新生代增長過快，像這次調優應用2秒內就能用光2G新生代堆空間的，就只能通過CMSScavengeBeforeRemark做一次Minor GC了。
增加CMSScavengeBeforeRemark參數開啟remark前進行Minor GC的嘗試
雖然官方說明這個增加這個參數是嘗試進行Minor GC，不一定會進行。但實際使用起來，幾乎每次remark前都會Minor GC。
8. 總結
調優前明確目標
調優過程對GC指標進行數據統計分析（本文借助gceasy.io在線分析工具）來驗證效果
需要能看懂GC日志
GC調優不是一個一蹴而就的事情，它是微調-觀察-再微調的過程。所以需要比較深入了解GC的一些基礎，才能少走彎路。
推薦文章
硬剛一周，3W字總結，一年的經驗告訴你如何準備校招！
今年的校招，Java 好拿 offer 嗎？
10月了，該聊聊今年秋招了！
聊聊在騰訊實習快一個月的感受
總結
以上是生活随笔為你收集整理的JVM GC耗时频频升高，这次排查完想说：还有谁？的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 10分钟看懂， Java NIO 底层原
- 下一篇： 本文把TCP/IP讲绝了！