JVM问题排查总结

777 阅读31分钟

先说心得: 今天在排查问题的时候发现,JDK1.8之后,jvm默认已经移除了永久带,将永久带内存迁移到了本地内存(MetaSpace)。之前配置的MaxPermSize在jdk1.8中失效了。 默认MetaSpace大小是64M默认70%会进行MetaSpace扩容随着metaspace的频繁扩容,可能会引发full gc或者服务假死。 如果存在metaspace利用率很高的情况,可以考虑优化一下jvm内存配置。 ​

想要系统性地掌握 GC 问题处理,这里给出一个学习路径,整体文章的框架也是按照这个结构展开,主要分四大步。

  • 建立知识体系: 从 JVM 的内存结构到垃圾收集的算法和收集器,学习 GC 的基础知识,掌握一些常用的 GC 问题分析工具。
  • 确定评价指标: 了解基本 GC 的评价方法,摸清如何设定独立系统的指标,以及在业务场景中判断 GC 是否存在问题的手段。
  • 场景调优实践: 运用掌握的知识和系统评价指标,分析与解决九种 CMS 中常见 GC 问题场景。
  • 总结优化经验: 对整体过程做总结并提出建议,同时将总结到的经验完善到知识体系之中。

1.GC基础

1.1 部分名词解释

  • TLAB: Thread Local Allocation Buffer 的简写,基于 CAS 的独享线程(Mutator Threads)可以优先将对象分配在 Eden 中的一块内存,因为是 Java 线程独享的内存区没有锁竞争,所以分配速度更快,每个 TLAB 都是一个线程独享的。
  • Mutator: 生产垃圾的角色,也就是我们的应用程序,垃圾制造者,通过 Allocator 进行 allocate 和 free。

1.2 内存划分

目前 Java 版本最新已经到了 Java 16,未来的 Java 17 以及现在的 Java 11 和 Java 8 是 LTS 版本,JVM 规范也在随着迭代在变更,由于本文主要讨论 CMS,此处还是放 Java 8 的内存结构。 image.png GC主要工作在Heap区和MetaSpace区(蓝色部分),在直接内存(metaspace就在这里面)中,如果使用的是DirectByteBuffer,那么在分配内存不够时,GC通过Cleaner间接管理。 任何自动内存管理系统都会面临的步骤:为新对象分配空间,然后收集垃圾对象空间,下面我们就展开介绍一下这些基础知识。

1.3 分配对象

Java中对象地址操作主要使用Unsafe调用了C的allocate和free两个方法,分配方法有两种:

  • 空闲链表(free list):通过额外的存储记录空闲的地址,将随机IO变为顺序IO,但带来了额外的空间消耗
  • 碰撞指针(bump pointer):通过一个指针作为分界点,需要分配内存时,仅需要把指针往空闲的一端移动与对象大小相等的距离,分配效率较高,但使用场景有限。

1.4 收集对象

1.4.1 识别垃圾

  • 引用计数法(Reference Counting):对每个对象的引用进行计数,每当有一个地方引用它时计数器 +1、引用失效则 -1,引用的计数放到对象头中,大于 0 的对象被认为是存活对象。虽然循环引用的问题可通过 Recycler 算法解决,但是在多线程环境下,引用计数变更也要进行昂贵的同步操作,性能较低,早期的编程语言会采用此算法。
  • 可达性分析(引用链 Tracing GC):从 GC Root 开始进行对象搜索,可以被搜索到的对象即为可达对象,此时还不足以判断对象是否存活/死亡,需要经过多次标记才能更加准确地确定,整个连通图之外的对象便可以作为垃圾被回收掉。目前 Java 中主流的虚拟机均采用此算法。

Tips:在现在的JVM中,可以作为GC Root的对象包括以下几种:

  1. 虚拟机栈(栈祯中的本地变量表)中引用的对象,比如各个线程被调用的方法堆栈中使用到的参数,局部变量,临时变量等
  2. 在方法区中类静态属性引用的对象,例如 Java类的引用类型静态变量
  3. 在方法区中常量引用的对象,例如字符串常量池中的引用
  4. 本地方法栈中JNI引用的对象
  5. Java虚拟机内部的引用,例如基本数据类型对应的class对象,一些常驻的异常对象等,还有系统类加载器
  6. 同步锁持有的对象
  7. 反映Java虚拟机内部情况的JMXBean,JVMTI中注册的回调,本地代码缓存等。

1.4.2 收集算法

  • Mark-Sweep(标记清除):回收过程主要分为两个阶段,第一阶段为追踪(Tracing)阶段,即从 GC Root 开始遍历对象图,并标记(Mark)所遇到的每个对象,第二阶段为清除(Sweep)阶段,即回收器检查堆中每一个对象,并将所有未被标记的对象进行回收,整个过程不会发生对象移动。整个算法在不同的实现中会使用三色抽象(Tricolour Abstraction)、位图标记(BitMap)等技术来提高算法的效率,存活对象较多时较高效。
  • Mark-Compact(标记整理):这个算法的主要目的就是解决在非移动式回收器中都会存在的碎片化问题,也分为两个阶段,第一阶段与 Mark-Sweep 类似,第二阶段则会对存活对象按照整理顺序(Compaction Order)进行整理。主要实现有双指针(Two-Finger)回收算法、滑动回收(Lisp2)算法和引线整理(Threaded Compaction)算法等。
  • Copying(复制):将空间分为两个大小相同的 From 和 To 两个半区,同一时间只会使用其中一个,每次进行回收时将一个半区的存活对象通过复制的方式转移到另一个半区。有递归(Robert R. Fenichel 和 Jerome C. Yochelson提出)和迭代(Cheney 提出)算法,以及解决了前两者递归栈、缓存行等问题的近似优先搜索算法。复制算法可以通过碰撞指针的方式进行快速地分配内存,但是也存在着空间利用率不高的缺点,另外就是存活对象比较大时复制的成本比较高。

三种算法在是否移动对象、空间和时间方面的一些对比,假设存活对象数量为 L、堆空间大小为** H**,则 image.png

1.5 收集器

目前在 Hotspot VM 中主要有分代收集和分区收集两大类,具体可以看下面的这个图,不过未来会逐渐向分区收集发展。在美团内部,有部分业务尝试用了 ZGC(感兴趣的同学可以学习下这篇文章 新一代垃圾回收器ZGC的探索与实践),其余基本都停留在 CMS 和 G1 上。另外在 JDK11 后提供了一个不执行任何垃圾回收动作的回收器 Epsilon(A No-Op Garbage Collector)用作性能分析。另外一个就是 Azul 的 Zing JVM,其 C4(Concurrent Continuously Compacting Collector)收集器也在业内有一定的影响力。 image.png

1.5.1 分代收集器

  • ParNew: 一款多线程的收集器,采用复制算法,主要工作在 Young 区,可以通过 -XX:ParallelGCThreads 参数来控制收集的线程数,整个过程都是 STW 的,常与 CMS 组合使用。
  • CMS: 以获取最短回收停顿时间为目标,采用“标记-清除”算法,分 4 大步(初始标记,并发标记,重新标记,并发清除)进行垃圾收集,其中初始标记和重新标记会 STW ,多数应用于互联网站或者 **B/S **系统的服务器端上,JDK9 被标记弃用,JDK14 被删除。

1.5.2 分区收集器

  • G1: 一种服务器端的垃圾收集器(主流),应用在多处理器和大容量内存环境中,在实现高吞吐量的同时,尽可能地满足垃圾收集暂停时间的要求。
  • ZGC: JDK11 中推出的一款低延迟垃圾回收器,适用于大内存低延迟服务的内存管理和回收,SPECjbb 2015 基准测试,在 128G 的大堆下,最大停顿时间才 1.68 ms,停顿时间远胜于 G1 和 CMS。

1.5.3 常用收集器

目前使用最多的是 CMS 和 G1 收集器,二者都有分代的概念,主要内存结构如下: image.png

1.6 常用工具

1.6.1 命令行终端

  • 标准终端类:jps、jinfo、jstat、jstack、jmap
  • 功能整合类:jcmd、vjtools、arthas、greys

1.6.2 可视化界面

  • 简易:JConsole、JVisualvm、HA、GCHisto、GCViewer
  • 进阶:MAT、JProfiler

2.GC问题判断

2.1 判断GC有没有问题?

2.1.1 评价标准

评判 GC 的两个核心指标:

  • 延迟(Latency): 也可以理解为最大停顿时间,即垃圾收集过程中一次 STW 的最长时间,越短越好,一定程度上可以接受频次的增大,GC 技术的主要发展方向。
  • 吞吐量(Throughput): 应用系统的生命周期内,由于 GC 线程会占用 Mutator 当前可用的 CPU 时钟周期,吞吐量即为 Mutator 有效花费的时间占系统总运行时间的百分比,例如系统运行了 100 min,GC 耗时 1 min,则系统吞吐量为 99%,吞吐量优先的收集器可以接受较长的停顿。

目前各大互联网公司的系统基本都更追求低延时,避免一次 GC 停顿的时间过长对用户体验造成损失,衡量指标需要结合一下应用服务的 SLA,主要如下两点来判断: image.png 简而言之,即为一次停顿的时间不超过应用服务的 TP9999,GC 的吞吐量不小于 99.99%。举个例子,假设某个服务 A 的 TP9999 为 80 ms,平均 GC 停顿为 30 ms,那么该服务的最大停顿时间最好不要超过 80 ms,GC 频次控制在 5 min 以上一次。如果满足不了,那就需要调优或者通过更多资源来进行并联冗余。(大家可以先停下来,看看监控平台上面的 gc.meantime 分钟级别指标,如果超过了 6 ms 那单机 GC 吞吐量就达不到 4 个 9 了。)

2.1.2 GC 日志学习

拿到 GC 日志,我们就可以简单分析 GC 情况了,通过一些工具,我们可以比较直观地看到 Cause 的分布情况,如下图就是使用 gceasy 绘制的图表: image.png 重点需要关注的几个GC Cause:

  • System.gc(): 手动触发GC操作。
  • CMS: CMS GC 在执行过程中的一些动作,重点关注 CMS Initial Mark 和 CMS Final Remark 两个 STW 阶段。
  • Promotion Failure: Old 区没有足够的空间分配给 Young 区晋升的对象(即使总可用内存足够大)。
  • Concurrent Mode Failure: CMS GC 运行期间,Old 区预留的空间不足以分配给新的对象,此时收集器会发生退化,严重影响 GC 性能,下面的一个案例即为这种场景。
  • GCLocker Initiated GC: 如果线程执行在 JNI 临界区时,刚好需要进行 GC,此时 GC Locker 将会阻止 GC 的发生,同时阻止其他线程进入 JNI 临界区,直到最后一个线程退出临界区时触发一次 GC。

以CMS为例,我进行了一下日志分析,具体内容如下: 首先确定CMS GC的6个过程:

1.初始标记:为了收集应用程序的对象引用需要暂停应用程序线程,该阶段完成后,应用程序线程再次启动。
2.并发标记:从第一阶段收集到的对象引用开始,遍历所有其他的对象引用。
3.并发预清理:改变当运行第二阶段时,由应用程序线程产生的对象引用,以更新第二阶段的结果。
4.重新标记:由于第三阶段是并发的,对象引用可能会发生进一步改变。因此,应用程序线程会再一次
被暂停以更新这些变化,并且在进行实际的清理之前确保一个正确的对象引用视图。
这一阶段十分重要,因为必须避免收集到仍被引用的对象。
5.并发清理:所有不再被应用的对象将从堆里清除掉。
6.并发重置:收集器做一些收尾的工作,以便下一次GC周期能有一个干净的状态。

其中4个阶段(名字以Concurrent开始的)与实际的应用程序是并发执行的,
而其他2个阶段需要暂停应用程序线程(STW).初始标记和重新标记

用下面代码和对应的GC参数对日志进行分析

public class GCTest {

    private static final int _10MB = 10 * 1024 * 1024;

    /**
     * @param args
     * @throws InterruptedException
     */
    public static void main(String[] args) throws Exception {
        test();

    }

    /**
     * VM arg: -Xms100m(设置最大堆内存) -Xmx100m(设置初始堆内存) 
     * -Xmn50m(设置新生代大小)
     * -XX:+PrintGCDetails(打印GC日志详细信息) 
     * -XX:+UseConcMarkSweepGC (采用 cms gc算法)
     * -XX:+UseParNewGC (新生代采用并行GC方式,
     * 高版本的jdk使用了UseConcMarkSweepGC参数时 这个参数会自动开启)
     * -XX:SurvivorRatio=8 (新生代eden区与survivor区空间比例8:1,
     * eden:fromsurvivor:tosurvivor -->8:1:1)
     * -XX:MaxTenuringThreshold=1 (用于控制对象能经历多少次
     * Minor GC(young gc)才晋升到老年代,默认15次)
     * -XX:+PrintTenuringDistribution(输出survivor区幸存对象的年龄分布)
     * -XX:CMSInitiatingOccupancyFraction=68 *(设置老年代空间使用率多少时触发第一次cms *gc,默认68%)
     * @throws InterruptedException
     */
    public static void test() throws InterruptedException {
        List<byte[]> list = new ArrayList<>();
        for (int n = 1; n < 8; n++) {
            byte[] alloc = new byte[_10MB];
            list.add(alloc);
        }
        Thread.sleep(Integer.MAX_VALUE);

    }

}

获取日志并分析

D:\platform\git\demo>java -Xms100m -Xmx100m -Xmn50m -XX:+PrintGCDetails 
-XX:+UseConcMarkSweepGC -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=1 
-XX:+PrintTenuringDistribution GCTest
[GC (Allocation Failure) 
[ParNew Desired survivor size 2621440 bytes, new threshold 1 (max 1)
- age   1:     636784 bytes,     636784 total: 33997K->632K(46080K), 0.0105313 secs] 
33997K->31354K(97280K), 0.0107013 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
//step 1,young gc,新生代没有空间存入新对象,则发生young gc(也叫 minor gc),
//33997K->632K(46080K), 0.0105313 secs]新生代由33997K gc后变成了632K,
//整个heap区情况: 33997K->31354K(97280K)
//新生代的对象copy(新生代采用的是复制算法收集内存)到survivor区,
//但此处survivor容纳不下,则直接copy到了老年代中大小(可以设置多大的对象直接升级到老年代中,这里涉及到内存担保策略)
//参数XX:PretenureSizeThreshold=<value>)
[GC (Allocation Failure) [ParNew: 32961K->32961K(46080K), 0.0001067 secs]
[CMS: 30722K->40960K(51200K), 0.0111639 secs] 63683K->62060K(97280K), 
[Metaspace: 2509K->2509K(1056768K)], 0.0118014 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
//step 2,老年代空间占用大小占比达到阈值,触发第一次老年代GC,即CMS GC
//CMS: 30722K->40960K(51200K): 老年代由30722K变为40960K,总大小51200K
[GC (CMS Initial Mark) [1 CMS-initial-mark: 40960K(51200K)] 72995K(97280K), 0.0004270 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 3 初始标记
[CMS-concurrent-mark-start]
[CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 4 并发标记
[CMS-concurrent-preclean-start]
[CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 5 并发预清理
[CMS-concurrent-abortable-preclean-start]
[CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[GC (CMS Final Remark) [YG occupancy: 32035 K (46080 K)][Rescan (parallel) , 0.0003930 secs]
//step 6重标记 
[weak refs processing, 0.0000436 secs][class unloading, 0.0001861 secs]
[scrub symbol table, 0.0003188 secs]
[scrub string table, 0.0000946 secs]
//weak refs processing 处理old区的弱引用,用于回收native memory
class unloading 回收SystemDictionary
[1 CMS-remark:40960K(51200K)] 72995K(97280K), 0.0013492 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[CMS-concurrent-sweep-start]
[CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 7 并发清理
[CMS-concurrent-reset-start]
[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 8 并发重置
Heap
 par new generation   total 46080K, used 32445K [0x00000000f9c00000, 0x00000000fce00000, 0x00000000fce00000)
  eden space 40960K,  79% used [0x00000000f9c00000, 0x00000000fbbaf5b0, 0x00000000fc400000)
  from space 5120K,   0% used [0x00000000fc900000, 0x00000000fc900000, 0x00000000fce00000)
  to   space 5120K,   0% used [0x00000000fc400000, 0x00000000fc400000, 0x00000000fc900000)
 concurrent mark-sweep generation total 51200K, used 40960K [0x00000000fce00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 2515K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 269K, capacity 386K, committed 512K, reserved 1048576K

基本上都是这种格式:回收前区域占用的大小->回收后区域占用的大小(区域设置的大小),耗时. 取其中最典型的部分进行分析

# 新生代分配失败了
[GC (Allocation Failure) [ParNew: 32961K->32961K(46080K), 0.0001067 secs]
# CMS:表明是老年代堆区(因为CMS只作用于老年代),
[CMS: 30722K->40960K(51200K), 0.0111639 secs] 63683K->62060K(97280K), 
[Metaspace: 2509K->2509K(1056768K)], 0.0118014 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

ParNew 表明新生代是并行方式进行GC

串行收集器:
DefNew:是使用-XX:+UseSerialGC(新生代,老年代都使用串行回收收集器)。
并行收集器:
ParNew:是使用-XX:+UseParNewGC(新生代使用并行收集器,老年代使用串行回收收集器)或者-XX:+UseConcMarkSweepGC(新生代使用并行收集器,老年代使用CMS)。
PSYoungGen:是使用-XX:+UseParallelOldGC(新生代,老年代都使用并行回收收集器)或者-XX:+UseParallelGC(新生代使用并行回收收集器,老年代使用串行收集器)
garbage-first heap:是使用-XX:+UseG1GC(G1收集器)

heap 区情况

[Metaspace: 2509K->2509K(1056768K)], 0.0118014 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

实际上在执行过程中,还存在一些特殊情况,例如concurrent mode failure情况,当我new 出的对象超过了堆内存的最大内存后会发生OOM时,就出现concurrent mode failure,GC日志如下:

[GC [ParNew: 31539K->496K(46080K), 0.0137601 secs] 31539K->31218K(97280K), 0.0152885 secs] 
[Times: user=0.02 sys=0.00, real=0.02 secs]
[GC [ParNew: 33275K->33275K(46080K), 0.0003866 secs][CMS: 30722K->40960K(51200K), 0.0217084 secs]
63997K->61912K(97280K), [CMS Perm : 2534K->2532K(21248K)], 0.0231226 secs] 
[Times: user=0.02 sys=0.00, real=0.02 secs]
[GC [1 CMS-initial-mark: 40960K(51200K)] 72152K(97280K), 0.0004554 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC [CMS[CMS-concurrent-mark: 0.010/0.011 secs] 
[Times: user=0.00 sys=0.00, real=0.01 secs]
 (concurrent mode failure): 40960K->40960K(51200K), 0.0159043 secs] 72152K->72152K(97280K), [CMS Perm : 2532K->2532K(21248K)], 0.0165056 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC [CMS: 40960K->40960K(51200K), 0.0075621 secs] 
72152K->72138K(97280K), [CMS Perm : 2532K->2532K(21248K)], 0.0084089 secs]
[Times: user=0.00 sys=0.00, real=0.01 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at GCTest.test(GCTest.java:19)
        at GCTest.main(GCTest.java:12)

造成这种情况的原因是:在执行CMS GC的过程中同时有对象要放入旧生代,而此时老年代空间不足造成的(内存担保失效)。 同样的情况还有promotion failed这种情形,这是由于在进行Minor GC(young gc)时,survivor space放不下、对象只能放入老年代,而此时老年代也放不下造成的。

2.2 我的GC问题排查过程?

2.2.1 GC堆栈信息

首先通过jstat(查看虚拟机运行时信息)命令看一看对应Java进程的堆栈信息

jstat -gcutil 26819
S0    S1      E     O      M      CCS   YGC YGCT   FGC  FGCT       GCT
0.00 43.75 0.00 42.22 67.19 50.93 4955 30.970 4890 3505.049 3536.020

可以看到M(metaSpace使用率)的值是67.19,metaSpace使用率为67.19;O为42.22,old区使用率为42.22

top -H -p 26819
26821 appdev 20 0 6864m 1.2g 13m R 87.6 7.5 53:40.18 java
26822 appdev 20 0 6864m 1.2g 13m R 87.6 7.5 53:41.40 java
26823 appdev 20 0 6864m 1.2g 13m R 87.6 7.5 53:43.64 java
26824 appdev 20 0 6864m 1.2g 13m R 85.6 7.5 53:41.59 java
26825 appdev 20 0 6864m 1.2g 13m R 85.6 7.5 53:43.82 java
26826 appdev 20 0 6864m 1.2g 13m R 85.6 7.5 53:40.47 java
26827 appdev 20 0 6864m 1.2g 13m R 85.6 7.5 53:45.05 java
26828 appdev 20 0 6864m 1.2g 13m R 83.6 7.5 53:39.08 java

可以发现26821到26828的cpu使用率很高,26821转为16进制为68c5 jstack(查看线程堆栈信息)

jstack 26819 > 26819.text
vim 26819.text 然后搜索68c5-68cc
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f0aa401e000 nid=0x68c5 runnable
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f0aa4020000 nid=0x68c6 runnable
"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f0aa4021800 nid=0x68c7 runnable
"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f0aa4023800 nid=0x68c8 runnable
"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007f0aa4025800 nid=0x68c9 runnable
"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007f0aa4027000 nid=0x68ca runnable
"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007f0aa4029000 nid=0x68cb runnable
"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007f0aa402a800 nid=0x68cc runnable

可以发现一致是full gc的线程在执行,占用cpu较高的资源,并且一致持续,表明一直达到了full gc的条件但是又不能回收掉内存从而占用大量cpu,导致程序不可用。 查看启动配置参数如下:

-Xms1000m -Xmx1000m -XX:MaxNewSize=256m -XX:ThreadStackSize=256 -XX:MetaspaceSize=38m -XX:MaxMetaspaceSize=380m

分析程序的逻辑,该程序是一个公共服务,程序会加载很多jar到内存。很多同事会上传jar,然后程序把jar加载到classloader(在堆空间里,full gc时会清理)进行分析并保存。

2.2.2 问题分析

根据jdk8的metaspace的fullgc的触发条件,初始metaspacesize是38m意味着当第一次加载的class达到38m的时候进行第一次gc(根据JDK 8的特性,G1和CMS都会很好地收集Metaspace区(一般都伴随着Full GC)),然后jvm会动态调整 (gc后会进行调整)metaspacesize的大小。

元空间的本质和永久代类似,都是对JVM规范中方法区的实现。不过元空间与永久代之间最大的区别在于:元空间并不在虚拟机中,而是使用本地内存。因此,默认情况下,元空间的大小仅受本地内存限制,但可以通过以下参数来指定元空间的大小:

In JDK 8, classes metadata is now stored in the native heap
and this space is called Metaspace. There are some new flags added for
Metaspace in JDK 8:
-XX:MetaspaceSize=<NNN>
where <NNN> is the initial amount of space(the initial
high-water-mark) allocated for class metadata (in bytes) that may induce a
garbage collection to unload classes. The amount is approximate. After the
high-water-mark is first reached, the next high-water-mark is managed by
the garbage collector
-XX:MaxMetaspaceSize=<NNN>
where <NNN> is the maximum amount of space to be allocated for class
metadata (in bytes). This flag can be used to limit the amount of space
allocated for class metadata. This value is approximate. By default there
is no limit set.
-XX:MinMetaspaceFreeRatio=<NNN>
where <NNN> is the minimum percentage of class metadata capacity
free after a GC to avoid an increase in the amount of space
(high-water-mark) allocated for class metadata that will induce a garbage
collection.
-XX:MaxMetaspaceFreeRatio=<NNN>
where <NNN> is the maximum percentage of class metadata capacity
free after a GC to avoid a reduction in the amount of space
(high-water-mark) allocated for class metadata that will induce a garbage
collection.

翻译

-XX:MetaspaceSize,初始空间大小,达到该值就会触发垃圾收集进行类型卸载,同时GC会对该值进行调整:如果释放了大量的空间,就适当降低该值;如果释放了很少的空间,那么在不超过MaxMetaspaceSize时,适当提高该值。
-XX:MaxMetaspaceSize,最大空间,默认是没有限制的。
除了上面两个指定大小的选项以外,还有两个与 GC 相关的属性:
-XX:MinMetaspaceFreeRatio,在GC之后,最小的Metaspace剩余空间容量的百分比,减少为分配空间所导致的垃圾收集
-XX:MaxMetaspaceFreeRatio,在GC之后,最大的Metaspace剩余空间容量的百分比,减少为释放空间所导致的垃圾收集
By default class
metadata allocation is only limited by the amount of available native memory. We
can use the new option MaxMetaspaceSize to limit the amount of native memory
used for the class metadata. It is analogous(类似) to MaxPermSize. A garbage collection is induced to collect the dead classloaders
and classes when the class metadata usage reaches MetaspaceSize (12Mbytes on
the 32bit client VM and 16Mbytes on the 32bit server VM with larger sizes on
the 64bit VMs). Set MetaspaceSize to a higher value to delay the induced
garbage collections. After an induced garbage collection, the class metadata usage
needed to induce the next garbage collection may be increased.

根据这段描述可以知道:

1.当metadata usage reaches MetaspaceSize(默认MetaspaceSize在64为server上是20.8m)就会触发gc;

2.XX:MinMetaspaceFreeRatio是用来避免下次申请的空闲metadata大于暂时拥有的空闲metadata而触发gc,举个例子就是,当metaspacesize的使用大小达到了第一次设置的初始值6m,这时进行进行扩容(之前已经做过MinMetaspaceExpansion和MaxMetaspaceExpansion扩展,但还是失败),然后gc后,由于回收了的内存很小,然后计算((待commit内存【未使用】)/(待commit内存+已经commmited内存) ==40%,(待commit内存+已经commmited内存【扩容后,未commit的变大,已经commit的不变,ratio变大,容易出发GC】)大于了metaspaceSize那么将尝试做扩容,也就是增大触发metaspaceGC的阈值,不过这个增量至少是MinMetaspaceExpansion才会做,不然不会增加这个阈值) ,这个参数主要是为了避免触发metaspaceGC的阈值和gc之后committed的内存的量比较接近,于是将这个阈值(metaspaceSize)进行扩大,尽量减小下次gc的几率。

3.同理-XX:MaxMetaspaceFreeRatio(默认70)是用来避免下次申请的空闲metadata很小,远远小于现在的空闲内存从而导致gc。主要作用是减小不必要的内存占用空间。 ​

JDK8的metaspace 引发的Full GC

jdk8使用metaspace代替之前的perm,metaspace使用native memory,默认情况下使用的最大大小是系统内存大小,当然也可以使用-XX:MaxMetaspaceSize设置最大大小,这个设置和之前的max perm size是一样的。同时当设置-XX:MaxMetaspaceSize这个参数后,我们也可以实现和max perm引起oom的问题。

We can achieve the famed OOM error by setting the MaxMetaspaceSize argument to JVM and running the sample program provided.

metaspaceSize默认初始大小: MetaspaceSize (12Mbytes on the 32bit client VM and 16Mbytes on the 32bit server VM with larger sizes on the 64bit VMs). 可以通过-XX:MetaspaceSize 设置我们需要的初始大小,设置大点可以增加第一次达到full gc的时间。(默认64M)

ps:下面是调整了下参数重启的进程,和上面的进程Id有出入。

jstat -gc 1706

S0CS1CS0US1UECEUOCOUMCMUCCSCCCSUYGCYGCTFGCFGCTGCT
31744.032768.00.021603.6195584.0192805.8761856.0384823.3467712.0309814.365536.036929.11012.88731.2244.112

分析:MC是已经commited的内存,MU是当前使用的内存。这里有个疑惑就是MC是不是就是metaspace已经总共使用的内存,因为这个值已经达到了maxmetaspacesize,同时为什么mu不是和mc一样我猜测是由于碎片内存导致,这里有知道的同学可以告诉我下。

在达到maxmetaspacesize的时候执行了3次fullgc。但是接下来由于不断申请内存,不断fullgc,fullgc不能回收内存,这时候fullgc的频率增大很多。在接下来 top -H -p 1706查看cpu可以看到大量高cpu进程,通过jstack查看都是在进行fullgc。

jmap -clstats 1706

第一次:total = 131 8016 13892091 N/A alive=45, dead=86 N/A

第二次:total = 1345 37619 77242171 N/A alive=1170, dead=175 N/A alive的classloader基本都是自己创建的,classLoader不断增加,每次gc并没有回收掉classloader

VM中的Class只有满足以下三个条件,才能被GC回收,也就是该Class被卸载(unload)

  • 该类所有的实例都已经被GC,也就是JVM中不存在该Class的任何实例。
  • 加载该类的ClassLoader已经被GC。ClassLoader被回收需要所有ClassLoader的所有类的实例都被回收。
  • 该类的java.lang.Class 对象没有在任何地方被引用,如不能在任何地方通过反射访问该类的方法
jcmd 1706 GC.class_stats | awk '{print $13}' | sort | uniq -c | sort -nrk1 > topclass.txt

得到结论,自定义的classloader加载的类重复多次,并且数量一直增加。看到大量的类重复数量。

2.2.3 GC日志分析

gc日志分析:
第一次fullgc:
[Heap Dump (before full gc): , 0.4032181 secs]2018-01-10T16:37:44.658+0800: 21.673: [Full GC (Metadata GC Threshold) [PSYoungGen: 14337K->0K(235520K)] [ParOldGen: 18787K->30930K(761856K)] 33125K->30930K(997376K), [Metaspace: 37827K->37827K(1083392K)], 0.1360661 secs] [Times: user=0.65 sys=0.04, real=0.14 secs]
主要是Metaspace这里:[Metaspace: 37827K->37827K(1083392K)] 达到了我们设定的初始值38m,并且gc并没有回收掉内存。1083392K这个值怀疑是使用了CompressedClassSpaceSize = 1073741824 (1024.0MB)这个导致的。
第四次fullgc:
[Heap Dump (before full gc): , 5.3642805 secs]2018-01-10T16:53:43.811+0800: 980.825: [Full GC (Metadata GC Threshold) [PSYoungGen: 21613K->0K(231424K)] [ParOldGen: 390439K->400478K(761856K)] 412053K->400478K(993280K), [Metaspace: 314108K->313262K(1458176K)], 1.2320834 secs] [Times: user=7.86 sys=0.06, real=1.23 secs]
主要是Metaspace这里:[Metaspace: 314108K->313262K(1458176K)]达到了我们设定的MinMetaspaceFreeRatio,并且gc几乎没有回收掉内存。1458176K这个值是CompressedClassSpaceSize = 1073741824 (1024.0MB)和 MaxMetaspaceSize = 503316480 (480.0MB)的和。

后面就是频率很快的重复fullgc。

有了以上基础,就知道怎么解决这次遇到的问题了。 总结下原因:classloader不断创建,classloader不断加载class,之前的classloader和class在fullgc的时候没有回收掉。

  1. 程序避免创建重复classloader,减少创建classLoader的数量。
  2. 增大XX:MinMetaspaceFreeRatio(默认40)的大小,可以看到现在是(67.19%)。
  3. 设置更大的maxmetaspaceSize。

延伸学习

1,System.gc()方法的调用 system.gc(), 此方法的调用是建议JVM进行Full GC,虽然只是建议而非一定,但很多情况下它会触发 Full GC,从而增加Full GC的频率,也即增加了间歇性停顿的次数。强烈建议能不使用此方法就别使用,让虚拟机自己去管理它的内存,可通过通过-XX:+ DisableExplicitGC来禁止RMI调用System.gc。

2,老年代代空间(old/Tenured)不足 老年代空间只有在新生代对象转入及创建为大对象、大数组时才会出现不足的现象,当执行Full GC后空间仍然不足,则抛出如下错误:java.lang.OutOfMemoryError: Java heap space 为避免以上两种状况引起的Full GC,调优时应尽量做到让对象在Minor GC阶段被回收、让对象在新生代多存活一段时间及不要创建过大的对象及数组。

3,永生区(perm)空间不足(jdk<=7 ,在jdk8里面是metaspace ,后面会重点描述) JVM规范中运行时数据区域中的方法区,在HotSpot虚拟机中又被习惯称为永生代或者永生区,Permanet Generation中存放的为一些class的信息、常量、静态变量等数据,当系统中要加载的类、反射的类和调用的方法较多时,Permanet Generation可能会被占满,在未配置为采用CMS GC的情况下也会执行Full GC。如果经过Full GC仍然回收不了,那么JVM会抛出如下错误信息:java.lang.OutOfMemoryError: PermGen space 为避免Perm Gen占满造成Full GC现象,可采用的方法为增大Perm Gen空间或转为使用CMS GC。

4,CMS GC时出现promotion failed和concurrent mode failure 对于采用CMS进行老年代GC的程序而言,尤其要注意GC日志中是否有promotion failed和concurrent mode failure两种状况,当这两种状况出现时可能会触发Full GC。promotion failed是在进行Minor GC时,survivor space放不下、对象只能放入老年代,而此时老年代也放不下造成的;concurrent mode failure是在执行CMS GC的过程中同时有对象要放入老年代,而此时老年代空间不足造成的(有时候“空间不足”是CMS GC时当前的浮动垃圾过多导致暂时性的空间不足触发Full GC)。对措施为:增大survivor space、老年代空间或调低触发并发GC的比率(-XX:CMSInitiatingOccupancyFraction=70,预留空间为70%),但在JDK 5.0+、6.0+的版本中有可能会由于JDK的bug29导致CMS在remark完毕后很久才触发sweeping动作。对于这种状况,可通过设置-XX: CMSMaxAbortablePrecleanTime=5(单位为ms)来避免。

5、统计得到的Minor GC晋升到旧生代(Eden到S2和S1到S2的和)的平均大小大于老年代的剩余空间 这是一个较为复杂的触发情况,Hotspot为了避免由于新生代对象晋升到旧生代导致旧生代空间不足的现象,在进行Minor GC时,做了一个判断,如果之前统计所得到的Minor GC晋升到旧生代的平均大小大于旧生代的剩余空间,那么就直接触发Full GC。例如程序第一次触发Minor GC后,有6MB的对象晋升到旧生代,那么当下一次Minor GC发生时,首先检查旧生代的剩余空间是否大于6MB,如果小于6MB,则执行Full GC。当新生代采用PS GC时,方式稍有不同,PS GC是在Minor GC后也会检查,例如上面的例子中第一次Minor GC后,PS GC会检查此时旧生代的剩余空间是否大于6MB,如小于,则触发对旧生代的回收。 除了以上4种状况外,对于使用RMI来进行RPC或管理的Sun JDK应用而言,默认情况下会一小时执行一次Full GC。可通过在启动时通过- java -Dsun.rmi.dgc.client.gcInterval=3600000来设置Full GC执行的间隔时间或通过-XX:+ DisableExplicitGC来禁止RMI调用System.gc。

6、堆中分配很大的对象 所谓大对象,是指需要大量连续内存空间的java对象,例如很长的数组,此种对象会直接进入老年代,而老年代虽然有很大的剩余空间,但是无法找到足够大的连续空间来分配给当前对象,此种情况就会触发JVM进行Full GC。 为了解决这个问题,CMS垃圾收集器提供了一个可配置的参数,即-XX:+UseCMSCompactAtFullCollection开关参数,用于在“享受”完Full GC服务之后额外免费赠送一个碎片整理的过程,空间碎片问题没有了,但提顿时间不得不变长了,JVM设计者们还提供了另外一个参数 -XX:CMSFullGCsBeforeCompaction,这个参数用于设置在执行多少次不压缩的Full GC后,跟着来一次带压缩的。