30-案例实战2：通过jps+jstat针对系统问题分析和优化

案例背景：

参考【案例实战剖析-日处理上亿数据的系统内存分析和优化】

示例代码：

/**
 * @Description: 案例实战-通过jps、jstat、jmap、jhat工具进行联调优化
 *  JVM参数： -XX:NewSize=100m -XX:MaxNewSize=100m -XX:InitialHeapSize=200m -XX:MaxHeapSize=200m -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15
 *  -XX:PretenureSizeThreshold=20m -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log
 *
 */
public class JVMTest2 {
   
   
    public static void main(String[] args) throws InterruptedException {
   
   
        Thread.sleep(30000);
        while(true){
   
   
            loadData();
        }
    }

    public static final int _1MB = 1024 * 1024;

    private static void loadData() throws InterruptedException {
   
   
        byte[] data = null;
        for (int i = 0; i < 4; i++) {
   
   
            data = new byte[10 * _1MB ];
        }
        data = null;
        byte[] data1 = new byte[10 * _1MB];
        byte[] data2 = new byte[10 * _1MB];
        byte[] data3 = new byte[10 * _1MB];
        data3 = new byte[10 * _1MB];

        Thread.sleep(1000);
    }
}

JVM参数调整只有： -XX:PretenureSizeThreshold=20m 大对象阈值改成20M，防止直接进入老年代

代码说明：

• 每秒调用一次loadData()方法，分配4个10M的数组，但是立马会成为垃圾，紧接着继续分配2个10M的数组分别为data1和data2，作为GC Roots对象持续引用，data3变量分配10M，此时内存已经分配了80M，那最后一行代码再申请分配10M的时候，就会触发GC。
• 通过模拟每秒触发一次GC，通过工具查看分析进行优化

数据分析：

1. 通过jstat -gc 进程id 1000 1000 每秒打印一次jvm内存使用情况，如下：

我们可以看到，程序正式开始第一次调用loadData()方法时，就发生了一次MinorGC，跟我们的预期一致。

​ 该次GC过后有 979KB的对象进入了S1区，这部分对象对应的应该是系统自己产生的一些GCRoots对象，同时我们注意看！OU里面也有对应而且有30MB，OU代表的是老年代区域内存，那么说明第一次GC后就有30MB对象进入了老年代。

​ 这是为什么呢？老年代为什么直接就有30MB对象了？大家思考下。

在我们的loadData() 方法中是有3个GCRoots对象的，这三个对象刚好加在一起是30MB，那么在发生Minor GC的时候，这部分对象是要进入Survivor区的，But！我们的Survivor区域只有10MB大小，很明显是放不下的！因此，通过空间分配担保原则，我们的这部分30MB对象会直接进入到老年代！

1. 我们继续分析后续的数据：

我们观察OU这一列数据，从最开始的30MB对象到后续，每次Minor GC都会进入20MB~30MB左右的对象，因为每次Minor GC过后存活下来的对象都无法存放到Survivor区域，因此都直接进入到老年代了！

​ 同时我们注意看：当老年代的占用达到50MB左右的时候，下一次继续进30MB对象的话 其实内存占用比已经达到了92%左右，那么会触发CMS垃圾收集器进行Full GC，因此60MB的老年代占用这里其实已经发生了一次Full GC，通过FGC次数我们也能看到：

​ 同样的此时老年代内存是60MB，下一次Minor GC还会再来30MB对象，又会触发一次Full GC，最终老年代空间占用降到了30MB，也对应了1次Full GC. 说明本次回收了60MB老年代垃圾对象，又进来了30MB对象。

因为老年代的内存总共就100MB，占用60MB,再来30MB进入老年代，那么会触发回收阈值从而导致Full GC，回收掉目前已经存在的60MB对象，那么新进来的30MB对象也就留在了老年代。

1. 小结

   按照我们此段代码的运行，我们可以总结得出，每秒申请分配80MB内存，触发一次MinorGC，每次MinorGC存活下来20~30MB对象，同时进入老年代的对象在20~30MB，老年代触发Full GC几乎在3秒一次。

2. GC时间分析

我们再来看GC时间，14次MinorGC总共耗时128ms，平均一次要9ms，6次Full GC，总耗时9ms，1次Full GC耗时1.5ms。

注意：Full GC的时间反而比Minor GC的时间更少！这是为什么？

这里大家要非常清楚我们的Full GC是为什么触发的？

由于每一秒都要触发Minor GC，而MinorGC过后会有30MB左右的对象要放入老年代，当老年代内存不够了，就会触发Full GC的执行，那么细想下，是不是这一秒有30MB对象需要进入老年代，而老年代内存不足触发Full GC，GC完毕后才有空间让30MB对象进入？

那么换句话说，是不是Minor GC得等到Full GC执行完毕后才能将30MB对象放入老年代，从而结束这次Minor GC？

因此，这就是为什么Minor GC的时间比Full GC的时间还要长的原因！

JVM性能优化

针对上述问题，我们已经知道了数据的分析过程也知道了GC的频率和时长，我们如何来进行优化呢？

其实很简单，我们之前说过针对JVM性能优化，优化什么？其实就是尽量减少Full GC次数和频率或避免发生。而我们当前的系统每秒都有30MB对象进入老年代，这个点就是根本点！我们要避免这部分对象每次都进入老年代，触发Full GC进行回收，我们尽量在Minor GC中进行回收！

而这30MB对象是Minor GC回收的时候由于Survivor区太小无法存放，导致进入老年代！

那么分析到这儿了，我们也就有思路了， 调大新生代内存，以及Survivor区大小。

Survivor区大小只要大于30MB即可，那么我们可以设置为50MB，按照默认8:1:1比例，整个新生代的大小就为500MB，那么Eden就是400MB，不过这里我们为了更好的观察数据（或者节约成本）我们可以将Eden区控制在大于80MB即可，比如100MB。

那么Eden100MB，Survivor50MB，比例就会变成 2:1:1，老年代可以不变还是100MB，内存分配如下：

JVM参数设置如下：

数据调试分析
接下来我们继续通过工具分析数据：

在上诉的截图里我们可以很清楚的看到：

• 第一次发生GC的时候，有11MB左右的对象进入了S1区
• 后续GC增长不大，最多也就32MB对象存留Survivor区，对于Survivor区50MB的大小而言能存放
• 第8次GC的时候，有1026KB对象进入了老年代，而且当次S1区对象有32M，大于了50%，根据动态年龄判定，年龄最大的那部分系统对象应该是进入了老年代，不过占用不大，可以接受

小结：

通过优化后的系统，几乎很难再触发Full GC的执行了，但是我们当前的系统其实Minor GC的触发也几乎是在每秒执行的，15次MinorGC也就145ms，如果还想进一步优化的同学，可以直接调整Eden的大小即可。

因此大多数线上系统都是如此，我们通过数据的分析发现问题后，精准调整对应的内存比例分配，就可以大幅度提升JVM的性能！