【日活百万电商返利App】一次线上JVM问题定位排查

2020-03-27 14:47:10 浏览数 (1)
前言

这篇文章最早是写于2019-08-14,在公司的confluence发布过。由于最近想标记整理压缩一些知识点碎片，于是便有了这篇文章的诞生。

项目介绍
  • 电商返利App
  • DAU 百万
  • 注册用户近3000w
  • DNU 几十万
线上排查工具介绍
  • jmap是java虚拟机自带的一种内存映像工具。
  • jstat是JDK自带的一个轻量级小工具。全称Java Virtual Machine statistics monitoring tool，它位于java的bin目录下，主要利用JVM内建的指令对Java应用程序的资源和性能进行实时的命令行的监控，包括了对Heap size和垃圾回收状况的监控。
  • jstack是Jdk自带的线程跟踪工具，用于打印指定Java进程的线程堆栈信息。
  • mat是一个检查内存泄漏的工具
  • vjmap是唯品会开源出来的是用于排查内存缓慢泄露，老生代增长过快原因的利器。因为jmap -histo PID 打印的是整个Heap的对象统计信息，而为了定位上面的问题，我们需要专门查看OldGen对象，和Survivor区大龄对象的工具。(只支持CMS和ParallelGC，不支持G1)
  • jvisualvm是JDK自带的监控程序。能够监控线程，内存情况，查看方法的CPU时间和内存中的对象，已被GC的对象，反向查看分配的堆栈
  • jconsole是JDK自带的监控程序。用于对JVM中内存,线程和类等的监控。
线上排查使用到的命令

查看进程使用gc情况: jstat -gc 16969<pid> 5000(打印时间间隔)

  • S0C：年轻代中第一个survivor（幸存区）的容量 (KB)
  • S1C：年轻代中第二个survivor（幸存区）的容量 (KB)
  • S0U：年轻代中第一个survivor（幸存区）目前已使用空间 (KB)
  • S1U：年轻代中第二个survivor（幸存区）目前已使用空间 (KB)
  • EC：年轻代中Eden（伊甸园）的容量 (KB)
  • EU：年轻代中Eden（伊甸园）目前已使用空间 (KB)
  • OC：Old代的容量 (KB)
  • OU：Old代目前已使用空间 (KB)
  • MC：元空间的容量 (KB)
  • MU：元空间目前已使用空间 (KB)
  • CCSC:压缩类空间大小
  • CCSU:压缩类空间使用大小
  • YGC：从应用程序启动到采样时年轻代中gc次数
  • YGCT：从应用程序启动到采样时年轻代中gc所用时间(s)
  • FGC：从应用程序启动到采样时old代(全gc)gc次数
  • FGCT：从应用程序启动到采样时old代(全gc)gc所用时间(s)
  • GCT：从应用程序启动到采样时gc用的总时间(s)

类加载统计 jstat -class 16969<pid>

java进程堆栈信息打印 jstack 16969<pid>

查看pid对应的线程使用CPU情况和内存占用: top -Hp pid

打印当前java堆中各个对象的数量,大小一页数据为50 jmap -histo pid | more -n 50

查看java堆中实例数数量前10的类 jmap -histo pid | sort -n -r -k 2 | head -10

查看java堆中容量前10的类 jmap -histo pid | sort -n -r -k 3 | head 10

查看整个JVM内存状态 jmap -heap <pid>

快照java堆信息到指定文件(会触发Full GC, 如果快照文件过大,会使目标进程stop world) jmap -dump:format=b,file=quMall.dump 16969<pid>

显示堆中活跃对象的统计信息,比如实例数量,占用空间(会触发Full GC) jmap -histo:live <pid>

查看进程使用的GC算法(实际上用到了javaagent技术来实现的： jinfo -flags 23467<pid>

查看应用运行的时间 ps -p 11864<pid> -o etime

显示垃圾回收的相关信息, 同时显示最后一次或当前正在发生的垃圾回收的诱因 jstat -gccause <pid> 5000<interval>

查看GC使用情况(比如s0区使用了多少): jstat -gcutil 6011<pid>

查看JVM内存中三代（young,old,metaspace）对象的使用和占用大小 jstat -gccapacity <pid>

查看metaspace中对象的信息及其占用量 jstat -gcmetacapacity<pid>

查看年轻代对象的信息 jstat -gcnew <pid>

查看年轻代对象的信息及其占用量 jstat -gcnewcapacity <pid>

查看old代对象的信息 jstat -gcold <pid>

查看old代对象的信息及其占用量 jstat -gcoldcapacity <pid>

查看进程是否启动AdaptiveSizePolicy策略 jinfo -flag UseAdaptiveSizePolicy 26626<pid>

查看MetaSpace默认初始化大小(默认是20.8MB) java -XX: PrintFlagsInitial|grep Meta

打印整个堆中对象的统计信息，按对象的total size排序 ./vjmap.sh -all PID > /tmp/histo.log

推荐，打印老年代的对象统计信息，按对象的oldgen size排序，比-all快很多，暂时只支持CMS ./vjmap.sh -old PID > /tmp/histo-old.log

推荐，打印Survivor区的对象统计信息，默认age>=3 ./vjmap.sh -sur PID > /tmp/histo-sur.log

推荐，打印Survivor区的对象统计信息，查看age>=4的对象 ./vjmap.sh -sur:minage=4 PID > /tmp/histo-sur.log

推荐，打印Survivor区的对象统计信息，单独查看age＝4的对象 ./vjmap.sh -sur:age=4 PID > /tmp/histo-sur.log

仅输出存活的对象,原理为正式统计前先执行一次full gc ./vjmap.sh -old:live PID > /tmp/histo-old－live.log

过滤对象大小，不显示过小的对象。按对象的oldgen size进行过滤，只打印OldGen占用超过1K的数据 ./vjmap.sh -old:minsize=1024 PID > /tmp/histo-old.log

dump文件分析

1.快照目标进程的堆信息到执行文件jmap -dump:format=b,file=mall.dump 16969<pid>。dump文件比较大,如果从生产服务器拉到本地,会触发带宽报警。如果要执行该操作，请在电商研发团队事先@所有人。

2.使用mat工具打开堆快照文件。(mat的基本操作可以看参考文章)

  • Histogram可以列出内存中的对象，对象的个数以及大小
  • Dominator Tree可以列出处于活跃状态的大对象。
  • Top consumers通过图形列出最大的object。
  • Leak Suspects自动分析泄漏的原因。

3.点开Reports->Leak Suspects 查看有可能内存泄漏的地方， ，可以体现出哪些对象被保持在内存中，以及为什么它们没有被垃圾回收。 图1可以看到WebappClassLoader占用了25,177,944字节的容量， 这是tomcat的类加载器，JDK自带的系统类加载器中占用比较多的是HashMap，这个其实比较正常。 图2可以看到JDBC4Connection的实例有539个，占用的空间是22,302,560字节，这个是比较可疑。

4.点开Actions->Histogram，模拟搜索JDBC。发现关于JDBC相关的实例数还挺多的。右键点击com.mysql.jdbc.JDBC4Connection，选择with outgoing references 查看JDBC4Connection实例具体的依赖关系。

  • with incoming references表示的是 当前查看的对象，被外部应用。
  • with outGoing references表示的是 当前对象，引用了外部对象。

5.选中一个JDBC4Connection实例，右键选择Merge Shortest Paths to GC roots -> with all references查看JDBC4Connection到GC roots的路径。

  • Paths to GC : 从当前对象到GC roots的路径，这个路径解释了为什么当前对象还能存活，对分析内存泄露很有帮助，这个查询只能针对单个对象使用。
  • Merge Shortest Paths to GC ：从GC roots到一个或一组对象的公共路径。
  • exclude all phantom/weak/soft etc.reference(排除所有虚弱软引用) ->查看剩余未被回收的强引用对象占用原因 & GC Roots。

6.可见JDBC4Connection被2个对象引用，一个是BasicResourcePool中的formerResources(曾经在连接池里呆过的对象)变量，一个是MySQL JDBC Driver的ConnectionPhantomReference

NonRegisteringDriver.java

这个虚引用是在JDBC Driver在构造connection时用来track这个connection的，在被GC回收前做一些clean up（释放资源）的事情，所以每个connection被构造出来后，都会被track，这是Driver为了防止有资源随着连接回收而未释放的手段。

代码语言：javascript复制
public class AbandonedConnectionCleanupThread extends Thread {
    private static boolean running = true;
    private static Thread threadRef = null;

    public AbandonedConnectionCleanupThread() {
        super("Abandoned connection cleanup thread");
    }

    public void run() {
        threadRef = this;
        while (running) {
            try {
                Reference<? extends ConnectionImpl> ref = NonRegisteringDriver.refQueue.remove(100);
                if (ref != null) {
                    try {
                        ((ConnectionPhantomReference) ref).cleanup();
                    } finally {
                        NonRegisteringDriver.connectionPhantomRefs.remove(ref);
                    }
                }

            } catch (Exception ex) {
                // no where to really log this if we're static
            }
        }
    }

    public static void shutdown() throws InterruptedException {
        running = false;
        if (threadRef != null) {
            threadRef.interrupt();
            threadRef.join();
            threadRef = null;
        }
    }

}

被PhantomReference引用的对象在被GC时, JVM会将PhantomReference对象扔到refqueue。然后会通过 AbandonedConnectionCleanupThread这个线程从NonRegisteringDriver.refQueue中拿到ConnectionPhantomReference，然后执行cleanup方法，最后删除connectionPhantomRefs这个ConcurrentHashMap中的ConnectionPhantomReference对象，完成connection相关资源的回收。

但是我们排查的结果是ConnectionPhantomReference并没有得到清理。经过查阅一些资料，得出以下结论:

似乎问题是CompressionInputStream'有对同一ConnectionImpl的引用，ConnectionPhantomReference正在等待在ReferenceQueue上排队，说它有资格进行垃圾回收。ConnectionPhantomReference通过它引用的com.mysql.jdbc.NetworkResources对象对CompressionInputStream有一个强引用。ConnectionPhantomReference由NonRegisteringDriver中的静态ConcurrentHashMap强烈保存。结果是ConnectionPhantomReference有效地引用了它要等待GC的JDBC4Connection对象; 并使JDBC4Connection实例保持活动状态，因此不符合垃圾回收的条件。

所以在我们程序中要定时去清除ConnectionPhantomReference引用。在quMall项目中一台服务器中Full GC清除7110个PhantomReference引用，耗时竟然达到0.6s。但是通过程序定时删除这些引用,下一次Full GC清除这些引用耗时可以忽略不计。

代码语言：javascript复制
/**
 * @author xiaoma
 * @version V1.0
 * @Description: 解决PhantomReference引用过多,造成内存泄漏
 * PhantomReference, 7110 refs, 587 refs, 0.6012897 secs
 * @date 2019/8/12 15:12
 */
@Service
public class MysqlConnectionPhantomRefCleaner implements InitializingBean {

    private Field declaredField;
    private ConcurrentHashMap referenceMap;

    @Override
    public void afterPropertiesSet() throws Exception {
        try {
            declaredField = NonRegisteringDriver.class.getDeclaredField("connectionPhantomRefs");
            declaredField.setAccessible(true);
            referenceMap = (ConcurrentHashMap<?, ?>) declaredField.get(null);
        } catch (Exception ex) {
            LogService.info(MessageFormat.format(
                    "清除PhantomReference计划, 初始化失败:{0}",
                    ex.getMessage()
            ));
        }
    }

    /**
     * 每秒10s清理一次
     */
    @PostConstruct
    public void clear() {
        ScheduledExecutorService scheduledExecutorService = Executors.newScheduledThreadPool(1);
        LogService.info("清除PhantomReference计划, 初始化成功");

        synchronized (MysqlConnectionPhantomRefCleaner.class) {
            scheduledExecutorService.scheduleAtFixedRate(new Runnable() {
                @Override
                public void run() {
                    if (!referenceMap.isEmpty()) {
                        int size = referenceMap.size();
                        LogService.info(MessageFormat.format(
                                "清除PhantomReference计划, current Mysql ConnectionPhantomReference map size:{0} start to clear",
                                size

                        ));
                        referenceMap.clear();
                    }
                }
            }, 1, 10, TimeUnit.SECONDS);
        }
    }

}

7.再来讲讲formerResources引用，我列出formerResources 相关代码。

代码语言：javascript复制
private void removeResource(Object resc, boolean synchronous){
    ...
    unused.remove(resc);
    destroyResource(resc, synchronous, checked_out);

    addToFormerResources( resc );

    asyncFireResourceRemoved( resc, false, managed.size(), unused.size(), excluded.size() );
    ...
}

private void cullExpired(){
    ...
    if ( shouldExpire( resc ) )
    {
        if ( logger.isLoggable( MLevel.FINER ) )
            logger.log( MLevel.FINER, "Removing expired resource: "   resc   " ["   this   "]");

        target_pool_size = Math.max( min, target_pool_size - 1 ); //expiring a resource resources the target size to match

        removeResource( resc );
    }
    ...
}

public Object checkoutResource( long timeout ){

    Object resc = prelimCheckoutResource( timeout );

...
}

private synchronized Object prelimCheckoutResource( long timeout ){
    ...
    Object  resc = unused.get(0);
    ...
    else if ( shouldExpire( resc ) ){
      removeResource( resc );
      ensureMinResources();
      return prelimCheckoutResource( timeout );
    }
}

cullExpired这个方法是c3p0的一个定时器里执行的方法，用来检查过期连接的。c3p0会定时对idle连接进行连接池过期检查。若空闲时间超过MaxIdleTime，则会remove，会加入到formerResources中。如果最后剩下的idle连接数超过或者小于minIdle的连接数，也会相应的进行缩减或者扩容，直到minIdle个连接数。

idleConnectionTest是维持连接池的idle连接和MySQL之间的心跳，防止MySQL Server端踢掉应用的连接，而前面提到的连接池过期检查则是c3p0对连接归还后是否长时间没被再次借出为依据来判断连接是否过期。

如果配置了maxIdleTime, 处于keep alived的连接会被认为是过期连接。连接池将丢弃这些连接，并创建新连接。因此,NonRegisteringDriver将慢慢地保留越来越多的JDBC4Connection对象，并且您将慢慢地发生内存泄漏。 这里也会造成频繁的Young GC。

checkoutResource是每次获取连接的时候，会对连接进行过期检查的校验。如果连接空闲时间超过MaxIdleTime,该连接会标志已经过期， 调用removeResource，将连接加入到formerResources中。配置了MaxIdeTime参数，checkout操作会加快过期连接的失效和创建新连接的速度，导致formerResources里退休的连接变多，最终加快了老年代的增长和内存泄漏。

正确的姿势是去掉maxIdleTime配置， 配置了idleConnectionTestPeriod这个参数即可。

类似的问题还会存在JedisPoolConfig中，这些都可以归结成持久化对象在JVM中的存活生命周期问题。 连接池对象，本地缓存对象都是，这些对象存活时间久，处于JVM的老生代中，应用希望尽可能的重用它们，但若结合具体场景的配置或使用不合理，导致这些对象并未最大化被重用，比如上面提到的过期检查导致不断有新的对象被创建出来，因为是持久化对象，很容易就进入到了老生代，霸占了资源。

上图是JedisPoolConfig默认配置，每30秒进行一次扫描，如果发现有空闲时间超过60s连接，执行清除操作。如果当前连接少于minIdle个,则会再创建新的。而清除掉的连接若未及时的被YGC掉，会进入到老年代。

我们只需配置minEvictableIdleTimeMills=-1，softMinEvictableIdleTimeMillis=60000就可以上述的问题。这样就不会对minIdle的连接进行清理，只有当连接数超过minIdle后,才进行清理工作。

JVM基础参数

-XX:ParallelGCThreads=8 JVM在进行并行GC的时候,用于GC的线程数，一般是机器的核数。

-XX: UseConcMarkSweepGC 打开此开关参数后，使用ParNew CMS Serial Old收集器组合进行垃圾收集。Serial Old作为CMS收集器出现Concurrent Mode Failure的备用垃圾收集器。

-XX: UseParallelGC 打开此开关参数后，使用Parallel Scavenge Serial Old收集器组合进行垃圾收集。

-XX: UseParallelOldGC 打开此开关参数后，使用Parallel Scavenge Parallel Old收集器组合进行垃圾收集。

JDK1.8 默认使用Parallel Scavenge年轻代回收器和Parallel Old老年代回收器, 默认打开AdaptiveSizePolicy策略。CMS默认关闭AdaptiveSizePolicy策略。在quMall项目中,没有关闭AdaptiveSizePolicy策略，造成S0,S1区只有8MB，从而导致频繁Young GC。所以要手动设置使Eden:S0:S1 = 8 : 1 : 1

代码语言：javascript复制
-XX:SurvivorRatio=8
-XX:-UseAdaptiveSizePolicy

AdaptiveSizePolicy为了达到三个预期目标，涉及以下操作：

  • 如果 GC停顿时间超过了预期值，会减小内存大小。理论上，减小内存，可以减少垃圾标记等操作的耗时，以此达到预期停顿时间。
  • 如果应用吞吐量小于预期，会增加内存大小。理论上，增大内存，可以降低 GC的频率，以此达到预期吞吐量。
  • 如果应用达到了前两个目标，则尝试减小内存，以减少内存消耗。

引用R大说过的话： HotSpot VM里，ParallelScavenge系的GC（UseParallelGC,UseParallelOldGC）默认行为是SurvivorRatio如果不显式设置就没啥用。显式设置到跟默认值一样的值则会有效果。因为ParallelScavenge系的GC最初设计就是默认打开AdaptiveSizePolicy的，它会自动、自适应的调整各种参数

在这里说下默认的ParallelScavenge 和 ParallelOld垃圾回收器:

  • Paralle Scavenge(年轻代):
    • 新生代收集器，可以和Serial Old、Parallel组合使用，不能和CMS组合使用。采用复制算法。使用多线程进行垃圾回收，回收时会导致Stop The World。关注系统吞吐量。
    • -XX:MaxGCPauseMillis：设置大于0的毫秒数，收集器尽可能在该时间内完成垃圾回收。
    • -XX:GCTimeRatio：大于0小于100的整数，即垃圾回收时间占总时间的比率，设置越小则希望垃圾回收所占时间越小，CPU能花更多的时间进行系统操作，提高吞吐量。也就是垃圾收集时间占总时间的比率，相当于是吞吐量的倒数。如果把此参数设置为19，那允许的最大GC时间就占总时间的5%（即1 /（1 19）），默认值为99，就是允许最大1%（即1 /（1 99））的垃圾收集时间。
    • GC日志关键字：PSYoungGen
  • Parallel Old(年老代）
    • 年老代收集器，只能和Parallel Scavenge组合使用(Parallel Scavenge收集器的年老代版本。采用标记-整理算法，会对垃圾回收导致的内存碎片进行整理关注吞吐量的系统可以将Parallel Scavenge Parallel Old组合使用。
    • GC日志关键字：ParOldGen

对于重载了 Object 类的 finalize 方法的类实例化的对象（这里称为 f 对象)，JVM 为了能在GC 对象时触发f对象的finalize 方法的调用，将每个f对象包装生成一个对应的FinalReference 对象，方便 GC 时进行处理。

SocksSocketImpl中重载了finalize方法，防止Socket 连接忘记关闭导致资源泄漏而进行的保底措施。

对于RPC调用短连接场景，每调用一次就会创建一个Socket 对象。致使 FinalReference 对象非常多, 因此YoungGC 耗时增加。 下面参数, 可以在 GC 的时候多线程并行处理Reference，降低GC时长。 -XX: ParallelRefProcEnabled

开启压缩对象指针(默认开启)，启用CompressOops后，会压缩的对象： • 每个Class的属性指针（静态成员变量） • 每个对象的属性指针 • 普通对象数组的每个元素指针。 -XX: UseCompressedOops

  • 扩展知识:
    • HotSpot虚拟机中，对象在内存中存储的布局，可以分为三块区域：对象头(header)，实例数据(Instance Data)，对象填充(Padding)。对象头包括markword和类型指针(class对象指针)。如果是数组，还包括数组长度。
    • 实例数据：对象实际的数据。
    • 对象填充：对齐，按8字节对齐。Java内存地址按照8字节对齐，长度必须是8的倍数。 markword：用于存储对象自身运行时的数据，如哈希码，GC分代年龄，锁状态标志，线程持有的锁，偏向线程ID，偏向时间戳。
    • 在32位JVM中，markword是32bit，类型指针是32bit，数组长度是32bit。从而得知一个普通对象头是8个字节，一个数组对象头是16个字节。
    • 在64位JVM中，markword是64bit，类型指针是64bit，开启指针压缩时是32bit，数组长度是64bit，开启压缩时是32bit。从而得知一个无压缩的普通对象头是16个字节，一个开启压缩的普通对象头是12个字节。一个无压缩的数组对象头是24个字节，一个开启压缩的数组对象头是16个字节。对象头在32位系统占用8字节，而在64位系统上占用16字节。
    • Referece类型在32位系统上每个占用4字节，而在64位系统上每个占用8字节。

    在Metaspace中开辟出一块类指针压缩空间(Compressed Class Space)，默认是1G(默认开启)。对象中指向类元数据的指针会被压缩成32位。

代码语言：javascript复制
-XX: UseCompressedClassPointers
-XX:CompressedClassSpaceSize=1G

使用CMS时，打开对年老代的压缩。可能会影响性能，但是可以消除碎片。 -XX: UseCMSCompactAtFullCollection

使用CMS，设置多少次FullGc后，对年老代进行压缩。 由于CMS不对内存空间进行压缩、整理、所以运行一段时间以后会产生“碎片”，使得运行效率降低。此值设置运行多少次GC以后对内存空间进行压缩、整理。

-XX:CMSFullGCsBeforeCompaction=0

这两个设置一般配合使用,一般用于『降低CMS GC频率或者增加频率、减少GC时长』的需求

-XX:CMSInitiatingOccupancyFraction=70 是指设定CMS在对内存占用率达到70%的时候开始GC(因为CMS会有浮动垃圾,所以一般都较早启动GC);

-XX: UseCMSInitiatingOccupancyOnly 只是用设定的回收阈值(上面指定的70%),如果不指定,JVM仅在第一次使用设定值,后续则自动调整。

CMS整个过程分为4步：

  • 初始标记(CMS initial mark)
  • 并发标记(CMS concurrent mark)
  • 重新标记(CMS remark)
  • 并发清除(CMS concurrent sweep)。在这个阶段会出现浮动垃圾。CMS收集器无法处理浮动垃圾,可能出现Concurrent Mode Failure失败而导致另一次Full GC的产生。由于在垃圾收集阶段用户线程还需要运行，即还需要预留足够的内存空间给用户线程使用，因此CMS收集器不能像其他收集器那样等到老年代几乎完全被填满了再进行收集，需要预留一部分空间提供并发收集时的程序运作使用。

在CMS GC前启动一次ygc，目的在于减少old gen对ygc gen的引用，降低remark时的开销, 一般CMS的GC耗时80%都在remark阶段。 -XX: CMSScavengeBeforeRemark

在进行GC的前后打印出堆的信息 -XX: PrintHeapAtGC

输出GC的详细日志 -XX: PrintGCDetails

输出GC的时间戳（以基准时间的形式） -XX: PrintGCDateStamps

打印GC时各种引用的处理时间。 -XX: PrintReferenceGC

输出GC日志 -XX: PrintGC

打开了就知道是多大的新生代对象晋升到老生代失败从而引发Full GC时的。 -XX: PrintPromotionFailure

输出显示在survivor空间里面有效的对象的岁数情况。 -XX: PrintTenuringDistribution

打印产生GC的原因，比如AllocationFailure什么的，在JDK8已默认打开，JDK7要显式打开一下。 -XX: PrintGCCause

GC日志存放的位置。

代码语言：javascript复制
-Xloggc:logs/quMall_gc.log"

如果达到初始化值就会触发垃圾收集进行类型卸载，同时GC会对该值进行调整：如果释放了大量的空间，就适当降低该值；如果释放了很少的空间，那么在不超过MaxMetaspaceSize时，适当提高该值。默认值是20.8MB。如果不手动指定元空间的大小，会因为元空间的扩容机制，造成频繁的Full GC。

代码语言：javascript复制
-XX:MetaspaceSize=256m 
-XX:MaxMetaspaceSize=256m

默认(MinHeapFreeRatio参数可以调整)空余堆内存小于40%时，JVM就会增大堆直到-Xmx的最大限制。 默认(MaxHeapFreeRatio参数可以调整)空余堆内存大于70%时，JVM会减少堆直到 -Xms的最小限制。 注意:java应用的jvm参数Xms与Xmx保持一致，避免因所使用的Java堆内存不够导致频繁full gc以及full gc中因动态调节Java堆大小而耗费延长其周期。

代码语言：javascript复制
-XX:MinHeapFreeRatio=40
-XX:MaxHeapFreeRatio=70
-Xms3072m 
-Xmx3072m

如果没有配置-XX: DisableExplicitGC，即没有屏蔽System.gc()触发FullGC，那么可以通过排查GC日志中有System字样判断是否System.gc()触发。 注意：如果应用中有用到Netty并且配置了该参数会内存溢出。 Netty中的DirectByteBuffer分配空间过程中发现直接内存不足时会显式调用System.gc()，以期通过Full GC来强迫已经无用的DirectByteBuffer对象释放掉它们关联的native memory。

代码语言：javascript复制
-XX: DisableExplicitGC
GC日志分析

之前看到电商模块中的一台服务器实例频繁Full GC和YGC，感觉很不正常，以下是排查定位问题的步骤。

1.先定位整个堆中哪些对象的实例数和占用空间比较多。话外音：如果垃圾回收器使用的是CMS和ParallelGC，可以使用vjmap快速定位年老代和Survivor区的对象统计信息，减少卡顿时间。 使用jmap -histo:live <pid>命令，可以看到跟JDBC相关类的实例数和占用空间比较多。为了进一步验证猜想,可以dump文件导入到mat工具进行分析(上面已经验证了JDBC存在内存泄漏)。

2.使用jstat -gc 16969<pid> 5000<interval>命令查看gc情况，发现S0和S1区只有7-8MB。接着使用jstat -gcutil 6011<pid>查看堆中各区域使用情况，发现S0区占比很高。

因为使用的是Parallel Scavenge、Parallel Old垃圾回收器，会启动AdaptiveSizePolicy策略。当这个参数打开之后，就不需要手工指定新生代的大小（-Xmn）、Eden与Survivor区的比例（-XX:SurvivorRatio）、晋升老年代对象大小门槛（-XX:PretenureSizeThreshold）等细节参数了，虚拟机会根据当前系统的运行情况收集性能监控信息，动态调整这些参数以提供最合适的停顿时间或最大的吞吐量，这种调节方式称为GC自适应的调节策略（GC Ergonomics）。

所以我们要禁用这个参数且将Eden:S0:S1设置为8:1:1

代码语言：javascript复制
-XX:SurvivorRatio=8
-XX:-UseAdaptiveSizePolicy

设置完这个参数后，再查看GC使用情况后，发现S0和S1区容量变大，S0区占用比也急剧减少，从而YGC减少。

3.查看GC日志，发现造成频繁Full GC的原因是Metadata GC Threshold。这由于没有设置Metaspace参数，导致初始化大小为20.8MB的元空间不够用，频繁扩容导致的Full GC。

代码语言：javascript复制
-XX:MetaspaceSize=256m 
-XX:MaxMetaspaceSize=256m
  1. 如果使用jmap -histo:live <pid>和jmap -dump:format=b,file=quMall.dump 16969<pid>会造成Full GC。

jmap命令导致的Full GC.jpg

5.可以看到Full GC时清除7100个PhantomReference引用耗时长达0.6s。根据上面的分析，我们应该定时清除PhantomReference引用。同时设置并行处理引用。优化后的Full GC清除PhantomReference引用耗时0.0000805s。

代码语言：javascript复制
-XX: ParallelRefProcEnabled

6.另外需要注意的是-Xms和 -Xmx应该设置成一样大，避免在每次GC 后调整堆的大小，从而造成频繁Full GC。

之前没有优化时，近2天GC的情况。

优化前.jpg优化前.jpg

优化后，近2天GC的情况。

优化后.jpg优化后.jpg
后续观察JVM状况
优化后.png优化后.png
优化前.png优化前.png
参考文章
  • 小白系列:
    • java高分局之jstat命令使用
    • jstack(查看线程)、jmap(查看内存)和jstat(性能分析)
    • 通过jstack与jmap分析一次线上故障
    • Java常用分析工具之jmap
    • 使用Memory Analyzer tool(MAT)分析内存泄漏
    • 利用内存分析工具（Memory Analyzer Tool，MAT）分析java项目内存泄露
    • allow heap & Retained heap
    • 解决com.mysql.jdbc.NonRegisteringDriver的内存泄漏
    • Java程序内存分析：使用mat工具分析内存占用
    • 内存泄露排查原因及解决方法——内存优化（五）
    • GC root & 使用MAT分析java堆
    • 使用MAT解决OOM的一次实战经历
    • 使用Eclipse Memory Analyzer Tool（MAT）分析线上故障(一) - 视图&功能篇
    • c3p0的重连机制
    • 唯品会vjmap使用
    • -XX: PrintGCTimeStamps -XX: PrintGCDetails 日志分析
    • JVM之几种垃圾收集器简单介绍
    • Java 中的 Reference介绍
    • 初步诊断你的GC
  • 大佬系列:
    • JVM理解Java虚拟机-第3章垃圾收集器与内存分配策略
    • 唯品会-记一次JVM老生代增长过快问题排查
    • 美团-一次 Young GC 的优化实践
    • 美团-PhantomReference导致CMS GC耗时严重
    • 美团-服务刚启动就 Old GC，要闹哪样？
尾言

感谢各位大佬观看。 如果您对这篇文章有什么意见或者错误需要改进的地方,欢迎与我讨论。

企业 jvm gcc jdbc 海外加速

0 人点赞