您好,我是湘王,这是我的51CTO博客,欢迎您来,欢迎您再来~
了解了基本的G1垃圾回收机制以后,就可以结合实际日志分析一下它的日志内容了,以后再遇到问题自己也能看懂。
首先要说明一下实验环境:
1、预先设置的JVM参数:
-XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:NewSize=10485760 -XX:MaxNewSize=10485760 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC
2、增加GC日志选项
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/work/logs/gc.log
3、操作系统和JDK环境(环境不同,结果可能不同)
Windows 10 × 64位企业版(15063)
JDK1.8_202_build-b08
示例的Java代码:
public static void main(String[] args) {
byte[] array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2 * 1024 * 1024];
array1 = null;
byte[] array2 = new byte[4 * 1024 * 1024];
}
这段代码在作用上就是个垃圾,实际开发的时候估计没谁会这么写,但用来分析GC内部的状态变化却是很好的例子。
执行第一行后,JVM状态为:
而执行完array1时,已堆满垃圾:
执行array2时,创建对象4M:byte[] array2 = new byte[4 * 1024 * 1024];
在已有3 × 2M对象情况下,eden空间不足,触发Young GC,可以看到日志内容:
1、CommandLine flags……打印出本次程序运行使用的JVM参数;
2、xxxx-xx-xxT22:16:12.896+0800: 0.107 [GC (Allocation Failure)……]表明在系统运行0.107秒之后发生了一次GC;
3、ParNew: 7291K->608K(9216K), 0.0008194 secs表明一次年轻代GC,GC前使用了7291K,GC后还有608K对象存活,GC后年轻代可用空间9216K,耗费0.0008194秒;
4、7291K->608K(19456K)表明整个JVM堆内存可用空间19456K,年轻代使用了7291K + 老年代10M,GC前整个JVM堆使用了7291K,GC后使用了608K;
5、Times: user=0.00 sys=0.00, real=0.00 secs表明本次GC消耗的时间,毫秒为单位。
GC前JVM内存状况:
GC后JVM内存状况:
7291K->608K(19456K)
再看看通过动态年龄判定进入老年代是怎么运行的。
1、相关JVM参数:
-XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:NewSize=10485760 -XX:MaxNewSize=10485760 -XX:MaxTenuringThreshold=15 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/work/logs/gc.log
2、Java示例代码:
public static void main(String[] args) {
byte[] array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2 * 1024 * 1024];
array1 = null;
byte[] array2 = new byte[128 * 1024];
byte[] array3 = new byte[2 * 1024 * 1024];
}
代码执行中创造了3 × 2M的数组,JVM状态为:
代码执行完成后:
查看GC日志可知:
第一次GC后有608K对象存活,这一次有750K对象存活;
750 - 608 ≈ 128K(刚好为array2大小,就是存活的array2)
【ParNew: 7586K->750K(9216K), 0.0008034 secs】表明
1、GC前:3 × 2M + 128K + 其他对象 = 7586K;
2、GC后:存活对象128K ≈ 750K - 608K,年轻代可用空间9216K。
查看GC日志:
Eden区使用了26%,正是array3对象;
Survivor From使用了73% = 750K / 1024K,保存存活对象
此时Survivor From:
1、存活对象年龄:1岁
2、存活对象大小:>Survivor × 50%
继续接下来完善代码,看看还会发生什么。
public static void main(String[] args) {
byte[] array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2 * 1024 * 1024];
array1 = new byte[2 * 1024 * 1024];
array1 = null;
byte[] array2 = new byte[128 * 1024];
byte[] array3 = new byte[2 * 1024 * 1024];
array3 = new byte[2 * 1024 * 1024];
array3 = new byte[2 * 1024 * 1024];
array3 = new byte[128 * 1024];
array3 = null;
byte[] array4 = new byte[2 * 1024 * 1024];
}
执行array4前,JVM内存状态:
执行array4后,触发Young GC:
1、第一次:ParNew: 7583K->797K(9216K), 0.0005995 secs
2、第二次:ParNew: 7100K->0K(9216K), 0.0029498 secs
3、存活的128K对象 + 原来的750K > Survivor × 50%
4、再次触发Young GC
按照动态年龄规则:年龄1 + 年龄2 + … … + 年龄n > Survivor × 50%
因此array2和Survivor中的剩余对象全部进入老年代。
上面的GC日志说明:
Eden区使用了26%,正是array4对象;
触发了动态年龄规则,S0、S1已经空了,而老年代使用了739K。
可以通过代码模拟对象年龄在15岁之后才进入老年代,自己测试一下,做一个小练习,然后对照GC日志看看结果是否如预期那样。
感谢您的大驾光临!咨询技术、产品、运营和管理相关问题,请关注后留言。欢迎骚扰,不胜荣幸~