一個簡單案例,帶你看懂GC日志!

Java技術棧
www.javastack.cn
關注閱讀更多優(yōu)質文章
環(huán)境準備
這樣一個案例程序:
public?class?Main?{
??public?static?void?main(String[]?args)?{
????byte[]?array1?=?new?byte[4?*?1024?*?1024];
????array1?=?null;
????byte[]?array2?=?new?byte[2?*?1024?*?1024];
????byte[]?array3?=?new?byte[2?*?1024?*?1024];
????byte[]?array4?=?new?byte[2?*?1024?*?1024];
????byte[]?array5?=?new?byte[128?*?1024];
????byte[]?array6?=?new?byte[2?*?1024?*?1024];
??}
}
我們采用如下參數(shù)來運行上述程序:
?-XX:NewSize=10M -XX:MaxNewSize=10M -XX:InitialHeapSize=20M -XX:MaxHeapSize=20M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log
?
參數(shù)介紹:
-XX:NewSize:初始年輕代大小
-XX:MaxNewSize:最大年輕代大小
-XX:InitialHeapSize:定義堆的初始化大小,默認值是物理內存的1/64,其實就是:-Xms
-XX:MaxHeapSize:定義最大堆的大小,默認為物理內存的1/4,其實就是:-Xmx
-XX:SurvivorRatio:Eden區(qū)與Survivor區(qū)的大小比值
-XX:MaxTenuringThreshold:年輕代對象轉換為老年代對象最大年齡值
-XX:PretenureSizeThreshold=3M:對象大小超過3M時直接在老年代分配內存
-XX:+UseParNewGC:使用ParNew收集器
-XX:+UseConcMarkSweepGC:使用CMS收集器
-XX:+PrintGCDetails:GC時打印詳細信息
-Xloggc:輸出GC日志信息到文件中
打印的GC日志情況:
0.118:?[GC?(Allocation?Failure)?0.118:?[ParNew?(promotion?failed):?8143K->8713K(9216K),?0.0043061?secs]0.122:?[CMS:?8194K->6675K(10240K),?0.0038347?secs]?12239K->6675K(19456K),?[Metaspace:?3042K->3042K(1056768K)],?0.0082981?secs]?[Times:?user=0.03?sys=0.01,?real=0.01?secs]?
Heap
?par?new?generation???total?9216K,?used?2213K?[0x00000007bec00000,?0x00000007bf600000,?0x00000007bf600000)
??eden?space?8192K,??27%?used?[0x00000007bec00000,?0x00000007bee297c8,?0x00000007bf400000)
??from?space?1024K,???0%?used?[0x00000007bf500000,?0x00000007bf500000,?0x00000007bf600000)
??to???space?1024K,???0%?used?[0x00000007bf400000,?0x00000007bf400000,?0x00000007bf500000)
?concurrent?mark-sweep?generation?total?10240K,?used?6675K?[0x00000007bf600000,?0x00000007c0000000,?0x00000007c0000000)
?Metaspace???????used?3063K,?capacity?4496K,?committed?4864K,?reserved?1056768K
??class?space????used?334K,?capacity?388K,?committed?512K,?reserved?1048576K
「日志詳解:」
GC:表明進行了一次垃圾回收,前面沒有Full修飾,表明這是一次Young GC
Allocation Failure:表明本次引起GC的原因是因為在年輕代中沒有足夠的空間能夠存儲新的數(shù)據(jù)了
ParNew:表明本次GC發(fā)生在年輕代并且使用的是ParNew垃圾收集器。ParNew是一個Serial收集器的多線程版本,會使用多個CPU和線程完成垃圾收集工作(默認使用的線程數(shù)和CPU數(shù)相同,可以使用-XX:ParallelGCThreads參數(shù)限制)
ParNew (promotion failed): 8143K->8713K(9216K) 8143K->8713K(9216K):單位是KB,三個參數(shù)分別為:GC前該內存區(qū)域(這里是年輕代)使用容量,GC后該內存區(qū)域使用容量,該內存區(qū)域總容量。
0.0043061 secs:該內存區(qū)域GC耗時,單位是秒
CMS: 8194K->6675K(10240K), 0.0038347 secs] 12239K->6675K(19456K)8194K->6675K(10240K):GC前該內存區(qū)域(這里是老年代)使用容量變化,10240K表示該內存區(qū)域總容量,
12239K->6675K(19456K):三個參數(shù)分別為:堆區(qū)垃圾回收前的大小,堆區(qū)垃圾回收后的大小,堆區(qū)總大小
Times: user=0.03 sys=0.01, real=0.01 secs:分別表示用戶態(tài)耗時,內核態(tài)耗時和總耗時
同時可以看到出現(xiàn)了promotion failed,那什么情況下會出現(xiàn)promotion failed?
推薦閱讀:46張PPT弄懂JVM、GC算法和性能調優(yōu)
?在進行Young GC時,Survivor Space放不下,對象只能放入老年代,而此時老年代也放不下時會出現(xiàn)
?
詳細介紹
「接下來詳細介紹GC過程:」
首先我們看如下代碼:
byte[]?array1?=?new?byte[4?*?1024?*?1024];
array1?=?null;
這行代碼直接分配了一個4MB的大對象,此時這個對象會直接進入老年代,接著array1不再引用這個對象

接著看下面的代碼:
byte[]?array2?=?new?byte[2?*?1024?*?1024];
byte[]?array3?=?new?byte[2?*?1024?*?1024];
byte[]?array4?=?new?byte[2?*?1024?*?1024];
byte[]?array5?=?new?byte[128?*?1024];
連續(xù)分配了4個數(shù)組,其中3個是2MB的數(shù)組,1個是128KB的數(shù)組,如下圖所示,全部會進入Eden區(qū)域中

接著會執(zhí)行如下代碼:
byte[]?array6?=?new?byte[2?*?1024?*?1024];
此時還能放得下2MB的對象嗎?不可能了,因為Eden區(qū)已經(jīng)放不下了。因此此時會直接觸發(fā)一次Young GC。
我們看下面的GC日志:
?ParNew (promotion failed): 8143K->8713K(9216K), 0.0043061 secs
?
這行日志顯示了,Eden區(qū)原來是有8000多KB的對象,但是回收之后發(fā)現(xiàn)一個都回收不掉,因為上述幾個數(shù)組都被變量引用了一,所以一定會直接把這些存活的對象放入到老年代里去,但是此時老年代里已經(jīng)有一個4MB的數(shù)組了,還能放的下3個2MB的數(shù)組和1個128KB的數(shù)組嗎?
明顯是不行的,此時一定會超過老年代的10MB大小。
所以此時我們看cms的gc日志:
?CMS: 8194K->6675K(10240K), 0.0038347 secs] 12239K->6675K(19456K), [Metaspace: 3042K->3042K(1056768K)], 0.0082981 secs
?
大家可以清晰看到,此時執(zhí)行了CMS垃圾回收器的Full GC,我們知道Full GC其實就是會對老年代進行Old GC, 同時一般會跟一次Young GC關聯(lián),還會觸發(fā)一次元數(shù)據(jù)區(qū)(永久代)的GC。
在CMS Full GC之前,就已經(jīng)觸發(fā)過Young GC了,此時大家可以看到此時Young GC就已經(jīng)有了,接著就是執(zhí)行針對 老年代的Old GC,也就是如下日志:
?CMS: 8194K->6675K(10240K), 0.0038347 secs]
?
「這里看到老年代從8MB左右的對象占用,變成了6MB左右的對象占用,這是怎么個過程呢?」
很簡單,一定是在Young GC之后,先把2個2MB的數(shù)組放入了老年代,此時要繼續(xù)放1個2MB的數(shù)組和1個128KB的數(shù)組到老年代,一定會放不下,所以此時就會觸發(fā)CMS的Full GC
然后此時就會回收掉其中的一個4MB的數(shù)組,因為他已經(jīng)沒人引用了
接著放入進去1個2MB的數(shù)組和1個128KB的數(shù)組
所以大家再看CMS的垃圾回收日志:CMS: 8194K->6836K(10240K), 0.0049920 secs,他是從回收前的8MB變成了 6MB
最后在CMS Full GC執(zhí)行完畢之后,其實年輕代的對象都進入了老年代,此時最后一行代碼要在年輕代分配2MB的數(shù)組就可以成功了

補充知識
為了方便理解上述內容,補充以下知識
「Young GC觸發(fā)條件:」
當年輕代Eden區(qū)域滿的時候會觸發(fā)一次Young GC
「Full GC觸發(fā)條件:」
Full GC用于清理整個堆空間。它的觸發(fā)條件主要有以下幾種:
1.顯式調用System.gc方法(建議JVM觸發(fā))。
2.元空間不足
3.年代空間不足,引起Full GC。這種情況比較復雜,有以下幾種:
大對象直接進入老年代引起,由
-XX:PretenureSizeThreshold參數(shù)定義Young GC時,經(jīng)歷過多次Young GC仍存在的對象進入老年代。
Young GC時,動態(tài)對象年齡判定機制會將對象提前轉移老年代。年齡從小到大進行累加,當加入某個年齡段后,累加和超過survivor區(qū)域
-XX:TargetSurvivorRatio的時候,從這個年齡段往上的年齡的對象進入老年代Young GC時,Eden和From Space區(qū)向To Space區(qū)復制時,大于To Space區(qū)可用內存,會直接把對象轉移到老年代
4.JVM的空間分配擔保機制可能會觸發(fā)Full GC:
空間擔保分配是指在發(fā)生Young GC之前,虛擬機會檢查老年代最大可用的連續(xù)空間是否大于新生代所有對象的總空間。
推薦閱讀:46張PPT弄懂JVM、GC算法和性能調優(yōu)
如果大于,則此次Young GC是安全的。
如果小于,則虛擬機會查看HandlePromotionFailure設置值是否允許擔保失敗。
如果HandlePromotionFailure=true,那么會繼續(xù)檢查老年代最大可用連續(xù)空間是否大于歷次晉升到老年代的對象的平均大小,如果大于,則嘗試進行一次Young GC,但這次Young GC依然是有風險的,失敗后會重新發(fā)起一次Full gc;如果小于或者HandlePromotionFailure=false,則改為直接進行一次Full GC。

「GC Easy工具」
這里推薦一個gceasy(https://gceasy.io)工具,可以上傳gc文件,然后他會利用可視化的界面來展現(xiàn)GC情況
如果覺得不錯,點個贊,轉發(fā)下再走吧,謝謝
參考:
https://www.oracle.com/java/technologies/javase/vmoptions-jsp.html
深入理解Java虛擬機(第3版)






關注Java技術棧看更多干貨


