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区域创建