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

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存活下来2030MB对象,同时进入老年代的对象在2030MB,老年代触发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的性能!

文章分类
后端
文章标签