JVM系统优化实践（15）：GC可视化工具实践

您好，我是湘王，这是我的CSDN博客，欢迎您来，欢迎您再来～

---

线上系统的JVM监测要么使用jstat、jmap、jhat等工具查看JVM状态，或者使用监控系统，如Zabbix、Prometheus、Open-FaIcon、Ganglia等。作为一个工具人，怎么能不懂jstat、jmap、jhat呢？

先来模拟一个BI（商业报表）系统。

一、环境：

JDK1.8_202_build-b08；

Windows 10 × 64位企业版（发行版本号15063）。

二、相关的JVM参数是：

-XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:NewSize=104857600 -XX:MaxNewSize=104857600 -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3145728 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/work/logs/gc.log

三、示例代码：

 

如果看过前面的文章，就可以从JVM参数推断出：

1、年轻代100M，其中Eden区80M，S0和S1各10M；

2、老年代100M；

3、使用ParNew + CMS垃圾回收算法；

4、分配的对象大小 ＞ 3M直接进入老年代；

5、年轻代对象年龄 ＞ 15时，进入老年代。

四、模拟步骤：

1、先启动程序运行；

2、通过JPS得到Java程序的PID；

3、使用jstat命令： jstat -gc [PID]或者jstat -gc [PID] 1000 1000。

得到GC日志结果，如图：

 

 

 

注意红框框的地方，可以看出：

1、Eden区从3276.8，逐步升至77588.4

2、当经过15秒，再分配对象发现已经超过eden空间大小时，触发YGC

3、首次YGC耗时3ms，S1：0 -> 720.7

YGC执行完后，S1大小 = 720.7，Eden大小 = 1805.6。经过15秒，Eden区再次从1805.6升至81920.0，触发第二次YGC。第二次YGC耗时1ms（总耗时4ms），S1：720.7 -> 0，S0：0 -> 875.4

 

如此循环交替，存活对象也在不断累积，但没有对JVM造成任何影响。Full GC发生的频率趋于0。不过可以试着让这个程序运行足够长的时间，反复观察YGC之后的eden、S0/S1和老年代的变化，看看是否会发生Full GC。

再来一个案例：一个亿级流量的实时日志采集系统。

1、每分钟执行100次计算，每次计算耗费10秒，需要消耗10M空间；

2、年轻代老年代各1.5G，年轻代按8：1：1分配；

3、eden=1.2G，S0=S1=100M；

4、每分钟会触发一次Young GC；

5、每次Young GC大概会有200M的存活对象；

6、每7分钟会触发一次Full GC；

7、频繁触发Full GC的主要原因在于S0/S1区空间太小。

一、环境：

1、JDK1.8_202_build-b08；

2、Windows 10 × 64位企业版（15063）。

二、相关JVM参数：

-XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:NewSize=104857600 -XX:MaxNewSize=104857600 -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=20971520 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/work/logs/gc.log

三、示例代码：

 

四、从JVM参数得知：

1、年轻代100M，其中Eden区80M，S0和S1各10M；

2、老年代100M；

3、使用ParNew + CMS垃圾回收算法；

4、分配的对象大小 ＞ 20M直接进入老年代；

5、年轻代对象年龄 ＞ 15时，进入老年代。

五、模拟步骤：

1、先启动程序运行；

2、通过JPS得到Java程序的PID；

3、使用jstat命令： jstat -gc [PID]或者jstat -gc [PID] 1000 1000。

通过jstat -gc [PID] 1000 1000得到如下GC日志：

 

 

从日志可以得知：

1、第1次Young GC后，就有30M对象存活，S0/S1放不下，直接进入老年代；

2、每隔1秒就触发1次Young GC，每次都有10~20M存活对象进入老年代；

3、当Young GC转移过来的存活对象老年代放不下或者空间也快占满时，触发Full GC；

4、Full GC也被频繁触发，基本上也是几秒钟就触发一次；

5、从第17次Young GC开始，S0=S1=0，而且到第146次之后，Full GC就不再被触发了；

6、可以发现Young GC比Full GC要慢，是因为它触发Full GC后，必须等Full GC执行完了，老年代有了足够的空间才能继续往里放存活对象。

最大的问题是Young GC后每次存活的对象太多，导致S0/S1空间不足，直接进入老年代，频繁触发Full GC。所以，需要对JVM进行优化，只需要调大年轻代即可：

-XX:InitialHeapSize=314572800 -XX:MaxHeapSize=314572800 -XX:NewSize=209715200 -XX:MaxNewSize=209715200 -XX:SurvivorRatio=2 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=20971520 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/home/work/logs/gc.log

增加了-XX:SurvivorRatio=2这个JVM参数。

顺便说一句：注意不要在JVM实验中钻牛角尖，因为eclipse等IDE，包括笔记本硬件、操作系统，都会对实验结果产生影响。核心是理解原理，然后结合实验结果去分析大的原理，而不是扣细微的细节，JVM自身内置会产生一些对象，所以对象占用之类的，都是不一样的。

---

感谢您的大驾光临！咨询技术、产品、运营和管理相关问题，请关注后留言。欢迎骚扰，不胜荣幸～