G1垃圾回收器学习笔记

一、面向多CPU的最新垃圾回收器- G1

1.1、什么是G1垃圾回收器?

G1也叫垃圾优先回收器(Garbage-First,G1)。其主要含义是不会像传统垃圾回收器一样等到空间满了才回收,而是在空间还没满时就进行了回收。

1.2、G1垃圾回收器的优势

  • 每次垃圾回收时间短,吞吐量高
  • 可以在用户指定的时间内完成垃圾回收

1.3、G1垃圾回收器的应用场景

  • 电商秒杀服务器
  • 多路直播服务器

1.4、垃圾回收器的发展史

image.png

1.5、G1最大的特征

将大空间分成若干小区域能实现一些更复杂、更精细的功能。

1.5.1、G1与传统垃圾回收器模型对比

image.png

1.5.2、G1划分成小区域的好处
  1. 垃圾回收线程和工作线程能够并行工作,避免“STW”
  2. 不同区域可同时回收,并发性更高,更适合多核服务器
  3. 可以先回收一部分区域,回收更快
  4. 可以建立停顿预测模型,用户可以设定垃圾回收最长时间
1.5.3、G1的发展史
  • 2004年10月论文发表 《Garbage-First Garbage Collection》
  • 2012年在JDK7首次引入支持
  • JDK8中基本成熟
  • JDK9成为默认垃圾回收器
  • 2020年JDK14删除CMS,G1正式登基
1.5.4、G1是未来的主流垃圾回收器
  • CMS逐步下线,ZGC尚未成熟,G1将是主流,不得不学
  • G1性能比传统垃圾回收器更高,是优化系统性能的重要途径

二、深入浅出G1三种垃圾回收策略的原理与实战

2.1、图解G1对象管理过程

2.1.1、对象的回收过程

image.png

image.png

image.png

2.1.2、大对象的回收过程

image.png

2.1.3、总结思考
  1. 每个区域该多大?总数为多少比较好?
  2. 新生/老年代区域比例该如何才能最优?
  3. 大对象该如何管理?
  4. 除了YGC,还有几种类型,如何工作?

2.2、Region划分原理与实战

  • Region区域总个数和大小都是可变的
    • 数量方面,region默认总个数为2048个
    • 大小方面,默认是1MB,可以通过参数将其修改为2,4,8,16和32MB这几种

image.png

2.2.1、案例1:G1是如何管理分区的

我们这里使用jdk17环境来演示下。

2.2.1.1、测试分区大小

先看大小问题,分区默认大小是多少呢?默认 是1MB,接下来,我们通过实验来验证。
我们先写一段代码:

public class RegionExample1 {
    public static void main(String[] args) {
        byte[] data = new byte[1024];
        for (int i = 0; i < 100; i++) {
            //不断申请256KB内存,导致内存泄漏
            data = new byte[1024 * 256];
            System.out.println("申请内存:" + (i+1) + "M");
        }
    }
}

我们这段代码就是在不断的创建大小为256KB的数组类型的对象。
VM参数配置如下:

-Xmx128M -XX:+UseG1GC -Xlog:gc*

参数解释
-Xmx128MXmx128M的主要作用是将堆内存限制在128M,这样方便我们快速将其使用完,从而能够看到垃圾回收等信息。
-XX:+UseG1GCjdk17默认就是G1垃圾回收器,可以省略
-Xlog:gc*启用所有 GC 相关日志,没配置日志文件保存地址,就打印到控制台

执行结果如下:

image.png

image.png

堆内存(Heap)
├── Young Generation (20MB)
│   ├── Eden 区 (17MB = 17个Region)
│   └── Survivor 区 (3MB = 3个Region) ← 你看到的 3 survivors
│
└── Old Generation (剩余空间)
    └── 存放长期存活的对象
2.2.1.2、测试分区类型

在G1里区域是有多种类型的:

  • 新生代分区:存储新创建的对象的分区,默认大小是1MB,又可以分为Eden区和Survivor区。
  • 老年代分区:存储生命周期比较长的对象,默认大小是1MB。
  • 大对象分区:主要存储比较大的对象。

image.png

2.2.1.2.1、什么样的年轻代对象才会放进H(Humongous)区?

答:如果对象大小等于分区的大于或等于单个分区的一半,则会将其放到H区。

现在region默认是1M,我们的对象也就是要达到1M的一半(1024K* 512)。

VM参数不变,我调大每个data对象的大小,代码如下:

public class RegionExample1 {
    public static void main(String[] args) {
        byte[] data = new byte[1024 * 511];
        for (int i = 0; i < 100; i++) {
            //不断申请256KB内存,导致内存泄漏
            data = new byte[1024 * 511];
        }
    }
}

image.png

public class RegionExample1 {
    public static void main(String[] args) {
        byte[] data = new byte[1024 * 512];
        for (int i = 0; i < 100; i++) {
            //不断申请256KB内存,导致内存泄漏
            data = new byte[1024 * 512];
        }
    }
}

image.png

2.2.1.3、新生代和老年代分别占多少?
2.2.1.3.1、上面我们注意到年轻代区域的个数是变化的,那么新生代和老年代是怎么分配的呢?

答:默认情况下,新生代占比是动态变化的,新生代占比堆空间的比例最小为5%,然后慢慢整家到最大为60%。

如果是5%,假设堆空间是128MB,那应该大约有6.4MB的空间是给新生代的。如果能到60%,那差不多就是76MB,我们继续修改上面的代码,如下:

public class RegionExample1 {
    public static void main(String[] args) {
        byte[] data = new byte[1024 * 256];
        for (int i = 0; i < 1000; i++) {
            //不断申请256KB内存,导致内存泄漏
            data = new byte[1024 * 256];
        }
    }
}

这里在新生代区分配1000个小对象,执行一下,此时会发现多次出现如下字样:

Pause Young (Normal) (G1 Evacuation Pause)

这就是GC开始的标记,这里我们观察每次Eden区的变化(到了73后面就不变了):

第一次:
[0.090s][info][gc,heap     ] GC(0) Eden regions: 23->0(40)
[0.090s][info][gc,heap     ] GC(0) Survivor regions: 0->3(3)
第二次:
[0.093s][info][gc,heap     ] GC(1) Eden regions: 40->0(73)
[0.093s][info][gc,heap     ] GC(1) Survivor regions: 3->3(6)
第三次:
[0.099s][info][gc,heap     ] GC(2) Eden regions: 73->0(73)
[0.099s][info][gc,heap     ] GC(2) Survivor regions: 3->3(10)
第四次:
[0.103s][info][gc,heap     ] GC(3) Eden regions: 73->0(73)
[0.103s][info][gc,heap     ] GC(3) Survivor regions: 3->3(10)
第五次:
[0.106s][info][gc,heap     ] GC(4) Eden regions: 73->0(73)
[0.106s][info][gc,heap     ] GC(4) Survivor regions: 3->3(10)

注意:这里73就表示73个region,也就是73M(一个region是1M)。

可以看到开始的时候使用的是比较小的23(M),而到了第三次时候迅速增加到73(MB),并且第三次之后就不再增加了。
堆空间除了分配对象,还要分配元空间数据等等,因此上面的23M和73M会与我们预期的稍微小一些。我们可以通过设置两种区域的比例来满足系统的某些优化方面的要求,方法是通过”-XX:NewRatio=n”来设置新生代和老年代的占比,默认值2,此时新生代占整个堆空间的比例就是:

1/(n+1)

我们通过下面的例子, vm参数新增“-XX:NewRatio”来验证一下:

-Xmx128M -XX:NewRatio=6 -Xlog:gc*

这里我们将堆空间限制为128MB,此时新生代的占比就是128/(1+6)=18MB,然后我们执行一下上面的代码,每次GC完成之后都输出的信息,eden区维持在接近18:

第一次:
[0.119s][info][gc,heap     ] GC(0) Eden regions: 18->0(15)
[0.119s][info][gc,heap     ] GC(0) Survivor regions: 0->3(3)
第二次:
[0.120s][info][gc,heap     ] GC(1) Eden regions: 15->0(17)
[0.120s][info][gc,heap     ] GC(1) Survivor regions: 3->1(3)
第三次:
[0.121s][info][gc,heap     ] GC(2) Eden regions: 17->0(17)
[0.121s][info][gc,heap     ] GC(2) Survivor regions: 1->1(3)
第四次:
[0.121s][info][gc,heap     ] GC(3) Eden regions: 17->0(17)
[0.121s][info][gc,heap     ] GC(3) Survivor regions: 1->1(3)
第五次:
[0.122s][info][gc,heap     ] GC(4) Eden regions: 17->0(17)
[0.122s][info][gc,heap     ] GC(4) Survivor regions: 1->1(3)

这就说明我们设置的参数确实生效了。

扩展,在G1里还有两组参数:

  1. 我们可以通过"-XX:newSize-XX:MaxNewSize"来设置新生代的最小值和最大值。如果不设置的话,G1会自动计算出一个值,从5%的Region数量开始,慢慢增加到60%。
  2. 我们也可以通过"-Xx:G1NewSizeRercent-Xx:G1MaxNewSizeRercent”来设置新生区region的数量,默认也是最小5%,最大60%。
2.2.1.4、如何设置分区大小
2.2.1.4.1、通过G1的vm参数HeapRegionSize设置区间大小

我们前面的测试中,region的大小都是1M,如果想修改,可以通过-XX:G1HeapRegionsize=4M来设置,例如使用下面的参数:

-Xmx128M -XX:G1HeapRegionSize=4M -Xlog:gc*

然后我们再执行代码,此时会看到输出的日志如下:

image.png

此时分区大小就是4MB,我们的修改生效了。注意,分区大小只能采用2的指数倍的值,例如1/2/4/8/16/32等等;如果不是,则会取最接近的值,例如如果设置的是31M就会向下取32M。

2.2.1.4.2、通过设置堆空间大小来设置分区大小

关于分区的问题,我们先说几条重要的结论,然后再逐步展开分析。

  1. 在JVM中,默认情况下,各种分区大小都是1MB。

  2. 分区默认个数2048个。

  3. 设置是通过如下公式进行的,这里的单位都是MB。

    image.png

  4. 分区的大小一般取1/2/4/8/16/32的这几种数值,如果根据上面的计算公式计算,结果小于1MB则会使用1MB,高于32MB就会使用32MB。

  5. 如果Xms和Xmx值不一样,则会以Xmx值的2倍代入公式计算出region值。

虽然通过-XX:G1HeapRegionsize能修改分区大小,但是平时我们更关心程序要在多大堆空间下工作,因此经常会设置-Xmx -Xms这两个参数,如果修改了这两个值,也会导致分区情况发生变化。

下面我们新增vm参数“-Xmx -Xms”并设置不同的值测试下:

-Xmx8192M -Xms8192M -Xlog:gc*

(8192+8192)/ 2 * 2048 = 4,因此region会被设置成4M。

执行之前的代码后,查看结果如下:

image.png

-Xmx4096M -Xms4096M -Xlog:gc*

(4096+4096)/ 2 * 2048 = 2,因此region会被设置成2M。

执行之前的代码后,查看结果如下:

image.png

2.3、G1三种垃圾回收策略的原理与实战

2.3.1、G1三种垃圾回收策略的概念与触发条件
2.3.1.1、G1三种垃圾回收方式分别是什么含义
  • 新生代回收(YGC): 只回收新生代区域,代价低/频率高。
  • 混合回收(MixGC): 回收全部新生代+部分老年代,频率一般。
  • 完全回收(FullGC): 全部堆空间,代价高/频率低,系统距崩溃不远了。
2.3.1.2、G1三种垃圾回放方式分别在什么时候触发

image.png

2.3.1.3、大对象:危险!危险!
  • 设计不合理,容易导致线上故障
  • 基本原则: 短周期对象,不要进入老年代
2.3.2、梳理几个容易晕的GC的概念
  • 第一组: MinorGC vs YoungGC
    两者等价的,新生代和年轻代也是一回事,当Eden区占满之后触发对年轻代的垃圾回收
  • 第二组: FullGC vs OldGC
    在G1之前的垃圾回收器里,两者是等价的,都是老年代被/占满之后触发对老年代的垃圾回收在G1里不等价,G1里的Full GC是将新生代、老年代和永久代等全部空间进行垃圾回收,显然包含的范围更广
  • 第三组: MajorGC
    这个名字在G1之前的垃圾回收器里有时会看到,现在用的比较少,因为其含义并不清晰有人认为MajorGC=OldGC,就是针对老年代的GC。
  • 第四组: MixedGC
    这个名字只在G1才有。前面讲过,当老年代占据堆空间超过45%就会触发,此时会对年轻代区域和部分老年代区域进行垃圾回收。

在G1垃圾回收器里,只有YoungGC、FullGC、MixedGC。

2.4、YGC原理与过程

2.4.2、YGC的大致工作过程

YGC又分为Eden区和S区。新创建的对象先分配在Eden区,新生区满了就触发YGC。
基本图解G1对象管理过程提到过,如下图:

新生成对象垃圾回收一次后继续分配
image.pngimage.png
2.4.2、YGC工作的详细过程
2.4.2.1、YGC的基本过程一

标记存活对象: 从GCroots出发标记存活对象。

image.png

2.4.2.2、YGC的基本过程二

复制存活对象到S区,该过程最耗时。

image.png

2.4.2.3、YGC的基本过程三

释放垃圾集合,回收region;该工作反而比较快,类似硬盘格式化。

image.png

2.4.2.4、YGC的基本过程四

动态调整新生代区域region的数量:自动判断增加还是减少region区的数量。如果需要变大,新生代就增加;如果YGC能力弱,回收时间太长,那就减少数量。

2.3.2.5、YGC的基本过程五

判断是否需要开启并发标记。如果开启了,并发标记是为下一步执行混合GC做准备的。

2.4.3、YGC里并行执行和串行执行的任务

以下任务是并行执行的:

  • 对于YGC,复制对象和标记是同时进行的,也即不是所有标记完才开始复制,而是找到一个对象就复制。
  • 更新RSet,处理跨区引用问题。

以下任务是串行执行的:

  1. 软引用、弱引用和虚引用的处理
  2. 释放分区
  3. 尝试回收大对象
  4. 尝试扩展内存
  5. 调整新生代分区的数目
  6. 尝试启动并发标记,如果启动成功就要进入mixedGC了
2.4.4、模拟一次YGC过程与GC日志详解

我们上一个案例执行垃圾回收都是新生代垃圾回收,分析其日志时,我们主要看几个核心的数据。这一案例,我们来仔细看下GC日志里到底有什么。代码内容如下:

public class RegionExample1 {
    public static void main(String[] args) {
        byte[] data = new byte[1024 * 256];
        for (int i = 0; i < 200; i++) {
            //不断申请256KB内存,导致内存泄漏
            data = new byte[1024 * 256];
        }
    }
}

我们这段代码仍然是不断创建大小为256KB的数组类型的对象。VM参数如下:

-Xmx128M -Xms128M -XX:+UnlockExperimentalVMOptions -Xlog:gc*

接下来,我们看看G1执行YGC时到底发生了什么。

垃圾回收的时候,GC日志可以记录每个GC的过程,其内容时非常服务的,不同的参数和用户程序时如何进行回收的,在GC日志里都有完成的提现。

......
# GC(0)开始:第0次GC;普通新生代YGC(G1 Evacuation Pause对象拷贝转移,STW停顿)
[0.067s][info][gc,start    ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)

# GC(0)本次回收实际启用3个拷贝工作线程,总配置8个;堆小不需要全部线程
[0.067s][info][gc,task     ] GC(0) Using 3 workers of 8 for evacuation

# YGC阶段:预处理本次要回收的Region集合CSet,耗时0.0ms
[0.068s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.0ms

# YGC阶段:合并堆根引用(栈、静态变量、卡表),找存活对象,耗时0.0ms
[0.068s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms

# YGC核心阶段Evacuate:拷贝转移存活对象,耗时0.7ms,YGC主要耗时点
[0.068s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 0.7ms

# YGC阶段:拷贝完成后收尾、清理卡表,耗时0.2ms
[0.068s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.2ms

# YGC阶段:其余杂项STW开销,耗时0.1ms
[0.068s][info][gc,phases   ] GC(0)   Other: 0.1ms

# Eden区Region变化:GC前23个,回收后0个;(40)代表当前Eden最大可用40个Region
[0.068s][info][gc,heap     ] GC(0) Eden regions: 23->0(40)

# Survivor区Region变化:GC前0个,GC后3个;(3)Survivor最大可用3个Region;存活对象复制到Survivor
[0.068s][info][gc,heap     ] GC(0) Survivor regions: 0->3(3)

# Old老年代Region变化:GC前0,GC后1;部分对象直接晋升到老年代
[0.068s][info][gc,heap     ] GC(0) Old regions: 0->1

# CDS归档只读Region,不会被GC回收,数量不变2个
[0.068s][info][gc,heap     ] GC(0) Archive regions: 2->2

# Humongous大对象Region;大于Region一半的对象,本次无大对象
[0.068s][info][gc,heap     ] GC(0) Humongous regions: 0->0

# Metaspace元空间统计;YGC不回收元空间;使用/已提交;NonClass非类元数据、Class类元数据
[0.068s][info][gc,metaspace] GC(0) Metaspace: 506K(704K)->506K(704K) NonClass: 482K(576K)->482K(576K) Class: 23K(128K)->23K(128K)

# GC(0)摘要行:YGC 堆23M→4M,堆总容量128M,STW暂停总时间1.020ms
[0.068s][info][gc          ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 23M->4M(128M) 1.020ms

# GC(0)CPU统计:User用户态CPU、Sys内核CPU;Real墙上时钟(受日志精度显示为0,以上面pause时间为准)
[0.068s][info][gc,cpu      ] GC(0) User=0.01s Sys=0.00s Real=0.00s

# GC(1)开始:第1次GC,又一次普通新生代YGC,距离上一次GC仅约2ms,堆太小Eden快速写满
[0.070s][info][gc,start    ] GC(1) Pause Young (Normal) (G1 Evacuation Pause)

# GC(1)本次实际使用3个拷贝工作线程,总配置8个
[0.070s][info][gc,task     ] GC(1) Using 3 workers of 8 for evacuation

# GC(1) YGC阶段:预处理回收集合CSet,耗时0.0ms
[0.071s][info][gc,phases   ] GC(1)   Pre Evacuate Collection Set: 0.0ms

# GC(1) YGC阶段:合并堆根引用,耗时0.0ms
[0.071s][info][gc,phases   ] GC(1)   Merge Heap Roots: 0.0ms

# GC(1) YGC核心拷贝转移对象,耗时0.8ms
[0.071s][info][gc,phases   ] GC(1)   Evacuate Collection Set: 0.8ms

# GC(1) YGC拷贝后收尾清理,耗时0.1ms
[0.071s][info][gc,phases   ] GC(1)   Post Evacuate Collection Set: 0.1ms

# GC(1) YGC其余杂项STW开销,耗时0.1ms
[0.071s][info][gc,phases   ] GC(1)   Other: 0.1ms

# GC(1) Eden:回收前40个Region,回收后0;(72)当前Eden最大可用72个Region
[0.071s][info][gc,heap     ] GC(1) Eden regions: 40->0(72)

# GC(1) Survivor:GC前3,GC后4;(6)Survivor上限6个Region
[0.071s][info][gc,heap     ] GC(1) Survivor regions: 3->4(6)

# GC(1) Old老年代Region数量不变维持1
[0.071s][info][gc,heap     ] GC(1) Old regions: 1->1

# GC(1) CDS归档Region,只读不回收,保持2
[0.071s][info][gc,heap     ] GC(1) Archive regions: 2->2

# GC(1) Humongous大对象Region,无大对象
[0.071s][info][gc,heap     ] GC(1) Humongous regions: 0->0

# GC(1) Metaspace元空间;加载少量新类略微上涨,YGC不释放元空间
[0.071s][info][gc,metaspace] GC(1) Metaspace: 526K(704K)->526K(704K) NonClass: 500K(576K)->500K(576K) Class: 25K(128K)->25K(128K)

# GC(1)摘要行:YGC堆44M→4M,堆总128M,STW暂停总1.172ms
[0.071s][info][gc          ] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 44M->4M(128M) 1.172ms

# GC(1) CPU统计;Real受日志精度显示0,以pause时间为准
[0.071s][info][gc,cpu      ] GC(1) User=0.00s Sys=0.00s Real=0.00s

# JVM即将退出,打印最终堆快照,标签gc,heap,exit
[0.071s][info][gc,heap,exit] Heap

# G1堆总大小131072K=128M;已使用15686K;堆内存地址区间
[0.071s][info][gc,heap,exit]  garbage-first heap   total 131072K, used 15686K [0x00000007f8000000, 0x0000000800000000)

# Region大小1024K(1M);Young区15个Region;其中Survivor占4个Region
[0.071s][info][gc,heap,exit]   region size 1024K, 15 young (15360K), 4 survivors (4096K)

# Metaspace元空间:used实际使用;committed操作系统已提交物理内存;reserved虚拟预留内存
[0.071s][info][gc,heap,exit]  Metaspace       used 531K, committed 704K, reserved 1114112K

# class space压缩类空间统计:used使用、committed已提交、reserved虚拟预留
[0.071s][info][gc,heap,exit]   class space    used 26K, committed 128K, reserved 1048576K
2.4.5 案例实战
2.4.5.1、每秒10万的公开课服务为什么被优先升为G1?

案例:有一个公开课,在线教育领域,为了吸引用户,会经常直播举行公开课。为了让学员尽快报名,借助大数据平台来分析数据,并实时展示给用户剩余名额等等。

系统条件:一万名学生,qps=2000,每个请求25KB,数据量50MB。机器使用4H8G物理机,大约两三分种触发一次YGC,每次几百毫秒,使用cms垃圾回收器。

业务挑战:如何支持几十万~百万名学生同时在线。

系统升级:

  1. 机器内存升级为32~64GB,机器增加。
  2. 使用G1垃圾回收器,设置最大停顿时间,例如200ms,增加了YGC次数,但是用户程序也在并行执行,互不影响。

2.5、停顿预测模型Remembered Set (RSet)与垃圾区域的选择原理

2.5.1、如何测试设置停顿时间

答:修改每次垃圾回收的时间,观察效果;指令:-XX:MaxGCPauseMillis=数值,执行YGC的次数由2变成多次。

  • 第一种情况:-XX:MaxGCPauseMillis=1,1ms垃圾回收会受不了多少东西,所以会回收多次。
-Xmx128M -Xms128M -XX:+UnlockExperimentalVMOptions -XX:MaxGCPauseMillis=1 -Xlog:gc*

年轻代回收了5次垃圾回收:

[0.008s][info][gc] Using G1
[0.008s][info][gc,init] Version: 17.0.16+8-LTS (release)
[0.008s][info][gc,init] CPUs: 8 total, 8 available
[0.008s][info][gc,init] Memory: 16384M
[0.008s][info][gc,init] Large Page Support: Disabled
[0.008s][info][gc,init] NUMA Support: Disabled
[0.008s][info][gc,init] Compressed Oops: Enabled (Zero based)
[0.008s][info][gc,init] Heap Region Size: 1M
[0.008s][info][gc,init] Heap Min Capacity: 128M
[0.008s][info][gc,init] Heap Initial Capacity: 128M
[0.008s][info][gc,init] Heap Max Capacity: 128M
[0.008s][info][gc,init] Pre-touch: Disabled
[0.008s][info][gc,init] Parallel Workers: 8
[0.008s][info][gc,init] Concurrent Workers: 2
[0.008s][info][gc,init] Concurrent Refinement Workers: 8
[0.008s][info][gc,init] Periodic GC: Disabled
[0.012s][info][gc,metaspace] CDS archive(s) mapped at: [0x0000000700000000-0x0000000700bc0000-0x0000000700bc0000), size 12320768, SharedBaseAddress: 0x0000000700000000, ArchiveRelocationMode: 1.
[0.012s][info][gc,metaspace] Compressed class space mapped at: 0x0000000701000000-0x0000000741000000, reserved size: 1073741824
[0.012s][info][gc,metaspace] Narrow klass base: 0x0000000700000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[0.115s][info][gc,start    ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[0.115s][info][gc,task     ] GC(0) Using 3 workers of 8 for evacuation
[0.116s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.116s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms
[0.116s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 0.7ms
[0.116s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.1ms
[0.116s][info][gc,phases   ] GC(0)   Other: 0.1ms
[0.116s][info][gc,heap     ] GC(0) Eden regions: 6->0(5)
[0.116s][info][gc,heap     ] GC(0) Survivor regions: 0->1(1)
[0.116s][info][gc,heap     ] GC(0) Old regions: 0->3
[0.116s][info][gc,heap     ] GC(0) Archive regions: 2->2
[0.116s][info][gc,heap     ] GC(0) Humongous regions: 0->0
[0.116s][info][gc,metaspace] GC(0) Metaspace: 513K(704K)->513K(704K) NonClass: 489K(576K)->489K(576K) Class: 23K(128K)->23K(128K)
[0.116s][info][gc          ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 6M->4M(128M) 0.948ms
[0.116s][info][gc,cpu      ] GC(0) User=0.00s Sys=0.00s Real=0.01s
[0.116s][info][gc,start    ] GC(1) Pause Young (Normal) (G1 Evacuation Pause)
[0.116s][info][gc,task     ] GC(1) Using 3 workers of 8 for evacuation
[0.116s][info][gc,mmu      ] GC(1) MMU target violated: 1.2ms (1.0ms/2.0ms)
[0.116s][info][gc,phases   ] GC(1)   Pre Evacuate Collection Set: 0.0ms
[0.116s][info][gc,phases   ] GC(1)   Merge Heap Roots: 0.0ms
[0.116s][info][gc,phases   ] GC(1)   Evacuate Collection Set: 0.3ms
[0.116s][info][gc,phases   ] GC(1)   Post Evacuate Collection Set: 0.0ms
[0.116s][info][gc,phases   ] GC(1)   Other: 0.0ms
[0.116s][info][gc,heap     ] GC(1) Eden regions: 5->0(5)
[0.116s][info][gc,heap     ] GC(1) Survivor regions: 1->1(1)
[0.116s][info][gc,heap     ] GC(1) Old regions: 3->4
[0.116s][info][gc,heap     ] GC(1) Archive regions: 2->2
[0.116s][info][gc,heap     ] GC(1) Humongous regions: 0->0
[0.116s][info][gc,metaspace] GC(1) Metaspace: 513K(704K)->513K(704K) NonClass: 490K(576K)->490K(576K) Class: 23K(128K)->23K(128K)
[0.116s][info][gc          ] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 9M->4M(128M) 0.400ms
[0.116s][info][gc,cpu      ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.116s][info][gc,start    ] GC(2) Pause Young (Normal) (G1 Evacuation Pause)
[0.116s][info][gc,task     ] GC(2) Using 3 workers of 8 for evacuation
[0.116s][info][gc,mmu      ] GC(2) MMU target violated: 1.2ms (1.0ms/2.0ms)
[0.116s][info][gc,phases   ] GC(2)   Pre Evacuate Collection Set: 0.0ms
[0.116s][info][gc,phases   ] GC(2)   Merge Heap Roots: 0.0ms
[0.116s][info][gc,phases   ] GC(2)   Evacuate Collection Set: 0.0ms
[0.116s][info][gc,phases   ] GC(2)   Post Evacuate Collection Set: 0.0ms
[0.116s][info][gc,phases   ] GC(2)   Other: 0.0ms
[0.116s][info][gc,heap     ] GC(2) Eden regions: 5->0(5)
[0.116s][info][gc,heap     ] GC(2) Survivor regions: 1->1(1)
[0.116s][info][gc,heap     ] GC(2) Old regions: 4->4
[0.116s][info][gc,heap     ] GC(2) Archive regions: 2->2
[0.116s][info][gc,heap     ] GC(2) Humongous regions: 0->0
[0.116s][info][gc,metaspace] GC(2) Metaspace: 513K(704K)->513K(704K) NonClass: 490K(576K)->490K(576K) Class: 23K(128K)->23K(128K)
[0.117s][info][gc          ] GC(2) Pause Young (Normal) (G1 Evacuation Pause) 9M->4M(128M) 0.124ms
[0.117s][info][gc,cpu      ] GC(2) User=0.00s Sys=0.00s Real=0.00s
[0.117s][info][gc,start    ] GC(3) Pause Young (Normal) (G1 Evacuation Pause)
[0.117s][info][gc,task     ] GC(3) Using 3 workers of 8 for evacuation
[0.117s][info][gc,mmu      ] GC(3) MMU target violated: 1.3ms (1.0ms/2.0ms)
[0.117s][info][gc,phases   ] GC(3)   Pre Evacuate Collection Set: 0.0ms
[0.117s][info][gc,phases   ] GC(3)   Merge Heap Roots: 0.0ms
[0.117s][info][gc,phases   ] GC(3)   Evacuate Collection Set: 0.0ms
[0.117s][info][gc,phases   ] GC(3)   Post Evacuate Collection Set: 0.0ms
[0.117s][info][gc,phases   ] GC(3)   Other: 0.0ms
[0.117s][info][gc,heap     ] GC(3) Eden regions: 5->0(34)
[0.117s][info][gc,heap     ] GC(3) Survivor regions: 1->1(1)
[0.117s][info][gc,heap     ] GC(3) Old regions: 4->4
[0.117s][info][gc,heap     ] GC(3) Archive regions: 2->2
[0.117s][info][gc,heap     ] GC(3) Humongous regions: 0->0
[0.117s][info][gc,metaspace] GC(3) Metaspace: 513K(704K)->513K(704K) NonClass: 490K(576K)->490K(576K) Class: 23K(128K)->23K(128K)
[0.117s][info][gc          ] GC(3) Pause Young (Normal) (G1 Evacuation Pause) 9M->4M(128M) 0.132ms
[0.117s][info][gc,cpu      ] GC(3) User=0.00s Sys=0.00s Real=0.00s
[0.119s][info][gc,start    ] GC(4) Pause Young (Normal) (G1 Evacuation Pause)
[0.119s][info][gc,task     ] GC(4) Using 3 workers of 8 for evacuation
[0.119s][info][gc,phases   ] GC(4)   Pre Evacuate Collection Set: 0.0ms
[0.119s][info][gc,phases   ] GC(4)   Merge Heap Roots: 0.0ms
[0.119s][info][gc,phases   ] GC(4)   Evacuate Collection Set: 0.1ms
[0.119s][info][gc,phases   ] GC(4)   Post Evacuate Collection Set: 0.1ms
[0.119s][info][gc,phases   ] GC(4)   Other: 0.0ms
[0.119s][info][gc,heap     ] GC(4) Eden regions: 34->0(31)
[0.119s][info][gc,heap     ] GC(4) Survivor regions: 1->1(5)
[0.119s][info][gc,heap     ] GC(4) Old regions: 4->4
[0.119s][info][gc,heap     ] GC(4) Archive regions: 2->2
[0.119s][info][gc,heap     ] GC(4) Humongous regions: 0->0
[0.119s][info][gc,metaspace] GC(4) Metaspace: 544K(704K)->544K(704K) NonClass: 517K(576K)->517K(576K) Class: 27K(128K)->27K(128K)
[0.119s][info][gc          ] GC(4) Pause Young (Normal) (G1 Evacuation Pause) 38M->4M(128M) 0.253ms
[0.119s][info][gc,cpu      ] GC(4) User=0.00s Sys=0.00s Real=0.00s
[0.120s][info][gc,heap,exit] Heap
[0.120s][info][gc,heap,exit]  garbage-first heap   total 131072K, used 22942K [0x00000007f8000000, 0x0000000800000000)
[0.120s][info][gc,heap,exit]   region size 1024K, 19 young (19456K), 1 survivors (1024K)
[0.120s][info][gc,heap,exit]  Metaspace       used 604K, committed 768K, reserved 1114112K
[0.120s][info][gc,heap,exit]   class space    used 30K, committed 128K, reserved 1048576K
  • 第二种情况:-XX:MaxGCPauseMillis=1000
-Xmx128M -Xms128M -XX:+UnlockExperimentalVMOptions -XX:MaxGCPauseMillis=1000 -Xlog:gc*

年轻代回收了1次垃圾回收:

[0.008s][info][gc] Using G1
[0.009s][info][gc,init] Version: 17.0.16+8-LTS (release)
[0.009s][info][gc,init] CPUs: 8 total, 8 available
[0.009s][info][gc,init] Memory: 16384M
[0.009s][info][gc,init] Large Page Support: Disabled
[0.009s][info][gc,init] NUMA Support: Disabled
[0.009s][info][gc,init] Compressed Oops: Enabled (Zero based)
[0.009s][info][gc,init] Heap Region Size: 1M
[0.009s][info][gc,init] Heap Min Capacity: 128M
[0.009s][info][gc,init] Heap Initial Capacity: 128M
[0.009s][info][gc,init] Heap Max Capacity: 128M
[0.009s][info][gc,init] Pre-touch: Disabled
[0.009s][info][gc,init] Parallel Workers: 8
[0.009s][info][gc,init] Concurrent Workers: 2
[0.009s][info][gc,init] Concurrent Refinement Workers: 8
[0.009s][info][gc,init] Periodic GC: Disabled
[0.014s][info][gc,metaspace] CDS archive(s) mapped at: [0x000000d800000000-0x000000d800bc0000-0x000000d800bc0000), size 12320768, SharedBaseAddress: 0x000000d800000000, ArchiveRelocationMode: 1.
[0.014s][info][gc,metaspace] Compressed class space mapped at: 0x000000d801000000-0x000000d841000000, reserved size: 1073741824
[0.014s][info][gc,metaspace] Narrow klass base: 0x000000d800000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[0.087s][info][gc,start    ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[0.088s][info][gc,task     ] GC(0) Using 3 workers of 8 for evacuation
[0.088s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.1ms
[0.088s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms
[0.088s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 0.6ms
[0.088s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.1ms
[0.088s][info][gc,phases   ] GC(0)   Other: 0.3ms
[0.088s][info][gc,heap     ] GC(0) Eden regions: 60->0(72)
[0.088s][info][gc,heap     ] GC(0) Survivor regions: 0->4(8)
[0.088s][info][gc,heap     ] GC(0) Old regions: 0->0
[0.088s][info][gc,heap     ] GC(0) Archive regions: 2->2
[0.088s][info][gc,heap     ] GC(0) Humongous regions: 0->0
[0.088s][info][gc,metaspace] GC(0) Metaspace: 598K(768K)->598K(768K) NonClass: 568K(640K)->568K(640K) Class: 30K(128K)->30K(128K)
[0.088s][info][gc          ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 60M->4M(128M) 1.049ms
[0.088s][info][gc,cpu      ] GC(0) User=0.01s Sys=0.00s Real=0.01s
[0.089s][info][gc,heap,exit] Heap
[0.089s][info][gc,heap,exit]  garbage-first heap   total 131072K, used 19104K [0x00000007f8000000, 0x0000000800000000)
[0.089s][info][gc,heap,exit]   region size 1024K, 18 young (18432K), 4 survivors (4096K)
[0.089s][info][gc,heap,exit]  Metaspace       used 627K, committed 832K, reserved 1114112K
[0.089s][info][gc,heap,exit]   class space    used 32K, committed 128K, reserved 1048576K
2.5.2、结论——停顿预测模型Remembered Set (RSet)主要是针对老年代
  • 停顿预测模型主要是针对老年代的。但是如果这是的时间太小,YGC时新生代也不一定全部回收。
  • 在G1垃圾回收器里,用户可通过MaxGCPauseMillis设定整个GC过程的期望停顿时间,默认是200ms。G1会努力在该时间内完成一次垃圾回收。
  • G1根据停顿预测模型,基于历史数据来预测本次手机需要选择的堆分区数量,从而尽量满足用户设定的时间。
2.5.3、面试实战——G1如何选择垃圾集合?

问题1:垃圾回收的时间花到那里了?

:真正决定回收时间的就是转移对象所需要的时间,甚至可以直接简化为回收时间=对象转移时间。

问题2: 如何统计回收时间?如何看哪些是回收价值高的?

:G1 预测模型是基于历史 GC 样本的统计模型,假设拷贝存活对象、扫描 RSet 的耗时是线性关系。每次 GC 完成采集真实耗时做样本,用加权移动平均更新统计,运行越久预测越准。模型预估每个 Region 拷贝存活对象 + 扫描 RSet 的耗时;Mixed‑GC 阶段,过滤掉存活占比过高的 Region,按照收益 / 耗时排序,逐个加入 CSet 回收集,累加预估总时间,不能超过 MaxGCPauseMillis 目标。

它只是预测,遇到 RSet 暴涨、存活对象突变,预测会失效,实际停顿会超出目标。

image.png

  • CSet(Collection Set) :我 要回收哪些 Region (待回收集合)
  • RSet(Remembered Set) :Region 内部的卡表集合,记录「外部其他 Region 引用到本 Region 的对象」,用来 GC 的时候避免扫描整个堆。

记忆口诀:

CSet:要回收谁

RSet:谁引用了我

2.6、混合回收MixedGC的原理与步骤

先了解一个概念与几个问题:

  • 混合回收和后面的full 回收都是同时处理新生代和老年代区域。
  • 对象什么时候进入老年代?
    Eden区的对象满足以下几种情况就会进入老年代:
    • 如果一些对象经过几轮YGC仍然存活,或者触发了动态年龄判断规则。
    • 存活对象在S区放不下,都火让对象进入老年代。
    • 大对象直接进入单独的大对象Region, 但是大对象区域本身占用的就是老年代的区域。
  • 混合回收什么时候发生?
    • 在YGC之后,已分配内存超过内存总容量的45%会触发MixedGC,参数是“-XX:InitiatingHeapOccupancyPercent”
2.6.1、什么是混合回收

混合回收的概念:**将“新生代和部分老年代”一起回收,这就是混合回收。**正常情况下,新生代能全部回收,老年代会选择一部分,但是如果停顿时间设置的太小,新生代也只能回收一部分Region。

2.7.2、混合回收基本步骤

第一步:初始标记阶段

标记出所有由GCRoot等直接引用的对象,会暂停用户程序运行,会STW。

第二步:并发标记阶段

标记出上一步中标记的所有引用的对象,执行时间略长。用户程序也会同时执行,不会STW。

第三步:再标记阶段

标记出上一个阶段没有被标记的对象(有可能上一阶段刚标记完引用对象,用户程序就更改了引用),会STW,执行速度非常快。

第四步:存活对象计数阶段

统计出每个region存活对象的数量。
为什么要统计呢?下一步回收时只会从老年代回收一部分Region,因此先统计每个Region存活数量、垃圾对象以及占比高低,才能判断该如何选择才能满足用户设定的停顿时间并保证收益最大。

第五步:垃圾回收阶段

选择回收价值高的区域,把存活对象复制到新分区,然后回收掉老区域。

2.6.3、混合回收完整过程

根据前面的说明,我们可以总结出混合回收的流程图。

image.png

问题1: 混合回收的并发标记为什么从YGC开始?

答:YGC是MixedGC的前奏,YGC完成,就代表MixedGC已经走完了出始标记阶段,YGC已经帮MixGC干完了初始化的活。MixedGC之前一定先进行一次YGC。

问题2: MixedGC的并发标记从哪里开始?YGC的处理结果是否可以用一下?

image.png

答:并发标记起点包含三种:新的S区对象、老年代GCRoot直接引用的对象、解决跨区域引用的老年代RSet。YGC的处理结果不需要用,因为它的存活对象已经存放到新的S区了。

2.6.4、如何确定哪些垃圾被回收,混合垃圾回收为什么分多次进行?

问题1: 哪些region会被回收?

答:MixedGC包含了新生代所有分区和老年代部分分区,回收的region是否要放入CSet(Collection Set)中,取决于vm参数“-XX:G1MixedGCLiveThresholdPercent”的值设置(默认85%),也就是存活对象数量是否大于这个Region区域的85%数量,大于就不再回收。

问题2:混合回收是否会真的要执行?

答:混合回收的执行条件取决于vm参数“-XX:G1HeapWastePercent”的值设置(默认5%),也就是可回收的空间占总空间的比例大于5%才会启动混合回收,否则及时并发标记已经完成也不执行。

问题3: 混合回收会多次执行吗?

答:混合回收是否多次执行,取决于停顿时间。

举例:假如混合回收计算出CSet里有400个Region满足回收的条件,但是根据停顿时间一次只能回收50个region,怎么办?

答:如果VM参数“-XX:G1MixedGCCountTarget”的值设置(默认是8)是默认设置,则会分成8次搞定,一次回收50个region。也即是混合回收对CSet分配回收,最多分成8次。

2.6.5、通过日志理解混合回收的执行过程

测试代码如下:

public class RegionExample1 {

    private static ArrayList<byte[]> list = new ArrayList<>();

    public static void main(String[] args) throws InterruptedException {
        while (true) {
            byte[] data = null;
            for (int i = 0; i < 50; i++) {
                //不断申请256KB内存,让其尽快达到总虚拟内存总容量的45%
                data = new byte[1024 * 256];

                //将创建的内存添加到list中,让其无法被GC回收,使其进入老年代
                list.add(new byte[1024 * 256]);
            }
            //每轮循环后休眠 100ms,控制内存分配速度
            Thread.sleep(100);
        }
    }
}

vm参数设置:-Xmx256M -Xms256M -XX:+UnlockExperimentalVMOptions -Xlog:gc*

执行代码日志如下:

[0.006s][info][gc] Using G1
[0.007s][info][gc,init] Version: 17.0.16+8-LTS (release)
[0.007s][info][gc,init] CPUs: 8 total, 8 available
[0.007s][info][gc,init] Memory: 16384M
[0.007s][info][gc,init] Large Page Support: Disabled
[0.007s][info][gc,init] NUMA Support: Disabled
[0.007s][info][gc,init] Compressed Oops: Enabled (Zero based)
[0.007s][info][gc,init] Heap Region Size: 1M
[0.007s][info][gc,init] Heap Min Capacity: 256M
[0.007s][info][gc,init] Heap Initial Capacity: 256M
[0.007s][info][gc,init] Heap Max Capacity: 256M
[0.007s][info][gc,init] Pre-touch: Disabled
[0.007s][info][gc,init] Parallel Workers: 8
[0.007s][info][gc,init] Concurrent Workers: 2
[0.007s][info][gc,init] Concurrent Refinement Workers: 8
[0.007s][info][gc,init] Periodic GC: Disabled
[0.011s][info][gc,metaspace] CDS archive(s) mapped at: [0x0000000400000000-0x0000000400bc0000-0x0000000400bc0000), size 12320768, SharedBaseAddress: 0x0000000400000000, ArchiveRelocationMode: 1.
[0.011s][info][gc,metaspace] Compressed class space mapped at: 0x0000000401000000-0x0000000441000000, reserved size: 1073741824
[0.011s][info][gc,metaspace] Narrow klass base: 0x0000000400000000, Narrow klass shift: 0, Narrow klass range: 0x100000000
[0.074s][info][gc,start    ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[0.074s][info][gc,task     ] GC(0) Using 6 workers of 8 for evacuation
[0.076s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.076s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms
[0.076s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 1.3ms
[0.076s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.1ms
[0.076s][info][gc,phases   ] GC(0)   Other: 0.3ms
[0.076s][info][gc,heap     ] GC(0) Eden regions: 23->0(19)
[0.076s][info][gc,heap     ] GC(0) Survivor regions: 0->3(3)
[0.076s][info][gc,heap     ] GC(0) Old regions: 0->9
[0.076s][info][gc,heap     ] GC(0) Archive regions: 2->2
[0.076s][info][gc,heap     ] GC(0) Humongous regions: 0->0
[0.076s][info][gc,metaspace] GC(0) Metaspace: 510K(704K)->510K(704K) NonClass: 485K(576K)->485K(576K) Class: 24K(128K)->24K(128K)
[0.076s][info][gc          ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 23M->12M(256M) 1.822ms
[0.076s][info][gc,cpu      ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[0.181s][info][gc,start    ] GC(1) Pause Young (Normal) (G1 Evacuation Pause)
[0.181s][info][gc,task     ] GC(1) Using 6 workers of 8 for evacuation
[0.183s][info][gc,phases   ] GC(1)   Pre Evacuate Collection Set: 0.0ms
[0.183s][info][gc,phases   ] GC(1)   Merge Heap Roots: 0.0ms
[0.183s][info][gc,phases   ] GC(1)   Evacuate Collection Set: 1.3ms
[0.183s][info][gc,phases   ] GC(1)   Post Evacuate Collection Set: 0.1ms
[0.183s][info][gc,phases   ] GC(1)   Other: 0.1ms
[0.183s][info][gc,heap     ] GC(1) Eden regions: 19->0(39)
[0.183s][info][gc,heap     ] GC(1) Survivor regions: 3->3(3)
[0.183s][info][gc,heap     ] GC(1) Old regions: 9->19
[0.183s][info][gc,heap     ] GC(1) Archive regions: 2->2
[0.183s][info][gc,heap     ] GC(1) Humongous regions: 0->0
[0.183s][info][gc,metaspace] GC(1) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.183s][info][gc          ] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 31M->22M(256M) 1.606ms
[0.183s][info][gc,cpu      ] GC(1) User=0.00s Sys=0.01s Real=0.00s
[0.287s][info][gc,start    ] GC(2) Pause Young (Normal) (G1 Evacuation Pause)
[0.287s][info][gc,task     ] GC(2) Using 6 workers of 8 for evacuation
[0.290s][info][gc,phases   ] GC(2)   Pre Evacuate Collection Set: 0.1ms
[0.290s][info][gc,phases   ] GC(2)   Merge Heap Roots: 0.0ms
[0.290s][info][gc,phases   ] GC(2)   Evacuate Collection Set: 2.1ms
[0.290s][info][gc,phases   ] GC(2)   Post Evacuate Collection Set: 0.3ms
[0.290s][info][gc,phases   ] GC(2)   Other: 0.1ms
[0.290s][info][gc,heap     ] GC(2) Eden regions: 39->0(50)
[0.290s][info][gc,heap     ] GC(2) Survivor regions: 3->6(6)
[0.290s][info][gc,heap     ] GC(2) Old regions: 19->35
[0.290s][info][gc,heap     ] GC(2) Archive regions: 2->2
[0.290s][info][gc,heap     ] GC(2) Humongous regions: 0->0
[0.290s][info][gc,metaspace] GC(2) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.290s][info][gc          ] GC(2) Pause Young (Normal) (G1 Evacuation Pause) 60M->41M(256M) 2.650ms
[0.290s][info][gc,cpu      ] GC(2) User=0.01s Sys=0.01s Real=0.01s
[0.394s][info][gc,start    ] GC(3) Pause Young (Normal) (G1 Evacuation Pause)
[0.394s][info][gc,task     ] GC(3) Using 6 workers of 8 for evacuation
[0.397s][info][gc,phases   ] GC(3)   Pre Evacuate Collection Set: 0.1ms
[0.397s][info][gc,phases   ] GC(3)   Merge Heap Roots: 0.0ms
[0.397s][info][gc,phases   ] GC(3)   Evacuate Collection Set: 2.3ms
[0.397s][info][gc,phases   ] GC(3)   Post Evacuate Collection Set: 0.1ms
[0.397s][info][gc,phases   ] GC(3)   Other: 0.1ms
[0.397s][info][gc,heap     ] GC(3) Eden regions: 50->0(67)
[0.397s][info][gc,heap     ] GC(3) Survivor regions: 6->7(7)
[0.397s][info][gc,heap     ] GC(3) Old regions: 35->59
[0.397s][info][gc,heap     ] GC(3) Archive regions: 2->2
[0.397s][info][gc,heap     ] GC(3) Humongous regions: 0->0
[0.397s][info][gc,metaspace] GC(3) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.397s][info][gc          ] GC(3) Pause Young (Normal) (G1 Evacuation Pause) 91M->66M(256M) 2.665ms
[0.397s][info][gc,cpu      ] GC(3) User=0.00s Sys=0.00s Real=0.00s
[0.602s][info][gc,start    ] GC(4) Pause Young (Normal) (G1 Evacuation Pause)
[0.602s][info][gc,task     ] GC(4) Using 6 workers of 8 for evacuation
[0.605s][info][gc,phases   ] GC(4)   Pre Evacuate Collection Set: 0.1ms
[0.605s][info][gc,phases   ] GC(4)   Merge Heap Roots: 0.0ms
[0.605s][info][gc,phases   ] GC(4)   Evacuate Collection Set: 2.8ms
[0.605s][info][gc,phases   ] GC(4)   Post Evacuate Collection Set: 0.1ms
[0.605s][info][gc,phases   ] GC(4)   Other: 0.1ms
[0.605s][info][gc,heap     ] GC(4) Eden regions: 67->0(57)
[0.605s][info][gc,heap     ] GC(4) Survivor regions: 7->10(10)
[0.605s][info][gc,heap     ] GC(4) Old regions: 59->89
[0.605s][info][gc,heap     ] GC(4) Archive regions: 2->2
[0.605s][info][gc,heap     ] GC(4) Humongous regions: 0->0
[0.605s][info][gc,metaspace] GC(4) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.605s][info][gc          ] GC(4) Pause Young (Normal) (G1 Evacuation Pause) 133M->99M(256M) 3.084ms
[0.605s][info][gc,cpu      ] GC(4) User=0.00s Sys=0.00s Real=0.00s
[0.817s][info][gc,start    ] GC(5) Pause Young (Normal) (G1 Evacuation Pause)
[0.817s][info][gc,task     ] GC(5) Using 6 workers of 8 for evacuation
[0.823s][info][gc,phases   ] GC(5)   Pre Evacuate Collection Set: 0.1ms
[0.823s][info][gc,phases   ] GC(5)   Merge Heap Roots: 0.1ms
[0.823s][info][gc,phases   ] GC(5)   Evacuate Collection Set: 5.8ms
[0.823s][info][gc,phases   ] GC(5)   Post Evacuate Collection Set: 0.3ms
[0.823s][info][gc,phases   ] GC(5)   Other: 0.1ms
[0.823s][info][gc,heap     ] GC(5) Eden regions: 57->0(47)
[0.823s][info][gc,heap     ] GC(5) Survivor regions: 10->9(9)
[0.823s][info][gc,heap     ] GC(5) Old regions: 89->119
[0.823s][info][gc,heap     ] GC(5) Archive regions: 2->2
[0.823s][info][gc,heap     ] GC(5) Humongous regions: 0->0
[0.823s][info][gc,metaspace] GC(5) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.823s][info][gc          ] GC(5) Pause Young (Normal) (G1 Evacuation Pause) 156M->128M(256M) 6.422ms
[0.823s][info][gc,cpu      ] GC(5) User=0.01s Sys=0.02s Real=0.01s
[0.929s][info][gc,start    ] GC(6) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[0.929s][info][gc,task     ] GC(6) Using 6 workers of 8 for evacuation
[0.932s][info][gc,phases   ] GC(6)   Pre Evacuate Collection Set: 0.0ms
[0.932s][info][gc,phases   ] GC(6)   Merge Heap Roots: 0.0ms
[0.932s][info][gc,phases   ] GC(6)   Evacuate Collection Set: 2.4ms
[0.932s][info][gc,phases   ] GC(6)   Post Evacuate Collection Set: 0.1ms
[0.932s][info][gc,phases   ] GC(6)   Other: 0.1ms
[0.932s][info][gc,heap     ] GC(6) Eden regions: 47->0(38)
[0.932s][info][gc,heap     ] GC(6) Survivor regions: 9->7(7)
[0.932s][info][gc,heap     ] GC(6) Old regions: 119->144
[0.932s][info][gc,heap     ] GC(6) Archive regions: 2->2
[0.932s][info][gc,heap     ] GC(6) Humongous regions: 0->0
[0.932s][info][gc,metaspace] GC(6) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.932s][info][gc          ] GC(6) Pause Young (Concurrent Start) (G1 Evacuation Pause) 174M->151M(256M) 2.798ms
[0.932s][info][gc,cpu      ] GC(6) User=0.00s Sys=0.01s Real=0.01s
[0.932s][info][gc          ] GC(7) Concurrent Mark Cycle
[0.932s][info][gc,marking  ] GC(7) Concurrent Clear Claimed Marks
[0.932s][info][gc,marking  ] GC(7) Concurrent Clear Claimed Marks 0.004ms
[0.932s][info][gc,marking  ] GC(7) Concurrent Scan Root Regions
[0.932s][info][gc,marking  ] GC(7) Concurrent Scan Root Regions 0.621ms
[0.932s][info][gc,marking  ] GC(7) Concurrent Mark
[0.932s][info][gc,marking  ] GC(7) Concurrent Mark From Roots
[0.932s][info][gc,task     ] GC(7) Using 2 workers of 2 for marking
[0.933s][info][gc,marking  ] GC(7) Concurrent Mark From Roots 0.929ms
[0.933s][info][gc,marking  ] GC(7) Concurrent Preclean
[0.933s][info][gc,marking  ] GC(7) Concurrent Preclean 0.016ms
[0.933s][info][gc,start    ] GC(7) Pause Remark
[0.933s][info][gc          ] GC(7) Pause Remark 157M->157M(256M) 0.224ms
[0.934s][info][gc,cpu      ] GC(7) User=0.00s Sys=0.00s Real=0.00s
[0.934s][info][gc,marking  ] GC(7) Concurrent Mark 1.233ms
[0.934s][info][gc,marking  ] GC(7) Concurrent Rebuild Remembered Sets
[0.934s][info][gc,marking  ] GC(7) Concurrent Rebuild Remembered Sets 0.410ms
[0.934s][info][gc,start    ] GC(7) Pause Cleanup
[0.934s][info][gc          ] GC(7) Pause Cleanup 157M->157M(256M) 0.058ms
[0.934s][info][gc,cpu      ] GC(7) User=0.00s Sys=0.00s Real=0.00s
[0.934s][info][gc,marking  ] GC(7) Concurrent Cleanup for Next Mark
[0.934s][info][gc,marking  ] GC(7) Concurrent Cleanup for Next Mark 0.347ms
[0.934s][info][gc          ] GC(7) Concurrent Mark Cycle 2.734ms
[1.032s][info][gc,start    ] GC(8) Pause Young (Prepare Mixed) (G1 Evacuation Pause)
[1.032s][info][gc,task     ] GC(8) Using 6 workers of 8 for evacuation
[1.035s][info][gc,phases   ] GC(8)   Pre Evacuate Collection Set: 0.0ms
[1.035s][info][gc,phases   ] GC(8)   Merge Heap Roots: 0.0ms
[1.035s][info][gc,phases   ] GC(8)   Evacuate Collection Set: 2.3ms
[1.035s][info][gc,phases   ] GC(8)   Post Evacuate Collection Set: 0.1ms
[1.035s][info][gc,phases   ] GC(8)   Other: 0.1ms
[1.035s][info][gc,heap     ] GC(8) Eden regions: 38->0(6)
[1.035s][info][gc,heap     ] GC(8) Survivor regions: 7->6(6)
[1.035s][info][gc,heap     ] GC(8) Old regions: 144->164
[1.035s][info][gc,heap     ] GC(8) Archive regions: 2->2
[1.035s][info][gc,heap     ] GC(8) Humongous regions: 0->0
[1.035s][info][gc,metaspace] GC(8) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.035s][info][gc          ] GC(8) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 189M->170M(256M) 2.647ms
[1.035s][info][gc,cpu      ] GC(8) User=0.00s Sys=0.00s Real=0.00s
[1.140s][info][gc,start    ] GC(9) Pause Young (Mixed) (G1 Evacuation Pause)
[1.140s][info][gc,task     ] GC(9) Using 6 workers of 8 for evacuation
[1.142s][info][gc,phases   ] GC(9)   Pre Evacuate Collection Set: 0.1ms
[1.142s][info][gc,phases   ] GC(9)   Merge Heap Roots: 0.0ms
[1.142s][info][gc,phases   ] GC(9)   Evacuate Collection Set: 1.9ms
[1.142s][info][gc,phases   ] GC(9)   Post Evacuate Collection Set: 0.2ms
[1.142s][info][gc,phases   ] GC(9)   Other: 0.1ms
[1.142s][info][gc,heap     ] GC(9) Eden regions: 6->0(10)
[1.142s][info][gc,heap     ] GC(9) Survivor regions: 6->2(2)
[1.142s][info][gc,heap     ] GC(9) Old regions: 164->171
[1.142s][info][gc,heap     ] GC(9) Archive regions: 2->2
[1.142s][info][gc,heap     ] GC(9) Humongous regions: 0->0
[1.142s][info][gc,metaspace] GC(9) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.142s][info][gc          ] GC(9) Pause Young (Mixed) (G1 Evacuation Pause) 175M->173M(256M) 2.321ms
[1.142s][info][gc,cpu      ] GC(9) User=0.00s Sys=0.01s Real=0.00s
[1.143s][info][gc,start    ] GC(10) Pause Young (Mixed) (G1 Evacuation Pause)
[1.143s][info][gc,task     ] GC(10) Using 6 workers of 8 for evacuation
[1.144s][info][gc,phases   ] GC(10)   Pre Evacuate Collection Set: 0.0ms
[1.144s][info][gc,phases   ] GC(10)   Merge Heap Roots: 0.0ms
[1.144s][info][gc,phases   ] GC(10)   Evacuate Collection Set: 1.3ms
[1.144s][info][gc,phases   ] GC(10)   Post Evacuate Collection Set: 0.1ms
[1.144s][info][gc,phases   ] GC(10)   Other: 0.0ms
[1.144s][info][gc,heap     ] GC(10) Eden regions: 10->0(21)
[1.144s][info][gc,heap     ] GC(10) Survivor regions: 2->2(2)
[1.144s][info][gc,heap     ] GC(10) Old regions: 171->176
[1.144s][info][gc,heap     ] GC(10) Archive regions: 2->2
[1.144s][info][gc,heap     ] GC(10) Humongous regions: 0->0
[1.144s][info][gc,metaspace] GC(10) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.144s][info][gc          ] GC(10) Pause Young (Mixed) (G1 Evacuation Pause) 182M->178M(256M) 1.685ms
[1.144s][info][gc,cpu      ] GC(10) User=0.01s Sys=0.00s Real=0.00s
[1.249s][info][gc,start    ] GC(11) Pause Young (Mixed) (G1 Evacuation Pause)
[1.249s][info][gc,task     ] GC(11) Using 6 workers of 8 for evacuation
[1.251s][info][gc,phases   ] GC(11)   Pre Evacuate Collection Set: 0.1ms
[1.251s][info][gc,phases   ] GC(11)   Merge Heap Roots: 0.0ms
[1.251s][info][gc,phases   ] GC(11)   Evacuate Collection Set: 1.6ms
[1.251s][info][gc,phases   ] GC(11)   Post Evacuate Collection Set: 0.2ms
[1.251s][info][gc,phases   ] GC(11)   Other: 0.2ms
[1.251s][info][gc,heap     ] GC(11) Eden regions: 21->0(19)
[1.251s][info][gc,heap     ] GC(11) Survivor regions: 2->3(3)
[1.251s][info][gc,heap     ] GC(11) Old regions: 176->185
[1.251s][info][gc,heap     ] GC(11) Archive regions: 2->2
[1.251s][info][gc,heap     ] GC(11) Humongous regions: 0->0
[1.251s][info][gc,metaspace] GC(11) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.251s][info][gc          ] GC(11) Pause Young (Mixed) (G1 Evacuation Pause) 198M->188M(256M) 2.189ms
[1.251s][info][gc,cpu      ] GC(11) User=0.01s Sys=0.00s Real=0.01s
[1.251s][info][gc,start    ] GC(12) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[1.251s][info][gc,task     ] GC(12) Using 6 workers of 8 for evacuation
[1.252s][info][gc,phases   ] GC(12)   Pre Evacuate Collection Set: 0.1ms
[1.252s][info][gc,phases   ] GC(12)   Merge Heap Roots: 0.1ms
[1.252s][info][gc,phases   ] GC(12)   Evacuate Collection Set: 0.5ms
[1.252s][info][gc,phases   ] GC(12)   Post Evacuate Collection Set: 0.2ms
[1.252s][info][gc,phases   ] GC(12)   Other: 0.1ms
[1.252s][info][gc,heap     ] GC(12) Eden regions: 19->0(25)
[1.252s][info][gc,heap     ] GC(12) Survivor regions: 3->3(3)
[1.252s][info][gc,heap     ] GC(12) Old regions: 185->195
[1.252s][info][gc,heap     ] GC(12) Archive regions: 2->2
[1.252s][info][gc,heap     ] GC(12) Humongous regions: 0->0
[1.252s][info][gc,metaspace] GC(12) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.252s][info][gc          ] GC(12) Pause Young (Concurrent Start) (G1 Evacuation Pause) 207M->198M(256M) 0.982ms
[1.252s][info][gc,cpu      ] GC(12) User=0.00s Sys=0.00s Real=0.00s
[1.252s][info][gc          ] GC(13) Concurrent Mark Cycle
[1.252s][info][gc,marking  ] GC(13) Concurrent Clear Claimed Marks
[1.252s][info][gc,marking  ] GC(13) Concurrent Clear Claimed Marks 0.006ms
[1.252s][info][gc,marking  ] GC(13) Concurrent Scan Root Regions
[1.253s][info][gc,marking  ] GC(13) Concurrent Scan Root Regions 0.335ms
[1.253s][info][gc,marking  ] GC(13) Concurrent Mark
[1.253s][info][gc,marking  ] GC(13) Concurrent Mark From Roots
[1.253s][info][gc,task     ] GC(13) Using 2 workers of 2 for marking
[1.255s][info][gc,marking  ] GC(13) Concurrent Mark From Roots 2.183ms
[1.255s][info][gc,marking  ] GC(13) Concurrent Preclean
[1.255s][info][gc,marking  ] GC(13) Concurrent Preclean 0.034ms
[1.255s][info][gc,start    ] GC(13) Pause Remark
[1.255s][info][gc          ] GC(13) Pause Remark 211M->211M(256M) 0.380ms
[1.255s][info][gc,cpu      ] GC(13) User=0.00s Sys=0.00s Real=0.00s
[1.255s][info][gc,marking  ] GC(13) Concurrent Mark 2.693ms
[1.255s][info][gc,marking  ] GC(13) Concurrent Rebuild Remembered Sets
[1.256s][info][gc,marking  ] GC(13) Concurrent Rebuild Remembered Sets 1.011ms
[1.256s][info][gc,start    ] GC(13) Pause Cleanup
[1.257s][info][gc          ] GC(13) Pause Cleanup 211M->211M(256M) 0.116ms
[1.257s][info][gc,cpu      ] GC(13) User=0.00s Sys=0.00s Real=0.00s
[1.257s][info][gc,marking  ] GC(13) Concurrent Cleanup for Next Mark
[1.257s][info][gc,marking  ] GC(13) Concurrent Cleanup for Next Mark 0.460ms
[1.257s][info][gc          ] GC(13) Concurrent Mark Cycle 4.716ms
[1.356s][info][gc,start    ] GC(14) Pause Young (Prepare Mixed) (G1 Evacuation Pause)
[1.356s][info][gc,task     ] GC(14) Using 6 workers of 8 for evacuation
[1.357s][info][gc,phases   ] GC(14)   Pre Evacuate Collection Set: 0.1ms
[1.357s][info][gc,phases   ] GC(14)   Merge Heap Roots: 0.1ms
[1.357s][info][gc,phases   ] GC(14)   Evacuate Collection Set: 0.7ms
[1.357s][info][gc,phases   ] GC(14)   Post Evacuate Collection Set: 0.3ms
[1.358s][info][gc,phases   ] GC(14)   Other: 0.1ms
[1.358s][info][gc,heap     ] GC(14) Eden regions: 25->0(20)
[1.358s][info][gc,heap     ] GC(14) Survivor regions: 3->4(4)
[1.358s][info][gc,heap     ] GC(14) Old regions: 195->206
[1.358s][info][gc,heap     ] GC(14) Archive regions: 2->2
[1.358s][info][gc,heap     ] GC(14) Humongous regions: 0->0
[1.358s][info][gc,metaspace] GC(14) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.358s][info][gc          ] GC(14) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 223M->210M(256M) 1.271ms
[1.358s][info][gc,cpu      ] GC(14) User=0.00s Sys=0.00s Real=0.00s
[1.358s][info][gc,start    ] GC(15) Pause Young (Mixed) (G1 Evacuation Pause)
[1.358s][info][gc,task     ] GC(15) Using 6 workers of 8 for evacuation
[1.359s][info][gc          ] GC(15) To-space exhausted
[1.359s][info][gc,phases   ] GC(15)   Pre Evacuate Collection Set: 0.0ms
[1.359s][info][gc,phases   ] GC(15)   Merge Heap Roots: 0.0ms
[1.359s][info][gc,phases   ] GC(15)   Evacuate Collection Set: 1.2ms
[1.359s][info][gc,phases   ] GC(15)   Post Evacuate Collection Set: 0.2ms
[1.360s][info][gc,phases   ] GC(15)   Other: 0.1ms
[1.360s][info][gc,heap     ] GC(15) Eden regions: 20->0(20)
[1.360s][info][gc,heap     ] GC(15) Survivor regions: 4->3(3)
[1.360s][info][gc,heap     ] GC(15) Old regions: 206->225
[1.360s][info][gc,heap     ] GC(15) Archive regions: 2->2
[1.360s][info][gc,heap     ] GC(15) Humongous regions: 0->0
[1.360s][info][gc,metaspace] GC(15) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.360s][info][gc          ] GC(15) Pause Young (Mixed) (G1 Evacuation Pause) 230M->228M(256M) 1.588ms
[1.360s][info][gc,cpu      ] GC(15) User=0.01s Sys=0.00s Real=0.01s
[1.460s][info][gc,start    ] GC(16) Pause Young (Mixed) (G1 Evacuation Pause)
[1.460s][info][gc,task     ] GC(16) Using 6 workers of 8 for evacuation
[1.461s][info][gc          ] GC(16) To-space exhausted
[1.461s][info][gc,phases   ] GC(16)   Pre Evacuate Collection Set: 0.1ms
[1.461s][info][gc,phases   ] GC(16)   Merge Heap Roots: 0.1ms
[1.461s][info][gc,phases   ] GC(16)   Evacuate Collection Set: 0.4ms
[1.461s][info][gc,phases   ] GC(16)   Post Evacuate Collection Set: 0.3ms
[1.461s][info][gc,phases   ] GC(16)   Other: 0.1ms
[1.461s][info][gc,heap     ] GC(16) Eden regions: 20->0(20)
[1.461s][info][gc,heap     ] GC(16) Survivor regions: 3->2(3)
[1.461s][info][gc,heap     ] GC(16) Old regions: 225->245
[1.461s][info][gc,heap     ] GC(16) Archive regions: 2->2
[1.461s][info][gc,heap     ] GC(16) Humongous regions: 0->0
[1.461s][info][gc,metaspace] GC(16) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.461s][info][gc          ] GC(16) Pause Young (Mixed) (G1 Evacuation Pause) 248M->247M(256M) 1.007ms
[1.461s][info][gc,cpu      ] GC(16) User=0.00s Sys=0.00s Real=0.00s
[1.461s][info][gc,start    ] GC(17) Pause Young (Mixed) (G1 Evacuation Pause)
[1.461s][info][gc,task     ] GC(17) Using 6 workers of 8 for evacuation
[1.462s][info][gc          ] GC(17) To-space exhausted
[1.462s][info][gc,phases   ] GC(17)   Pre Evacuate Collection Set: 0.1ms
[1.462s][info][gc,phases   ] GC(17)   Merge Heap Roots: 0.0ms
[1.462s][info][gc,phases   ] GC(17)   Evacuate Collection Set: 0.2ms
[1.462s][info][gc,phases   ] GC(17)   Post Evacuate Collection Set: 0.3ms
[1.462s][info][gc,phases   ] GC(17)   Other: 0.1ms
[1.462s][info][gc,heap     ] GC(17) Eden regions: 7->0(20)
[1.462s][info][gc,heap     ] GC(17) Survivor regions: 2->0(0)
[1.462s][info][gc,heap     ] GC(17) Old regions: 245->254
[1.462s][info][gc,heap     ] GC(17) Archive regions: 2->2
[1.462s][info][gc,heap     ] GC(17) Humongous regions: 0->0
[1.462s][info][gc,metaspace] GC(17) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.462s][info][gc          ] GC(17) Pause Young (Mixed) (G1 Evacuation Pause) 254M->254M(256M) 0.775ms
[1.462s][info][gc,cpu      ] GC(17) User=0.00s Sys=0.00s Real=0.00s
[1.462s][info][gc,ergo     ] Attempting full compaction
[1.462s][info][gc,start    ] GC(18) Pause Full (G1 Compaction Pause)
[1.462s][info][gc,task     ] GC(18) Using 6 workers of 8 for full compaction
[1.462s][info][gc,phases,start] GC(18) Phase 1: Mark live objects
[1.463s][info][gc,phases      ] GC(18) Phase 1: Mark live objects 0.990ms
[1.463s][info][gc,phases,start] GC(18) Phase 2: Prepare for compaction
[1.464s][info][gc,phases      ] GC(18) Phase 2: Prepare for compaction 0.394ms
[1.464s][info][gc,phases,start] GC(18) Phase 3: Adjust pointers
[1.464s][info][gc,phases      ] GC(18) Phase 3: Adjust pointers 0.531ms
[1.464s][info][gc,phases,start] GC(18) Phase 4: Compact heap
[1.472s][info][gc,phases      ] GC(18) Phase 4: Compact heap 7.926ms
[1.473s][info][gc,heap        ] GC(18) Eden regions: 0->0(12)
[1.473s][info][gc,heap        ] GC(18) Survivor regions: 0->0(0)
[1.473s][info][gc,heap        ] GC(18) Old regions: 254->234
[1.473s][info][gc,heap        ] GC(18) Archive regions: 2->2
[1.473s][info][gc,heap        ] GC(18) Humongous regions: 0->0
[1.473s][info][gc,metaspace   ] GC(18) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.473s][info][gc             ] GC(18) Pause Full (G1 Compaction Pause) 254M->176M(256M) 10.691ms
[1.473s][info][gc,cpu         ] GC(18) User=0.03s Sys=0.01s Real=0.01s
[1.578s][info][gc,start       ] GC(19) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[1.578s][info][gc,task        ] GC(19) Using 6 workers of 8 for evacuation
[1.579s][info][gc,phases      ] GC(19)   Pre Evacuate Collection Set: 0.1ms
[1.579s][info][gc,phases      ] GC(19)   Merge Heap Roots: 0.0ms
[1.579s][info][gc,phases      ] GC(19)   Evacuate Collection Set: 0.3ms
[1.579s][info][gc,phases      ] GC(19)   Post Evacuate Collection Set: 0.2ms
[1.579s][info][gc,phases      ] GC(19)   Other: 0.1ms
[1.579s][info][gc,heap        ] GC(19) Eden regions: 12->0(16)
[1.579s][info][gc,heap        ] GC(19) Survivor regions: 0->2(2)
[1.579s][info][gc,heap        ] GC(19) Old regions: 234->239
[1.579s][info][gc,heap        ] GC(19) Archive regions: 2->2
[1.579s][info][gc,heap        ] GC(19) Humongous regions: 0->0
[1.579s][info][gc,metaspace   ] GC(19) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.579s][info][gc             ] GC(19) Pause Young (Concurrent Start) (G1 Evacuation Pause) 187M->182M(256M) 0.827ms
[1.579s][info][gc,cpu         ] GC(19) User=0.00s Sys=0.00s Real=0.00s
[1.579s][info][gc             ] GC(20) Concurrent Mark Cycle
[1.579s][info][gc,marking     ] GC(20) Concurrent Clear Claimed Marks
[1.579s][info][gc,marking     ] GC(20) Concurrent Clear Claimed Marks 0.005ms
[1.579s][info][gc,marking     ] GC(20) Concurrent Scan Root Regions
[1.579s][info][gc,marking     ] GC(20) Concurrent Scan Root Regions 0.036ms
[1.579s][info][gc,marking     ] GC(20) Concurrent Mark
[1.579s][info][gc,marking     ] GC(20) Concurrent Mark From Roots
[1.579s][info][gc,task        ] GC(20) Using 2 workers of 2 for marking
[1.580s][info][gc,start       ] GC(21) Pause Young (Normal) (G1 Evacuation Pause)
[1.580s][info][gc,task        ] GC(21) Using 6 workers of 8 for evacuation
[1.580s][info][gc             ] GC(21) To-space exhausted
[1.580s][info][gc,phases      ] GC(21)   Pre Evacuate Collection Set: 0.1ms
[1.580s][info][gc,phases      ] GC(21)   Merge Heap Roots: 0.1ms
[1.580s][info][gc,phases      ] GC(21)   Evacuate Collection Set: 0.1ms
[1.580s][info][gc,phases      ] GC(21)   Post Evacuate Collection Set: 0.1ms
[1.580s][info][gc,phases      ] GC(21)   Other: 0.1ms
[1.580s][info][gc,heap        ] GC(21) Eden regions: 13->0(16)
[1.580s][info][gc,heap        ] GC(21) Survivor regions: 2->0(0)
[1.580s][info][gc,heap        ] GC(21) Old regions: 239->254
[1.580s][info][gc,heap        ] GC(21) Archive regions: 2->2
[1.580s][info][gc,heap        ] GC(21) Humongous regions: 0->0
[1.580s][info][gc,metaspace   ] GC(21) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.580s][info][gc             ] GC(21) Pause Young (Normal) (G1 Evacuation Pause) 195M->195M(256M) 0.472ms
[1.580s][info][gc,cpu         ] GC(21) User=0.01s Sys=0.00s Real=0.00s
[1.580s][info][gc,ergo        ] Attempting full compaction
[1.580s][info][gc,start       ] GC(22) Pause Full (G1 Compaction Pause)
[1.580s][info][gc,task        ] GC(22) Using 6 workers of 8 for full compaction
[1.580s][info][gc,phases,start] GC(22) Phase 1: Mark live objects
[1.581s][info][gc,phases      ] GC(22) Phase 1: Mark live objects 0.859ms
[1.581s][info][gc,phases,start] GC(22) Phase 2: Prepare for compaction
[1.581s][info][gc,phases      ] GC(22) Phase 2: Prepare for compaction 0.178ms
[1.581s][info][gc,phases,start] GC(22) Phase 3: Adjust pointers
[1.582s][info][gc,phases      ] GC(22) Phase 3: Adjust pointers 0.522ms
[1.582s][info][gc,phases,start] GC(22) Phase 4: Compact heap
[1.586s][info][gc,phases      ] GC(22) Phase 4: Compact heap 4.593ms
[1.587s][info][gc,heap        ] GC(22) Eden regions: 0->0(12)
[1.587s][info][gc,heap        ] GC(22) Survivor regions: 0->0(0)
[1.587s][info][gc,heap        ] GC(22) Old regions: 254->246
[1.587s][info][gc,heap        ] GC(22) Archive regions: 2->2
[1.587s][info][gc,heap        ] GC(22) Humongous regions: 0->0
[1.587s][info][gc,metaspace   ] GC(22) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.587s][info][gc             ] GC(22) Pause Full (G1 Compaction Pause) 195M->185M(256M) 7.067ms
[1.587s][info][gc,cpu         ] GC(22) User=0.01s Sys=0.00s Real=0.00s
[1.587s][info][gc,marking     ] GC(20) Concurrent Mark From Roots 7.833ms
[1.587s][info][gc,marking     ] GC(20) Concurrent Mark Abort
[1.587s][info][gc             ] GC(20) Concurrent Mark Cycle 7.940ms
[1.587s][info][gc,start       ] GC(23) Pause Young (Normal) (G1 Evacuation Pause)
[1.587s][info][gc,task        ] GC(23) Using 6 workers of 8 for evacuation
[1.588s][info][gc             ] GC(23) To-space exhausted
[1.588s][info][gc,phases      ] GC(23)   Pre Evacuate Collection Set: 0.0ms
[1.588s][info][gc,phases      ] GC(23)   Merge Heap Roots: 0.0ms
[1.588s][info][gc,phases      ] GC(23)   Evacuate Collection Set: 0.1ms
[1.588s][info][gc,phases      ] GC(23)   Post Evacuate Collection Set: 0.2ms
[1.588s][info][gc,phases      ] GC(23)   Other: 0.1ms
[1.588s][info][gc,heap        ] GC(23) Eden regions: 8->0(16)
[1.588s][info][gc,heap        ] GC(23) Survivor regions: 0->0(0)
[1.588s][info][gc,heap        ] GC(23) Old regions: 246->254
[1.588s][info][gc,heap        ] GC(23) Archive regions: 2->2
[1.588s][info][gc,heap        ] GC(23) Humongous regions: 0->0
[1.588s][info][gc,metaspace   ] GC(23) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.588s][info][gc             ] GC(23) Pause Young (Normal) (G1 Evacuation Pause) 193M->193M(256M) 0.450ms
[1.588s][info][gc,cpu         ] GC(23) User=0.00s Sys=0.00s Real=0.00s
[1.588s][info][gc,ergo        ] Attempting full compaction
[1.588s][info][gc,start       ] GC(24) Pause Full (G1 Compaction Pause)
[1.588s][info][gc,task        ] GC(24) Using 6 workers of 8 for full compaction
[1.588s][info][gc,phases,start] GC(24) Phase 1: Mark live objects
[1.589s][info][gc,phases      ] GC(24) Phase 1: Mark live objects 0.830ms
[1.589s][info][gc,phases,start] GC(24) Phase 2: Prepare for compaction
[1.589s][info][gc,phases      ] GC(24) Phase 2: Prepare for compaction 0.168ms
[1.589s][info][gc,phases,start] GC(24) Phase 3: Adjust pointers
[1.589s][info][gc,phases      ] GC(24) Phase 3: Adjust pointers 0.330ms
[1.589s][info][gc,phases,start] GC(24) Phase 4: Compact heap
[1.592s][info][gc,phases      ] GC(24) Phase 4: Compact heap 2.758ms
[1.593s][info][gc,heap        ] GC(24) Eden regions: 0->0(12)
[1.593s][info][gc,heap        ] GC(24) Survivor regions: 0->0(0)
[1.593s][info][gc,heap        ] GC(24) Old regions: 254->250
[1.593s][info][gc,heap        ] GC(24) Archive regions: 2->2
[1.593s][info][gc,heap        ] GC(24) Humongous regions: 0->0
[1.593s][info][gc,metaspace   ] GC(24) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.593s][info][gc             ] GC(24) Pause Full (G1 Compaction Pause) 193M->188M(256M) 4.768ms
[1.593s][info][gc,cpu         ] GC(24) User=0.01s Sys=0.00s Real=0.01s
[1.593s][info][gc,start       ] GC(25) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[1.593s][info][gc,task        ] GC(25) Using 6 workers of 8 for evacuation
[1.593s][info][gc             ] GC(25) To-space exhausted
[1.593s][info][gc,phases      ] GC(25)   Pre Evacuate Collection Set: 0.0ms
[1.593s][info][gc,phases      ] GC(25)   Merge Heap Roots: 0.0ms
[1.593s][info][gc,phases      ] GC(25)   Evacuate Collection Set: 0.1ms
[1.593s][info][gc,phases      ] GC(25)   Post Evacuate Collection Set: 0.2ms
[1.593s][info][gc,phases      ] GC(25)   Other: 0.1ms
[1.593s][info][gc,heap        ] GC(25) Eden regions: 4->0(16)
[1.593s][info][gc,heap        ] GC(25) Survivor regions: 0->0(0)
[1.593s][info][gc,heap        ] GC(25) Old regions: 250->254
[1.593s][info][gc,heap        ] GC(25) Archive regions: 2->2
[1.593s][info][gc,heap        ] GC(25) Humongous regions: 0->0
[1.593s][info][gc,metaspace   ] GC(25) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.593s][info][gc             ] GC(25) Pause Young (Concurrent Start) (G1 Evacuation Pause) 192M->192M(256M) 0.504ms
[1.593s][info][gc,cpu         ] GC(25) User=0.00s Sys=0.00s Real=0.00s
[1.593s][info][gc,ergo        ] Attempting full compaction
[1.593s][info][gc,start       ] GC(26) Pause Full (G1 Compaction Pause)
[1.593s][info][gc,task        ] GC(26) Using 6 workers of 8 for full compaction
[1.593s][info][gc             ] GC(27) Concurrent Mark Cycle
[1.593s][info][gc,marking     ] GC(27) Concurrent Clear Claimed Marks
[1.593s][info][gc,marking     ] GC(27) Concurrent Clear Claimed Marks 0.004ms
[1.593s][info][gc,marking     ] GC(27) Concurrent Scan Root Regions
[1.593s][info][gc,marking     ] GC(27) Concurrent Scan Root Regions 0.003ms
[1.593s][info][gc,marking     ] GC(27) Concurrent Mark
[1.593s][info][gc,marking     ] GC(27) Concurrent Mark From Roots
[1.593s][info][gc,task        ] GC(27) Using 2 workers of 2 for marking
[1.593s][info][gc,phases,start] GC(26) Phase 1: Mark live objects
[1.594s][info][gc,phases      ] GC(26) Phase 1: Mark live objects 0.658ms
[1.594s][info][gc,phases,start] GC(26) Phase 2: Prepare for compaction
[1.594s][info][gc,phases      ] GC(26) Phase 2: Prepare for compaction 0.149ms
[1.594s][info][gc,phases,start] GC(26) Phase 3: Adjust pointers
[1.595s][info][gc,phases      ] GC(26) Phase 3: Adjust pointers 0.340ms
[1.595s][info][gc,phases,start] GC(26) Phase 4: Compact heap
[1.595s][info][gc,phases      ] GC(26) Phase 4: Compact heap 0.152ms
[1.595s][info][gc,heap        ] GC(26) Eden regions: 0->0(12)
[1.595s][info][gc,heap        ] GC(26) Survivor regions: 0->0(0)
[1.595s][info][gc,heap        ] GC(26) Old regions: 254->252
[1.595s][info][gc,heap        ] GC(26) Archive regions: 2->2
[1.595s][info][gc,heap        ] GC(26) Humongous regions: 0->0
[1.595s][info][gc,metaspace   ] GC(26) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.595s][info][gc             ] GC(26) Pause Full (G1 Compaction Pause) 192M->190M(256M) 1.949ms
[1.595s][info][gc,cpu         ] GC(26) User=0.01s Sys=0.00s Real=0.00s
[1.595s][info][gc,marking     ] GC(27) Concurrent Mark From Roots 1.955ms
[1.595s][info][gc,marking     ] GC(27) Concurrent Mark Abort
[1.595s][info][gc             ] GC(27) Concurrent Mark Cycle 1.995ms
[1.595s][info][gc,start       ] GC(28) Pause Young (Normal) (G1 Evacuation Pause)
[1.595s][info][gc,task        ] GC(28) Using 6 workers of 8 for evacuation
[1.596s][info][gc             ] GC(28) To-space exhausted
[1.596s][info][gc,phases      ] GC(28)   Pre Evacuate Collection Set: 0.1ms
[1.596s][info][gc,phases      ] GC(28)   Merge Heap Roots: 0.0ms
[1.596s][info][gc,phases      ] GC(28)   Evacuate Collection Set: 0.1ms
[1.596s][info][gc,phases      ] GC(28)   Post Evacuate Collection Set: 0.1ms
[1.596s][info][gc,phases      ] GC(28)   Other: 0.0ms
[1.596s][info][gc,heap        ] GC(28) Eden regions: 2->0(16)
[1.596s][info][gc,heap        ] GC(28) Survivor regions: 0->0(0)
[1.596s][info][gc,heap        ] GC(28) Old regions: 252->254
[1.596s][info][gc,heap        ] GC(28) Archive regions: 2->2
[1.596s][info][gc,heap        ] GC(28) Humongous regions: 0->0
[1.596s][info][gc,metaspace   ] GC(28) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.596s][info][gc             ] GC(28) Pause Young (Normal) (G1 Evacuation Pause) 191M->191M(256M) 0.426ms
[1.596s][info][gc,cpu         ] GC(28) User=0.00s Sys=0.00s Real=0.00s
[1.596s][info][gc,ergo        ] Attempting full compaction
[1.596s][info][gc,start       ] GC(29) Pause Full (G1 Compaction Pause)
[1.596s][info][gc,task        ] GC(29) Using 6 workers of 8 for full compaction
[1.596s][info][gc,phases,start] GC(29) Phase 1: Mark live objects
[1.596s][info][gc,phases      ] GC(29) Phase 1: Mark live objects 0.671ms
[1.597s][info][gc,phases,start] GC(29) Phase 2: Prepare for compaction
[1.597s][info][gc,phases      ] GC(29) Phase 2: Prepare for compaction 0.121ms
[1.597s][info][gc,phases,start] GC(29) Phase 3: Adjust pointers
[1.597s][info][gc,phases      ] GC(29) Phase 3: Adjust pointers 0.303ms
[1.597s][info][gc,phases,start] GC(29) Phase 4: Compact heap
[1.597s][info][gc,phases      ] GC(29) Phase 4: Compact heap 0.155ms
[1.597s][info][gc,heap        ] GC(29) Eden regions: 0->0(12)
[1.597s][info][gc,heap        ] GC(29) Survivor regions: 0->0(0)
[1.597s][info][gc,heap        ] GC(29) Old regions: 254->253
[1.597s][info][gc,heap        ] GC(29) Archive regions: 2->2
[1.597s][info][gc,heap        ] GC(29) Humongous regions: 0->0
[1.598s][info][gc,metaspace   ] GC(29) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.598s][info][gc             ] GC(29) Pause Full (G1 Compaction Pause) 191M->190M(256M) 1.741ms
[1.598s][info][gc,cpu         ] GC(29) User=0.00s Sys=0.00s Real=0.00s
[1.598s][info][gc,start       ] GC(30) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[1.598s][info][gc,task        ] GC(30) Using 6 workers of 8 for evacuation
[1.598s][info][gc             ] GC(30) To-space exhausted
[1.598s][info][gc,phases      ] GC(30)   Pre Evacuate Collection Set: 0.1ms
[1.598s][info][gc,phases      ] GC(30)   Merge Heap Roots: 0.0ms
[1.598s][info][gc,phases      ] GC(30)   Evacuate Collection Set: 0.2ms
[1.598s][info][gc,phases      ] GC(30)   Post Evacuate Collection Set: 0.1ms
[1.598s][info][gc,phases      ] GC(30)   Other: 0.1ms
[1.598s][info][gc,heap        ] GC(30) Eden regions: 1->0(16)
[1.598s][info][gc,heap        ] GC(30) Survivor regions: 0->0(0)
[1.598s][info][gc,heap        ] GC(30) Old regions: 253->254
[1.598s][info][gc,heap        ] GC(30) Archive regions: 2->2
[1.598s][info][gc,heap        ] GC(30) Humongous regions: 0->0
[1.598s][info][gc,metaspace   ] GC(30) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.598s][info][gc             ] GC(30) Pause Young (Concurrent Start) (G1 Evacuation Pause) 191M->191M(256M) 0.480ms
[1.598s][info][gc,cpu         ] GC(30) User=0.00s Sys=0.00s Real=0.00s
[1.598s][info][gc,ergo        ] Attempting full compaction
[1.598s][info][gc,start       ] GC(31) Pause Full (G1 Compaction Pause)
[1.598s][info][gc             ] GC(32) Concurrent Mark Cycle
[1.598s][info][gc,task        ] GC(31) Using 6 workers of 8 for full compaction
[1.598s][info][gc,marking     ] GC(32) Concurrent Clear Claimed Marks
[1.598s][info][gc,marking     ] GC(32) Concurrent Clear Claimed Marks 0.045ms
[1.598s][info][gc,marking     ] GC(32) Concurrent Scan Root Regions
[1.598s][info][gc,marking     ] GC(32) Concurrent Scan Root Regions 0.003ms
[1.598s][info][gc,marking     ] GC(32) Concurrent Mark
[1.598s][info][gc,marking     ] GC(32) Concurrent Mark From Roots
[1.598s][info][gc,task        ] GC(32) Using 2 workers of 2 for marking
[1.598s][info][gc,phases,start] GC(31) Phase 1: Mark live objects
[1.599s][info][gc,phases      ] GC(31) Phase 1: Mark live objects 0.712ms
[1.599s][info][gc,phases,start] GC(31) Phase 2: Prepare for compaction
[1.599s][info][gc,phases      ] GC(31) Phase 2: Prepare for compaction 0.110ms
[1.599s][info][gc,phases,start] GC(31) Phase 3: Adjust pointers
[1.599s][info][gc,phases      ] GC(31) Phase 3: Adjust pointers 0.279ms
[1.599s][info][gc,phases,start] GC(31) Phase 4: Compact heap
[1.600s][info][gc,phases      ] GC(31) Phase 4: Compact heap 0.148ms
[1.600s][info][gc,heap        ] GC(31) Eden regions: 0->0(12)
[1.600s][info][gc,heap        ] GC(31) Survivor regions: 0->0(0)
[1.600s][info][gc,heap        ] GC(31) Old regions: 254->252
[1.600s][info][gc,heap        ] GC(31) Archive regions: 2->2
[1.600s][info][gc,heap        ] GC(31) Humongous regions: 0->0
[1.600s][info][gc,metaspace   ] GC(31) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.600s][info][gc             ] GC(31) Pause Full (G1 Compaction Pause) 191M->191M(256M) 1.850ms
[1.600s][info][gc,cpu         ] GC(31) User=0.01s Sys=0.01s Real=0.01s
[1.600s][info][gc,marking     ] GC(32) Concurrent Mark From Roots 1.816ms
[1.600s][info][gc,marking     ] GC(32) Concurrent Mark Abort
[1.600s][info][gc             ] GC(32) Concurrent Mark Cycle 1.891ms
[1.600s][info][gc,start       ] GC(33) Pause Young (Normal) (G1 Evacuation Pause)
[1.600s][info][gc,task        ] GC(33) Using 6 workers of 8 for evacuation
[1.600s][info][gc             ] GC(33) To-space exhausted
[1.600s][info][gc,phases      ] GC(33)   Pre Evacuate Collection Set: 0.1ms
[1.600s][info][gc,phases      ] GC(33)   Merge Heap Roots: 0.0ms
[1.600s][info][gc,phases      ] GC(33)   Evacuate Collection Set: 0.1ms
[1.600s][info][gc,phases      ] GC(33)   Post Evacuate Collection Set: 0.1ms
[1.600s][info][gc,phases      ] GC(33)   Other: 0.0ms
[1.600s][info][gc,heap        ] GC(33) Eden regions: 2->0(16)
[1.600s][info][gc,heap        ] GC(33) Survivor regions: 0->0(0)
[1.600s][info][gc,heap        ] GC(33) Old regions: 252->254
[1.600s][info][gc,heap        ] GC(33) Archive regions: 2->2
[1.600s][info][gc,heap        ] GC(33) Humongous regions: 0->0
[1.600s][info][gc,metaspace   ] GC(33) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.600s][info][gc             ] GC(33) Pause Young (Normal) (G1 Evacuation Pause) 192M->192M(256M) 0.348ms
[1.600s][info][gc,cpu         ] GC(33) User=0.00s Sys=0.00s Real=0.00s
[1.600s][info][gc,ergo        ] Attempting full compaction
[1.600s][info][gc,start       ] GC(34) Pause Full (G1 Compaction Pause)
[1.600s][info][gc,task        ] GC(34) Using 6 workers of 8 for full compaction
[1.600s][info][gc,phases,start] GC(34) Phase 1: Mark live objects
[1.601s][info][gc,phases      ] GC(34) Phase 1: Mark live objects 0.596ms
[1.601s][info][gc,phases,start] GC(34) Phase 2: Prepare for compaction
[1.601s][info][gc,phases      ] GC(34) Phase 2: Prepare for compaction 0.123ms
[1.601s][info][gc,phases,start] GC(34) Phase 3: Adjust pointers
[1.601s][info][gc,phases      ] GC(34) Phase 3: Adjust pointers 0.289ms
[1.601s][info][gc,phases,start] GC(34) Phase 4: Compact heap
[1.602s][info][gc,phases      ] GC(34) Phase 4: Compact heap 0.252ms
[1.602s][info][gc,heap        ] GC(34) Eden regions: 0->0(12)
[1.602s][info][gc,heap        ] GC(34) Survivor regions: 0->0(0)
[1.602s][info][gc,heap        ] GC(34) Old regions: 254->253
[1.602s][info][gc,heap        ] GC(34) Archive regions: 2->2
[1.602s][info][gc,heap        ] GC(34) Humongous regions: 0->0
[1.602s][info][gc,metaspace   ] GC(34) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.602s][info][gc             ] GC(34) Pause Full (G1 Compaction Pause) 192M->191M(256M) 1.799ms
[1.602s][info][gc,cpu         ] GC(34) User=0.00s Sys=0.00s Real=0.00s
[1.707s][info][gc,start       ] GC(35) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[1.707s][info][gc,task        ] GC(35) Using 6 workers of 8 for evacuation
[1.708s][info][gc             ] GC(35) To-space exhausted
[1.708s][info][gc,phases      ] GC(35)   Pre Evacuate Collection Set: 0.1ms
[1.708s][info][gc,phases      ] GC(35)   Merge Heap Roots: 0.0ms
[1.708s][info][gc,phases      ] GC(35)   Evacuate Collection Set: 0.1ms
[1.708s][info][gc,phases      ] GC(35)   Post Evacuate Collection Set: 0.1ms
[1.708s][info][gc,phases      ] GC(35)   Other: 0.1ms
[1.708s][info][gc,heap        ] GC(35) Eden regions: 1->0(16)
[1.708s][info][gc,heap        ] GC(35) Survivor regions: 0->0(0)
[1.708s][info][gc,heap        ] GC(35) Old regions: 253->254
[1.708s][info][gc,heap        ] GC(35) Archive regions: 2->2
[1.708s][info][gc,heap        ] GC(35) Humongous regions: 0->0
[1.708s][info][gc,metaspace   ] GC(35) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.708s][info][gc             ] GC(35) Pause Young (Concurrent Start) (G1 Evacuation Pause) 192M->192M(256M) 0.467ms
[1.708s][info][gc,cpu         ] GC(35) User=0.00s Sys=0.00s Real=0.00s
[1.708s][info][gc,ergo        ] Attempting full compaction
[1.708s][info][gc             ] GC(36) Concurrent Mark Cycle
[1.708s][info][gc,marking     ] GC(36) Concurrent Clear Claimed Marks
[1.708s][info][gc,marking     ] GC(36) Concurrent Clear Claimed Marks 0.004ms
[1.708s][info][gc,marking     ] GC(36) Concurrent Scan Root Regions
[1.708s][info][gc,marking     ] GC(36) Concurrent Scan Root Regions 0.007ms
[1.708s][info][gc,start       ] GC(37) Pause Full (G1 Compaction Pause)
[1.708s][info][gc,task        ] GC(37) Using 6 workers of 8 for full compaction
[1.708s][info][gc,marking     ] GC(36) Concurrent Mark
[1.708s][info][gc,marking     ] GC(36) Concurrent Mark From Roots
[1.708s][info][gc,task        ] GC(36) Using 2 workers of 2 for marking
[1.708s][info][gc,phases,start] GC(37) Phase 1: Mark live objects
[1.709s][info][gc,phases      ] GC(37) Phase 1: Mark live objects 0.575ms
[1.709s][info][gc,phases,start] GC(37) Phase 2: Prepare for compaction
[1.709s][info][gc,phases      ] GC(37) Phase 2: Prepare for compaction 0.136ms
[1.709s][info][gc,phases,start] GC(37) Phase 3: Adjust pointers
[1.709s][info][gc,phases      ] GC(37) Phase 3: Adjust pointers 0.278ms
[1.709s][info][gc,phases,start] GC(37) Phase 4: Compact heap
[1.709s][info][gc,phases      ] GC(37) Phase 4: Compact heap 0.234ms
[1.710s][info][gc,heap        ] GC(37) Eden regions: 0->0(12)
[1.710s][info][gc,heap        ] GC(37) Survivor regions: 0->0(0)
[1.710s][info][gc,heap        ] GC(37) Old regions: 254->253
[1.710s][info][gc,heap        ] GC(37) Archive regions: 2->2
[1.710s][info][gc,heap        ] GC(37) Humongous regions: 0->0
[1.710s][info][gc,metaspace   ] GC(37) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.710s][info][gc             ] GC(37) Pause Full (G1 Compaction Pause) 192M->192M(256M) 1.793ms
[1.710s][info][gc,cpu         ] GC(37) User=0.01s Sys=0.00s Real=0.01s
[1.710s][info][gc,marking     ] GC(36) Concurrent Mark From Roots 1.782ms
[1.710s][info][gc,marking     ] GC(36) Concurrent Mark Abort
[1.710s][info][gc             ] GC(36) Concurrent Mark Cycle 1.849ms
[1.710s][info][gc,start       ] GC(38) Pause Young (Normal) (G1 Evacuation Pause)
[1.710s][info][gc,task        ] GC(38) Using 6 workers of 8 for evacuation
[1.710s][info][gc             ] GC(38) To-space exhausted
[1.710s][info][gc,phases      ] GC(38)   Pre Evacuate Collection Set: 0.1ms
[1.710s][info][gc,phases      ] GC(38)   Merge Heap Roots: 0.0ms
[1.710s][info][gc,phases      ] GC(38)   Evacuate Collection Set: 0.1ms
[1.710s][info][gc,phases      ] GC(38)   Post Evacuate Collection Set: 0.1ms
[1.710s][info][gc,phases      ] GC(38)   Other: 0.0ms
[1.710s][info][gc,heap        ] GC(38) Eden regions: 1->0(16)
[1.710s][info][gc,heap        ] GC(38) Survivor regions: 0->0(0)
[1.710s][info][gc,heap        ] GC(38) Old regions: 253->254
[1.710s][info][gc,heap        ] GC(38) Archive regions: 2->2
[1.710s][info][gc,heap        ] GC(38) Humongous regions: 0->0
[1.710s][info][gc,metaspace   ] GC(38) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.710s][info][gc             ] GC(38) Pause Young (Normal) (G1 Evacuation Pause) 193M->193M(256M) 0.313ms
[1.710s][info][gc,cpu         ] GC(38) User=0.00s Sys=0.00s Real=0.00s
[1.710s][info][gc,ergo        ] Attempting full compaction
[1.710s][info][gc,start       ] GC(39) Pause Full (G1 Compaction Pause)
[1.710s][info][gc,task        ] GC(39) Using 6 workers of 8 for full compaction
[1.710s][info][gc,phases,start] GC(39) Phase 1: Mark live objects
[1.711s][info][gc,phases      ] GC(39) Phase 1: Mark live objects 0.522ms
[1.711s][info][gc,phases,start] GC(39) Phase 2: Prepare for compaction
[1.711s][info][gc,phases      ] GC(39) Phase 2: Prepare for compaction 0.127ms
[1.711s][info][gc,phases,start] GC(39) Phase 3: Adjust pointers
[1.711s][info][gc,phases      ] GC(39) Phase 3: Adjust pointers 0.231ms
[1.711s][info][gc,phases,start] GC(39) Phase 4: Compact heap
[1.711s][info][gc,phases      ] GC(39) Phase 4: Compact heap 0.105ms
[1.711s][info][gc,heap        ] GC(39) Eden regions: 0->0(12)
[1.711s][info][gc,heap        ] GC(39) Survivor regions: 0->0(0)
[1.711s][info][gc,heap        ] GC(39) Old regions: 254->254
[1.711s][info][gc,heap        ] GC(39) Archive regions: 2->2
[1.711s][info][gc,heap        ] GC(39) Humongous regions: 0->0
[1.711s][info][gc,metaspace   ] GC(39) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.711s][info][gc             ] GC(39) Pause Full (G1 Compaction Pause) 193M->192M(256M) 1.336ms
[1.711s][info][gc,cpu         ] GC(39) User=0.00s Sys=0.00s Real=0.00s
[1.711s][info][gc,ergo        ] Attempting maximum full compaction clearing soft references
[1.711s][info][gc,start       ] GC(40) Pause Full (G1 Compaction Pause)
[1.711s][info][gc,task        ] GC(40) Using 6 workers of 8 for full compaction
[1.711s][info][gc,phases,start] GC(40) Phase 1: Mark live objects
[1.712s][info][gc,phases      ] GC(40) Phase 1: Mark live objects 0.682ms
[1.712s][info][gc,phases,start] GC(40) Phase 2: Prepare for compaction
[1.712s][info][gc,phases      ] GC(40) Phase 2: Prepare for compaction 0.133ms
[1.712s][info][gc,phases,start] GC(40) Phase 3: Adjust pointers
[1.712s][info][gc,phases      ] GC(40) Phase 3: Adjust pointers 0.281ms
[1.712s][info][gc,phases,start] GC(40) Phase 4: Compact heap
[1.713s][info][gc,phases      ] GC(40) Phase 4: Compact heap 0.314ms
[1.713s][info][gc,heap        ] GC(40) Eden regions: 0->0(12)
[1.713s][info][gc,heap        ] GC(40) Survivor regions: 0->0(0)
[1.713s][info][gc,heap        ] GC(40) Old regions: 254->254
[1.713s][info][gc,heap        ] GC(40) Archive regions: 2->2
[1.713s][info][gc,heap        ] GC(40) Humongous regions: 0->0
[1.713s][info][gc,metaspace   ] GC(40) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.713s][info][gc             ] GC(40) Pause Full (G1 Compaction Pause) 192M->192M(256M) 1.970ms
[1.713s][info][gc,cpu         ] GC(40) User=0.01s Sys=0.00s Real=0.00s
[1.713s][info][gc,start       ] GC(41) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[1.713s][info][gc,task        ] GC(41) Using 6 workers of 8 for evacuation
[1.714s][info][gc,phases      ] GC(41)   Pre Evacuate Collection Set: 0.0ms
[1.714s][info][gc,phases      ] GC(41)   Merge Heap Roots: 0.0ms
[1.714s][info][gc,phases      ] GC(41)   Evacuate Collection Set: 0.1ms
[1.714s][info][gc,phases      ] GC(41)   Post Evacuate Collection Set: 0.1ms
[1.714s][info][gc,phases      ] GC(41)   Other: 0.0ms
[1.714s][info][gc,heap        ] GC(41) Eden regions: 0->0(12)
[1.714s][info][gc,heap        ] GC(41) Survivor regions: 0->0(0)
[1.714s][info][gc,heap        ] GC(41) Old regions: 254->254
[1.714s][info][gc,heap        ] GC(41) Archive regions: 2->2
[1.714s][info][gc,heap        ] GC(41) Humongous regions: 0->0
[1.714s][info][gc,metaspace   ] GC(41) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.714s][info][gc             ] GC(41) Pause Young (Concurrent Start) (G1 Evacuation Pause) 192M->192M(256M) 0.280ms
[1.714s][info][gc,cpu         ] GC(41) User=0.00s Sys=0.00s Real=0.00s
[1.714s][info][gc,ergo        ] Attempting full compaction
[1.714s][info][gc,start       ] GC(42) Pause Full (G1 Compaction Pause)
[1.714s][info][gc,task        ] GC(42) Using 6 workers of 8 for full compaction
[1.714s][info][gc             ] GC(43) Concurrent Mark Cycle
[1.714s][info][gc,marking     ] GC(43) Concurrent Clear Claimed Marks
[1.714s][info][gc,marking     ] GC(43) Concurrent Clear Claimed Marks 0.003ms
[1.714s][info][gc,marking     ] GC(43) Concurrent Scan Root Regions
[1.714s][info][gc,marking     ] GC(43) Concurrent Scan Root Regions 0.002ms
[1.714s][info][gc,marking     ] GC(43) Concurrent Mark
[1.714s][info][gc,marking     ] GC(43) Concurrent Mark From Roots
[1.714s][info][gc,task        ] GC(43) Using 2 workers of 2 for marking
[1.714s][info][gc,phases,start] GC(42) Phase 1: Mark live objects
[1.714s][info][gc,phases      ] GC(42) Phase 1: Mark live objects 0.541ms
[1.714s][info][gc,phases,start] GC(42) Phase 2: Prepare for compaction
[1.715s][info][gc,phases      ] GC(42) Phase 2: Prepare for compaction 0.149ms
[1.715s][info][gc,phases,start] GC(42) Phase 3: Adjust pointers
[1.715s][info][gc,phases      ] GC(42) Phase 3: Adjust pointers 0.314ms
[1.715s][info][gc,phases,start] GC(42) Phase 4: Compact heap
[1.715s][info][gc,phases      ] GC(42) Phase 4: Compact heap 0.227ms
[1.716s][info][gc,heap        ] GC(42) Eden regions: 0->0(12)
[1.716s][info][gc,heap        ] GC(42) Survivor regions: 0->0(0)
[1.716s][info][gc,heap        ] GC(42) Old regions: 254->253
[1.716s][info][gc,heap        ] GC(42) Archive regions: 2->2
[1.716s][info][gc,heap        ] GC(42) Humongous regions: 0->0
[1.716s][info][gc,metaspace   ] GC(42) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.716s][info][gc             ] GC(42) Pause Full (G1 Compaction Pause) 192M->192M(256M) 1.887ms
[1.716s][info][gc,cpu         ] GC(42) User=0.00s Sys=0.00s Real=0.00s
[1.716s][info][gc,marking     ] GC(43) Concurrent Mark From Roots 1.966ms
[1.716s][info][gc,marking     ] GC(43) Concurrent Mark Abort
[1.716s][info][gc             ] GC(43) Concurrent Mark Cycle 2.007ms
[1.716s][info][gc,heap,exit   ] Heap
[1.716s][info][gc,heap,exit   ]  garbage-first heap   total 262144K, used 197425K [0x00000007f0000000, 0x0000000800000000)
[1.716s][info][gc,heap,exit   ]   region size 1024K, 1 young (1024K), 0 survivors (0K)
[1.716s][info][gc,heap,exit   ]  Metaspace       used 801K, committed 960K, reserved 1114112K
[1.716s][info][gc,heap,exit   ]   class space    used 58K, committed 128K, reserved 1048576K
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
	at g1.test.RegionExample1.main(RegionExample1.java:17)

我们详细分析下日志。

这是普通YGC日志:关键字“Pause Young (Normal)”
从Root引用对象的分区开始扫描: 关键字“Concurrent Scan Root Regions”
标记root引用对象的分区:关键字“Concurrent Mark From Roots”

[0.074s][info][gc,start    ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[0.074s][info][gc,task     ] GC(0) Using 6 workers of 8 for evacuation
[0.076s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.076s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms
[0.076s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 1.3ms
[0.076s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.1ms
[0.076s][info][gc,phases   ] GC(0)   Other: 0.3ms
[0.076s][info][gc,heap     ] GC(0) Eden regions: 23->0(19)
[0.076s][info][gc,heap     ] GC(0) Survivor regions: 0->3(3)
[0.076s][info][gc,heap     ] GC(0) Old regions: 0->9
[0.076s][info][gc,heap     ] GC(0) Archive regions: 2->2
[0.076s][info][gc,heap     ] GC(0) Humongous regions: 0->0
[0.076s][info][gc,metaspace] GC(0) Metaspace: 510K(704K)->510K(704K) NonClass: 485K(576K)->485K(576K) Class: 24K(128K)->24K(128K)
[0.076s][info][gc          ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 23M->12M(256M) 1.822ms

这是并发标记日志:关键字“准备进入 Mixed GC 阶段”

[0.929s][info][gc,start    ] GC(6) Pause Young (Concurrent Start) (G1 Evacuation Pause)
[0.929s][info][gc,task     ] GC(6) Using 6 workers of 8 for evacuation
[0.932s][info][gc,phases   ] GC(6)   Pre Evacuate Collection Set: 0.0ms
[0.932s][info][gc,phases   ] GC(6)   Merge Heap Roots: 0.0ms
[0.932s][info][gc,phases   ] GC(6)   Evacuate Collection Set: 2.4ms
[0.932s][info][gc,phases   ] GC(6)   Post Evacuate Collection Set: 0.1ms
[0.932s][info][gc,phases   ] GC(6)   Other: 0.1ms
[0.932s][info][gc,heap     ] GC(6) Eden regions: 47->0(38)
[0.932s][info][gc,heap     ] GC(6) Survivor regions: 9->7(7)
[0.932s][info][gc,heap     ] GC(6) Old regions: 119->144
[0.932s][info][gc,heap     ] GC(6) Archive regions: 2->2
[0.932s][info][gc,heap     ] GC(6) Humongous regions: 0->0
[0.932s][info][gc,metaspace] GC(6) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[0.932s][info][gc          ] GC(6) Pause Young (Concurrent Start) (G1 Evacuation Pause) 174M->151M(256M) 2.798ms

重新建立region的停顿预测模型RSet(Remembered Set):关键字“Concurrent Rebuild Remembered Sets”

[0.934s][info][gc,marking  ] GC(7) Concurrent Mark 1.233ms
[0.934s][info][gc,marking  ] GC(7) Concurrent Rebuild Remembered Sets
[0.934s][info][gc,marking  ] GC(7) Concurrent Rebuild Remembered Sets 0.410ms
[0.934s][info][gc,start    ] GC(7) Pause Cleanup
[0.934s][info][gc          ] GC(7) Pause Cleanup 157M->157M(256M) 0.058ms
[0.934s][info][gc,cpu      ] GC(7) User=0.00s Sys=0.00s Real=0.00s
[0.934s][info][gc,marking  ] GC(7) Concurrent Cleanup for Next Mark
[0.934s][info][gc,marking  ] GC(7) Concurrent Cleanup for Next Mark 0.347ms

这是准备进入混合垃圾回收日志:关键字“Pause Young (Prepare Mixed)”

[1.032s][info][gc,start    ] GC(8) Pause Young (Prepare Mixed) (G1 Evacuation Pause)
[1.032s][info][gc,task     ] GC(8) Using 6 workers of 8 for evacuation
[1.035s][info][gc,phases   ] GC(8)   Pre Evacuate Collection Set: 0.0ms
[1.035s][info][gc,phases   ] GC(8)   Merge Heap Roots: 0.0ms
[1.035s][info][gc,phases   ] GC(8)   Evacuate Collection Set: 2.3ms
[1.035s][info][gc,phases   ] GC(8)   Post Evacuate Collection Set: 0.1ms
[1.035s][info][gc,phases   ] GC(8)   Other: 0.1ms
[1.035s][info][gc,heap     ] GC(8) Eden regions: 38->0(6)
[1.035s][info][gc,heap     ] GC(8) Survivor regions: 7->6(6)
[1.035s][info][gc,heap     ] GC(8) Old regions: 144->164
[1.035s][info][gc,heap     ] GC(8) Archive regions: 2->2
[1.035s][info][gc,heap     ] GC(8) Humongous regions: 0->0
[1.035s][info][gc,metaspace] GC(8) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.035s][info][gc          ] GC(8) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 189M->170M(256M) 2.647ms

这是混合垃圾回收日志:关键字“Pause Young (Mixed)”,回收了6次后出现OOM。

[1.358s][info][gc,start    ] GC(15) Pause Young (Mixed) (G1 Evacuation Pause)
[1.358s][info][gc,task     ] GC(15) Using 6 workers of 8 for evacuation
[1.359s][info][gc          ] GC(15) To-space exhausted
[1.359s][info][gc,phases   ] GC(15)   Pre Evacuate Collection Set: 0.0ms
[1.359s][info][gc,phases   ] GC(15)   Merge Heap Roots: 0.0ms
[1.359s][info][gc,phases   ] GC(15)   Evacuate Collection Set: 1.2ms
[1.359s][info][gc,phases   ] GC(15)   Post Evacuate Collection Set: 0.2ms
[1.360s][info][gc,phases   ] GC(15)   Other: 0.1ms
[1.360s][info][gc,heap     ] GC(15) Eden regions: 20->0(20)
[1.360s][info][gc,heap     ] GC(15) Survivor regions: 4->3(3)
[1.360s][info][gc,heap     ] GC(15) Old regions: 206->225
[1.360s][info][gc,heap     ] GC(15) Archive regions: 2->2
[1.360s][info][gc,heap     ] GC(15) Humongous regions: 0->0
[1.360s][info][gc,metaspace] GC(15) Metaspace: 793K(960K)->793K(960K) NonClass: 735K(832K)->735K(832K) Class: 57K(128K)->57K(128K)
[1.360s][info][gc          ] GC(15) Pause Young (Mixed) (G1 Evacuation Pause) 230M->228M(256M) 1.588ms
[1.360s][info][gc,cpu      ] GC(15) User=0.01s Sys=0.00s Real=0.01s
2.6.6、案例:计费系统不稳而招来投诉的问题(从VM参数值来判断系统停顿时间引来的问题)。

系统基础信息:

jdk8, 机器8H16G,QPS不超过5000, VM参数如下:

image.png

vm参数描述
-XX:InitialHeapSize=1G初始堆内存大小设置,
-Xms规范写法,作用跟-Xms一样。
-XX:MaxHeapSize=8GJVM 堆内存的上限设置,超过此值会触发 OutOfMemoryError
-Xmx规范写法,作用跟-Xmx一样。
-XX:+UseG1GC使用 G1 (Garbage-First) 垃圾收集器,G1 将堆划分为多个 Region
(默认 2048 个)。
适合大堆内存(>4GB)和低停顿时间要求
-XX:SurvivorRatio=8伊甸区与幸存区的比例,
Eden : Survivor = 8 : 1,年轻代被分为:Eden + 2个 Survivor 区。
实际比例:Eden 占 8/10,每个 Survivor 占 1/10,
值越大,Eden 区越大,Young GC 频率越低。
-XX:MaxGCPauseMillis=20最大 GC 停顿时间目标,
G1 会尽量控制每次 GC 停顿不超过 20ms,
G1 会根据此值动态调整每次回收的 Region 数量,
值越小,GC 越频繁,但吞吐量可能降低。
-XX:G1HeapRegionSize=4MG1 Region 大小,这里每个 Region 的大小设置为 4MB。
堆会被划分为 10G / 4M = 2560 个 Region,
小 Region:回收更精细,但管理开销大,
大 Region:管理开销小,但回收粒度粗。
-XX:MaxTenuringThreshold=15对象晋升老年代的最大年龄,对象在 Survivor 区经历 15 次 GC 后
晋升到老年代。取值范围:0-15,值越大,对象在年轻代停留时间越长。
-XX:InitiatingHeapOccupancyPercent=45触发 Mixed GC 的堆占用阈值,当老年代占用达到堆的 45% 时,
触发 Concurrent Mark,
随后会进入 Mixed GC 阶段,默认值是 45%。

日志分析情况:

  • Eden区的总大小,最高不到1G(理论上达到8G应该不是问题)
    • 答:不正常,eden区范围是总内存的5%~60。
  • MixedGC频率很高,每几次YGC就会执行一次。
    • 答:大部分新对象在YGC就应该回被回收。MixedGC频繁,说明有大量的对象没有被YGC回收,写到老年代触发MixedGC。
  • 每次混合回收之后,堆空间基本就空了。
    • 答:这就说明有很多大量短周期对象进入老年代,快速挤占堆空间,达到45%比例,触发MixedGC。
  • QPS并不高,为什么会出现这种情况?
    • 答:从VM参数“-XX:MaxGCPauseMillis”找到故障原因,垃圾回收停顿时间大小,如下图:

      image.png

      关键:每次在YGC回收Eden区时,因为垃圾回收停顿时间设置只有20ms,YGC只能回收region一部分垃圾对象然后重新YGC(如果停顿时间内能够回收掉region垃圾对象,Eden空间不够会自动扩展),然后Eden空间大小始终在初始值1G徘徊。

2.7、FullGC基本原理与实战

先了解一个概念与几个问题:

  • 思考什么情况下会触发FullGC?
    • YGC和MixedGC仍然都无法分配对象空间(无法分配对象)会触发FullGC;
    • 元空间满了也会触发FullGC。
  • Full GC是非常危险的
    • FullGC可能会进行两次:第一次进行全量垃圾回收,第二次是回收软引用,如果还不够用,对象仍然无法分配,系统基本就要OOM了。
  • Full GC该如何复制对象?
    • 在YGC和MixedGC里,复制对象的时候都可以先转移到一个空间的Region里面,也就是“标记-复制”算法,而FullGC是“标记-压缩”算法,相比“标记-复制”算法,时间更慢,代价更高。
“标记-复制”算法与“标记-压缩”算法
image.png
2.7.1、FullGC基本过程

image.png

  • 第一步:标记存活对象,然后计算对象的新地址。

    • FullGC时,进入标记阶段,标记出所有的存活对象,这个过程与YGC、 MixedGC基本类时。
  • 第二步:找出并标记 Survivor 区中引用老年代对象的引用关系

    • 逐个遍历每个Region并标记,每个region从头开始,找到存活对象指向到接下来被回收的新位置。
  • 第三步:更新引用对象的地址

    • 上一步已经计算好每个对象新的地址了,那么此时就需要便利所有存活对象,将对象间的引用也指向到新的位置上去了。
  • 第四步:复制对象

    • 将对象真正复制到对象的新位置上去,如下图。

    image.png

  • 第五步:复制后的处理

    • 对回收工作进行收尾,例如调整堆分区大小等等。

2.8、大对象不要进入老年代

先了解一个概念与几个问题:

  • 大对象该怎么存储?
    • 第一种思路:使用多个region来存储。但如果大对象过多,就会不停挤占region,会触发MixedGC,严重的会触发FullGC。
    • 第二种思路:将每个region设置大一点,使用VM参数“-XX:G1HeapRegionSize”。
    • 第三种思路:从业务代码改造,将大对象拆成小对象。

image.png

2.8.1、代码一测试
public class RegionExample1 {
    public static void main(String[] args) {
        byte[] data = new byte[1024 * 2000];
        for (int i = 0; i < 200; i++) {
            //不断申请内存
            data = new byte[1024 * 2000];
        }
    }
}

vm参数设置:

-Xmx128M -Xms128M -XX:+UnlockExperimentalVMOptions -Xlog:gc*

执行代码后日志:关键字“G1 Humongous Allocation”,出现使用大对象分配(不推荐大对象,这里一个对象是2000KB,超过region默认1M的一半,所以只能使用H区存储)。

[0.088s][info][gc,start    ] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation)
[0.088s][info][gc,task     ] GC(0) Using 3 workers of 8 for evacuation
[0.090s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.090s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms
[0.090s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 1.3ms
[0.090s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.3ms
[0.090s][info][gc,phases   ] GC(0)   Other: 0.3ms
[0.090s][info][gc,heap     ] GC(0) Eden regions: 6->0(24)
[0.090s][info][gc,heap     ] GC(0) Survivor regions: 0->3(3)
[0.090s][info][gc,heap     ] GC(0) Old regions: 0->1
[0.090s][info][gc,heap     ] GC(0) Archive regions: 2->2
[0.090s][info][gc,heap     ] GC(0) Humongous regions: 54->2
[0.090s][info][gc,metaspace] GC(0) Metaspace: 594K(768K)->594K(768K) NonClass: 563K(640K)->563K(640K) Class: 30K(128K)->30K(128K)
2.8.2、代码二测试

代码不变,vm参数新增“-XX:G1HeapRegionSize”

-Xmx128M -Xms128M -XX:G1HeapRegionSize=4M -XX:+UnlockExperimentalVMOptions -Xlog:gc*

执行代码后日志:关键字“Pause Young (Normal)”,变成普通对象分配(这里一个对象是2000KB,不超过region的4M的一半,所以用普通单个region区存储便可)。

[0.107s][info][gc,start    ] GC(0) Pause Young (Normal) (G1 Evacuation Pause)
[0.107s][info][gc,task     ] GC(0) Using 3 workers of 8 for evacuation
[0.108s][info][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.108s][info][gc,phases   ] GC(0)   Merge Heap Roots: 0.0ms
[0.108s][info][gc,phases   ] GC(0)   Evacuate Collection Set: 0.7ms
[0.108s][info][gc,phases   ] GC(0)   Post Evacuate Collection Set: 0.1ms
[0.108s][info][gc,phases   ] GC(0)   Other: 0.1ms
[0.108s][info][gc,heap     ] GC(0) Eden regions: 5->0(4)
[0.108s][info][gc,heap     ] GC(0) Survivor regions: 0->1(1)
[0.108s][info][gc,heap     ] GC(0) Old regions: 0->1
[0.108s][info][gc,heap     ] GC(0) Archive regions: 2->2
[0.108s][info][gc,heap     ] GC(0) Humongous regions: 0->0
[0.108s][info][gc,metaspace] GC(0) Metaspace: 517K(704K)->517K(704K) NonClass: 493K(576K)->493K(576K) Class: 24K(128K)->24K(128K)
[0.108s][info][gc          ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 22M->9M(128M) 1.038ms
[0.108s][info][gc,cpu      ] GC(0) User=0.00s Sys=0.01s Real=0.00s
评论
成就一亿技术人!
拼手气红包6.0元
还能输入1000个字符
 
 条评论被折叠 查看
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值