GC日志怎么看

Young GC

案例准備

/**
 * 案例代碼
 */
public class Demo1 {

    public static void main(String[] args) {
        // 1. 在eden區創建了一個1m數組對象，main線程虛擬機棧中
        // 的main()方法棧幀的局部變量arry1指向它
        byte[] arry1 = new byte[1024 * 1024];
        // 2. eden區中創建了一個新對象，arry1指向第二個對象
        arry1 = new byte[1024 * 1024];
        // 3. eden區中創建了一個新對象，arry1指向第三個對象
        arry1 = new byte[1024 * 1024];
        // 4. arry1不指向任何對象，3個對象沒有gc root引用，變成了垃圾
        arry1 = null;
        // 5. 往eden區中創建一個2m對象，由於eden區最大只有4m，此時會觸發young gc
        byte[] arry2 = new byte[2 * 1024 * 1024];
    }

}

/**
 * 執行腳本
 */
java  -jar -Xmn5M -Xms10M -Xmx10M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log  demo-1.0.jar

 

　　首先我將新生代大小設置為5m，最大堆10m，eden和from、to比例為8:1:1 ；大對象閾值為10m(超過閾值直接進入老年代)；垃圾回收器用的 parnew + cms。上面的代碼肯定會young gc的。

gc執行過程

　　圖是運行后的gc日志，我們來逐步分析一下。

1. CommandLine flags：這個是看程序運行時的jvm參數的。有我們命令指定的，也有jvm自身默認的一些參數。
2. GC (Allocation Failure)：這個從字面意思上就說了，引發這次gc的原因是"對象分配失敗"
2.1 0.206 表示是系統大概運行200多毫秒之后發生的本次gc
2.2 ParNew: 3498K->281K(4608K)表示新生代觸發了young gc，用的parnew垃圾回收器。
　　3498K   表示gc之前，新生代已經占用的大小，3m*1024=3072k，多的那些除了對象本身大小，還會有對象的一些其他信息
　　281K     表示gc之后，存活下來的對象大小，此時它們的年齡就是一歲
　　4608K   代表了可用新生代的大小。eden + 一個s區 = 1024*4+512 = 4608k。因為兩個s區只有一個是可以放存活對象那個的，另外一個必須是空間的，讓新生代的使用率達到90%
2.3 0.0007884 secs 表示此次gc回收這3m對象一共花了0.78毫秒
2.4 3498K->281K(9728K), 0.0008658 secs 是整個堆的內存情況，9728K是整個堆的可用大小，新生代4.5m+老年代5m=9728k
2.5 Times: user=0.00 sys=0.00, real=0.00 secs 表示本次gc消耗時間，因為只有幾毫秒，所以以秒為單位來看都是0
3. 下面則是GC過后的堆內存使用情況
　　3.1 par new generation total 4608K, used 2411K 表示parnew負責的年輕代總共有4.5m，已使用2.3m(是因為我們后面創建了一個2m的數組)
　　3.2 eden space 4096K, 52% used 表示eden區的4m用了一半，存放了我們那個2m的數組
　　3.3 from space 512K, 55% used 表示from區占用了一半，就是回收后存活的281k對象
　　3.4 to space 512K, 0% used 此時的to區域還沒有對象占用
　　3.5 concurrent mark-sweep generation total 5120K, used 0K 表示cms管理的5m老年代內存
　　3.6 Metaspace used 2671K, capacity 4486K, committed 4864K, reserved 1056768K
　　　  class space used 288K, capacity 386K, committed 512K, reserved 1048576K
　　　  表示的元空間和和class信息

模擬對象進入老年代

/**
 * 案例代碼
 */
public class Demo1 {

    public static void main(String[] args) {
        byte[] arry1 = new byte[2 * 1024 * 1024];
        arry1 = new byte[2 * 1024 * 1024];
        arry1 = new byte[2 * 1024 * 1024];
        arry1 = null;

        byte[] arry2 = new byte[256 * 1024];

        /* 1. eden區總共才8m，已占用 6.25 ，此時第一次觸發young gc
              arry2就被回收到from區域了、年齡為1；arry3在gc后放入了eden區  */
        byte[] arry3 = new byte[2 * 1024 * 1024];

        arry3 = new byte[2 * 1024 * 1024];
        arry3 = new byte[2 * 1024 * 1024];
        arry3 = new byte[256 * 1024];
        arry3 = null;
        /* 2. 第二次觸發young gc，且由於對象>50%from區域，觸發了空間擔保機制；
              現在 from區域全部進入了老年代(不觸發的話還是在from區)，arry4進去了eden區  */
        byte[] arry4 = new byte[2 * 1024 * 1024];
    }

}




/**
 * 執行腳本
 * 新生代大小設置為10m，最大堆20m，eden和from、to比例為8:1:1 ；對象超過15歲進入老年代；大對象閾值為10m(超過閾值直接進入老年代)；垃圾回收器用的 parnew + cms
 */
java  -jar -Xmn10M -Xms20M -Xmx20M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=10M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log  demo-1.0.jar
        

Full GC

案例代碼

/**
 * 案例代碼
 */
public class Demo1 {

    public static void main(String[] args) {
        // 大於閾值3M，直接進入老年代
        byte[] arry1 = new byte[4 *1024 * 1024];
        // 沒有gc root引用，成為垃圾
        arry1 = null;
        // eden區創建對象
        byte[] arry2 = new byte[2 *1024 * 1024];
        byte[] arry3 = new byte[2 *1024 * 1024];
        byte[] arry4 = new byte[2 *1024 * 1024];
        byte[] arry5 = new byte[256 * 1024];
        /* 此時eden放不下，觸發young gc；
           但是arry2 arry3 arry4 arry5 都被引用在，不會被回收，於是放入老代
           老年代還剩 10-4=6m ，於是老年代放不下觸發了full gc
           此時 arr2 arr3 arr4 arr5 都到了老年代。 arr6 在eden區*/
        byte[] arry6 = new byte[2 *1024 * 1024];
    }

}

/**
 * 執行腳本
 * 新生代大小設置為10m，最大堆20m，eden和from、to比例為8:1:1 ；對象超過15歲進入老年代；大對象閾值為3m(超過閾值直接進入老年代)；垃圾回收器用的 parnew + cms
 */
java  -jar -Xmn10M -Xms20M -Xmx20M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log  demo-1.0.jar

GC日志分析

1. byte[] arry6 = new byte[2 *1024 * 1024] 執行這行代碼的時候，新生代已經有了6.25m，此時eden區域不夠觸發了young gc
　　ParNew (promotion failed): 6907K->7445K(9216K)
　　說明新生代已經用了6907kb空間，在進行gc時發現都在引用無法被回收，所以回收后還剩7445k，from區放不下，則放入老年代
2. CMS: 8194K->6677K(10240K)
　　由於之前arr1在老年代占用了4m還剩6m，放不下7445k，所以進行了full gc 回收后 (4m+7445k)回收后還剩 6677k
　　11003K->6677K(19456K)
　　表示新生代+老年代一共19456k內存，共占用了11003k，回收后還剩6677k
3. [Metaspace: 2664K->2664K(1056768K)] 老年代gc觸發時，都會順手去回收元空間
4. gc完成，arr6在eden區域創建