GC案例

FGC----jmap -histo:live致使

線上某服務的老年代配置了CMS，但卻在gc.log發現連續Full GC的問題。JVM參數配置以下：

-XX:+UseCMSInitiatingOccupancyOnly
-XX:CMSInitiatingOccupancyFraction=68

參數的意義是：在老年代到68%的時候，會觸發一次CMS GC，應該是出現相似以下的日誌：

T20:10:37.803+0800: 3246087.559: [CMS-concurrent-mark-start]
T20:10:38.463+0800: 3246088.220: [CMS-concurrent-mark: 0.661/0.661 secs] [Times: user=3.17 sys=0.56, real=0.66 secs]
T20:10:38.463+0800: 3246088.220: [CMS-concurrent-preclean-start]
T20:10:38.552+0800: 3246088.309: [CMS-concurrent-preclean: 0.069/0.089 secs] [Times: user=0.14 sys=0.04, real=0.09 secs]_
T20:10:38.552+0800: 3246088.309: [CMS-concurrent-abortable-preclean-start]

但線上環境的日誌卻出現以下的狀況：

老年代配置了900M，但卻在只使用了50+M的時候觸發了Full GC，並且是在短暫的時間內連續觸發。

配置了CMS卻觸發Full GC，有如下幾種可能：

• 大對象分配時，年輕代不夠，直接晉升到老年代，老年代空間也不夠，觸發 Full GC（老年代還剩800+M，顯然不可能）

• 內存碎片致使（因爲CMS是基於標記清除算法的，全部會致使內存碎片，但經過grep -i "cms" gc.log，JVM還沒有觸發過CMS回收，因此也不存在內存碎片的說法） 

• CMS GC失敗致使（從gc.log並未找到concurrent mode failure的記錄，排除）(promotion failed也會致使)

• jmap -histo（人爲執行該命令）

經筆者回憶，在中午快12點的時候確實登陸過線上機，執行過jmap -histo:live命令，經驗證，手動執行jmap -histo:live，也確實會在gc.log出現觸發 Full GC的現象，問題獲得驗證。