Jtoss
Jason
目录

JVM - 分析垃圾回收策略

# 分析垃圾回收策略

# 内存设置

# 设置JVM内存

1、JVM内存分配有如下一些参数

  • -Xms：堆内存大小
  • -Xmx：堆内存最大大小
  • -Xmn：新生代大小，扣除新生代剩下的就是老年代大小
  • -Xss：线程栈大小
  • -XX:NewSize：初始新生代大小
  • -XX:MaxNewSize：最大新生代大小
  • -XX:InitialHeapSize：初始堆大小
  • -XX:MaxHeapSize：最大堆大小
  • -XX:MetaspaceSize：元空间（永久代）大小，jdk1.8 之前用 -XX:PermSize 设置
  • -XX:MaxMetaspaceSize：元空间（永久代）最大大小，jdk8 之前用 -XX:MaxPermSize 设置
  • -XX:SurvivorRatio：新生代 Eden 区和 Survivor 区的比例，默认为 8，即 8:1:1

一般 -Xms 和 -Xmx 设置一样的大小，-XX:MetaspaceSize 和 -XX:MaxMetaspaceSize 设置一样的大小。-Xms 等价于 -XX:InitialHeapSize，-Xmx 等价于 -XX:MaxHeapSize；-Xmn 等价于 -XX:MaxNewSize。

2、在IDEA中可以按照如下方式设置JVM参数

img

3、命令行启动时可以按照如下格式设置

java -jar -Xms1G -Xmx1G -Xmn512M -Xss1M -XX:MetaspaceSize=128M -XX:MaxMetaspaceSize=128M app.jar
1
2

# 输出GC日志

# 设置GC参数

可以在启动时加上如下参数来查看GC日志：

  • -XX:+PrintGC：打印GC日志
  • -XX:+PrintGCDetails：打印详细的GC日志
  • -XX:+PrintGCTimeStamps：打印每次GC发生的时间
  • -Xloggc:./gc.log：设置GC日志文件的路径

例如，我在IDEA中添加了如下JVM启动参数：

-Xms1G
-Xmx1G
-Xmn512M
-Xss1M
-XX:MetaspaceSize=128M
-XX:MaxMetaspaceSize=128M
-XX:SurvivorRatio=8
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-Xloggc:./gc.log
1
2
3
4
5
6
7
8
9
10
11
12

启动程序之后打印出了如下的一些日志：

 1 Java HotSpot(TM) 64-Bit Server VM (25.191-b12) for windows-amd64 JRE (1.8.0_191-b12), built on Oct  6 2018 09:29:03 by "java_re" with MS VC++ 10.0 (VS2010)
 2 Memory: 4k page, physical 33408872k(22219844k free), swap 35506024k(21336808k free)
 3 CommandLine flags: -XX:-BytecodeVerificationLocal -XX:-BytecodeVerificationRemote -XX:CompressedClassSpaceSize=125829120 -XX:InitialHeapSize=1073741824 -XX:+ManagementServer -XX:MaxHeapSize=1073741824 -XX:MaxMetaspaceSize=134217728 -XX:MaxNewSize=536870912 -XX:MetaspaceSize=134217728 -XX:NewSize=536870912 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:ThreadStackSize=1024 -XX:TieredStopAtLevel=1 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
 4 2020-09-25T13:00:41.631+0800: 4.013: [GC (Allocation Failure) [PSYoungGen: 419840K->20541K(472064K)] 419840K->20573K(996352K), 0.0118345 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
 5 2020-09-25T13:00:44.252+0800: 6.633: [GC (Allocation Failure) [PSYoungGen: 440381K->39872K(472064K)] 440413K->39928K(996352K), 0.0180292 secs] [Times: user=0.08 sys=0.08, real=0.02 secs] 
 6 ......
 7 2020-09-25T13:06:58.361+0800: 380.743: [GC (Allocation Failure) [PSYoungGen: 422656K->14159K(472064K)] 610503K->204082K(996352K), 0.0111278 secs] [Times: user=0.16 sys=0.00, real=0.01 secs] 
 8 Heap
 9  PSYoungGen      total 472064K, used 406352K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000)
10   eden space 419840K, 93% used [0x00000000e0000000,0x00000000f7f00528,0x00000000f9a00000)
11   from space 52224K, 27% used [0x00000000f9a00000,0x00000000fa7d3d70,0x00000000fcd00000)
12   to   space 52224K, 0% used [0x00000000fcd00000,0x00000000fcd00000,0x0000000100000000)
13  ParOldGen       total 524288K, used 189923K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000)
14   object space 524288K, 36% used [0x00000000c0000000,0x00000000cb978d08,0x00000000e0000000)
15  Metaspace       used 111852K, capacity 117676K, committed 117888K, reserved 1153024K
16   class space    used 13876K, capacity 14914K, committed 14976K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

从第三行 CommandLine flags 可以得到如下的信息：

  • -XX:InitialHeapSize=1073741824：初始堆大小为1G（等于 -Xms 设置的值）
  • -XX:MaxHeapSize=1073741824：最大堆内存 1G（等于 -Xmx 设置的值）
  • -XX:NewSize=536870912：新生代初始大小 512M（等于 -Xmn 设置的值）
  • -XX:MaxNewSize=536870912：最新生代初始大小 512M（等于 -Xmn 设置的值）
  • -XX:MetaspaceSize=134217728：元空间大小 128M
  • -XX:MaxMetaspaceSize=134217728：最大元空间 128M
  • -XX:SurvivorRatio=8：新生代 Eden 和 Survivor 的比例
  • -XX:ThreadStackSize=1024：线程栈的大小 1M
  • -XX:+UseParallelGC：默认使用 年轻代 Parallel Scavenge + 老年代 Parallel Old 的垃圾回收器组合。

# 查看默认参数

如果要查看JVM的默认参数，就可以通过给JVM加打印GC日志的参数，就可以在GC日志中看到JVM的默认参数了。

还可以在启动参数中添加 -XX:+PrintFlagsFinal 参数，将会打印系统的所有参数，就可以看到自己配置的参数或系统的默认参数了。

img

# GC日志

之后的日志就是每次垃圾回收时产生的日志，每行日志说明了这次GC的执行情况，例如第四行GC日志：

2020-09-25T13:00:41.631+0800: 4.013: [GC (Allocation Failure) [PSYoungGen: 419840K->20541K(472064K)] 419840K->20573K(996352K), 0.0118345 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
1
2

详细内容如下：

  • 2020-09-25T13:00:41.631+0800：GC发生的时间点。
  • 4.013：系统运行多久之后发生的GC，单位秒，这里就是系统运行 4.013 秒后发生了一次GC。
  • GC (Allocation Failure)：说明了触发GC的原因，这里是指对象分配失败导致的GC。
  • PSYoungGen：指触发的是年轻代的垃圾回收，使用的是 Parallel Scavenge 垃圾回收器。
  • 419840K->20541K：对年轻代执行了一次GC，GC之前年轻代使用了 419840K，GC之后有 20541K 的对象活下来了。
  • (472064K)：年轻代可用空间是 472064K，即 461 M，为什么是461M呢？因为新生代大小为 512M，Eden 区占 409.6M，两块 Survivor 区各占 51.2M，所以年轻代的可用空间为 Eden+1个Survivor的大小，即460.8M，约为461M。
  • 419840K->20573K：GC前整个堆内存使用了 419840K，GC之后堆内存使用了 20573K。
  • (996352K)：整个堆的大小是 996352K，即 973M，其实就是年轻代的 461M + 老年代的 512 M
  • 0.0118345 secs：本次GC耗费的时间
  • Times: user=0.00 sys=0.00, real=0.01 secs：本次GC耗费的时间

# JVM退出时的GC情况

程序结束运行后，还会打印一些日志，就是第12行之后的日志，这部分展示的是当前堆内存的使用情况：

1 Heap
2  PSYoungGen      total 472064K, used 406352K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000)
3   eden space 419840K, 93% used [0x00000000e0000000,0x00000000f7f00528,0x00000000f9a00000)
4   from space 52224K, 27% used [0x00000000f9a00000,0x00000000fa7d3d70,0x00000000fcd00000)
5   to   space 52224K, 0% used [0x00000000fcd00000,0x00000000fcd00000,0x0000000100000000)
6  ParOldGen       total 524288K, used 189923K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000)
7   object space 524288K, 36% used [0x00000000c0000000,0x00000000cb978d08,0x00000000e0000000)
8  Metaspace       used 111852K, capacity 117676K, committed 117888K, reserved 1153024K
9   class space    used 13876K, capacity 14914K, committed 14976K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10

详细内容如下：

  • PSYoungGen total 472064K, used 406352K：指 Parallel Scavenge 回收器负责的年轻代总共有 472064K（461M）内存，目前使用了 406352K （396.8M）。
  • eden space 419840K, 93% used：Eden 区的空间为 419840K（410M），已经使用了 93%。
  • from space 52224K, 27% used：From Survivor 区的空间为 52224K（51M），已经使用了 27%。
  • to space 52224K, 0% used：To Survivor 区的空间为 52224K（51M），使用了 0%，就是完全空闲的。
  • ParOldGen total 524288K, used 189923K：指 Parallel Old 回收器负责的老年代总共有 524288K（512M），目前使用了 189923K（185.4M）。
  • object space 524288K, 36% used：老年代空间总大小 524288K（512M），使用了 36%。
  • Metaspace & class space：Metaspace 元数据空间和Class空间，总容量、使用的内存等。

# 内存分配与回收策略

接下来我们就通过一些 demo 结合着GC日志分析下什么时候会触发GC，以及对象在堆中如何分配流转的。

# 对象首先分配到Eden区

我们通过如下这段程序来验证下对象首先是分配到 Eden 区的：

public class GCMain {
    static final int _1M = 1024 * 1024;

    public static void main(String[] args) {
        byte[] b1 = new byte[_1M * 30];
        byte[] b2 = new byte[_1M * 30];
    }
}
1
2
3
4
5
6
7
8
9

jvm参数设置为如下：堆200M，年轻代 100M，Eden区占 80M，Survivor 各占 10M，老年代100M。使用默认的 Parallel Scavenge + Parallel Old 回收器。

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:+UseParallelGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

程序运行结束后，查看运行的GC日志：

 1 Java HotSpot(TM) 64-Bit Server VM (25.191-b12) for windows-amd64 JRE (1.8.0_191-b12), built on Oct  6 2018 09:29:03 by "java_re" with MS VC++ 10.0 (VS2010)
 2 Memory: 4k page, physical 33408872k(23013048k free), swap 35506024k(22095152k free)
 3 CommandLine flags: -XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:MaxNewSize=104857600 -XX:NewSize=104857600 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
 4 Heap
 5  PSYoungGen      total 92160K, used 68062K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
 6   eden space 81920K, 83% used [0x00000000f9c00000,0x00000000fde77ba0,0x00000000fec00000)
 7   from space 10240K, 0% used [0x00000000ff600000,0x00000000ff600000,0x0000000100000000)
 8   to   space 10240K, 0% used [0x00000000fec00000,0x00000000fec00000,0x00000000ff600000)
 9  ParOldGen       total 102400K, used 0K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
10   object space 102400K, 0% used [0x00000000f3800000,0x00000000f3800000,0x00000000f9c00000)
11  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
12   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
  • 从第5行可以看出，年轻代总共可用空间为 92160K（90M），已经使用了 68062K（66.4M）。代码中创建了两个30M的byte数组，为何会占用66.4M呢？多出来的这部分对象可以认为是对象数组本身额外需要占用的内存空间以及程序运行时所创建的一些额外的对象，就称为未知对象吧。
  • 从第6行之后可以看出，Eden 使用了 83%，From Survivor、To Survivor、老年代使用率均为 0%。可以确认对象首先是分配到 Eden 区的。

# Eden 区满了触发 YoungGC

使用如下jvm参数：

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:+UseParallelGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

运行如下代码，第2、3、4行将产生60M的垃圾对象，第6行再分配时，eden 区空间就不够分配了，此时就会触发一次 YoungGC。

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 30];
    b1 = new byte[_1M * 30];
    b1 = null;

    byte[] b2 = new byte[_1M * 30];
}
1
2
3
4
5
6
7
8

看GC日志可以发现触发了一次 Young GC：

 1 2020-09-26T00:14:16.832+0800: 0.194: [GC (Allocation Failure) [PSYoungGen: 66424K->815K(92160K)] 66424K->823K(194560K), 0.0010813 secs] [Times: user=0.08 sys=0.08, real=0.00 secs] 
 2 Heap
 3  PSYoungGen      total 92160K, used 33993K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
 4   eden space 81920K, 40% used [0x00000000f9c00000,0x00000000fbc66800,0x00000000fec00000)
 5   from space 10240K, 7% used [0x00000000fec00000,0x00000000feccbca0,0x00000000ff600000)
 6   to   space 10240K, 0% used [0x00000000ff600000,0x00000000ff600000,0x0000000100000000)
 7  ParOldGen       total 102400K, used 8K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 8   object space 102400K, 0% used [0x00000000f3800000,0x00000000f3802000,0x00000000f9c00000)
 9  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
10   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K 1 Java HotSpot(TM) 64-Bit Server VM (25.191-b12) for windows-amd64 JRE (1.8.0_191-b12), built on Oct  6 2018 09:29:03 by "java_re" with MS VC++ 10.0 (VS2010)
 2 Memory: 4k page, physical 33408872k(22977952k free), swap 35506024k(21515696k free)
 3 CommandLine flags: -XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:MaxNewSize=104857600 -XX:NewSize=104857600 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=41943040 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
 4 Heap
 5  par new generation   total 92160K, used 6622K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 6   eden space 81920K,   8% used [0x00000000f3800000, 0x00000000f3e77b80, 0x00000000f8800000)
 7   from space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
 8   to   space 10240K,   0% used [0x00000000f9200000, 0x00000000f9200000, 0x00000000f9c00000)
 9  concurrent mark-sweep generation total 102400K, used 40960K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
10  Metaspace       used 3046K, capacity 4556K, committed 4864K, reserved 1056768K
11   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
  • 第1行可以看出，由于内存分配失败触发了一次YoungGC，回收前内存占用 66424K，回收后只有 815K 了。整个堆回收前占用 66424K，回收后存活 823K。
  • 第3行可以看出，程序结束后，新生代使用了 33993K，其中就包括最后一个 b2 对象。
  • 第5行可以看出，Young GC后，存活的 815K 对象进入了 from survivor 区，占用 7% 的空间。

从上面的分析可以确认 eden 区快满了，无法给新生对象分配内存时，将触发一次 Young GC，并把存活的对象复制到一个 survivor 区中。

# 大对象将直接进入老年代

要控制大对象的阀值可以通过 -XX:PretenureSizeThreshold 参数设置，但是它只对 Serial 和 ParNew 回收器生效，对 Parallel Scavenge 不生效，所以这里我们使用 ParNew + CMS 的回收器组合，并设置大对象阀值为4M：

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=40M -XX:+UseConcMarkSweepGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

运行如下的代码，直接创建一个 40M 的对象：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 40];
}
1
2
3
4

查看GC日志：

 1 Java HotSpot(TM) 64-Bit Server VM (25.191-b12) for windows-amd64 JRE (1.8.0_191-b12), built on Oct  6 2018 09:29:03 by "java_re" with MS VC++ 10.0 (VS2010)
 2 Memory: 4k page, physical 33408872k(22977952k free), swap 35506024k(21515696k free)
 3 CommandLine flags: -XX:InitialHeapSize=209715200 -XX:MaxHeapSize=209715200 -XX:MaxNewSize=104857600 -XX:NewSize=104857600 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=41943040 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
 4 Heap
 5  par new generation   total 92160K, used 6622K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 6   eden space 81920K,   8% used [0x00000000f3800000, 0x00000000f3e77b80, 0x00000000f8800000)
 7   from space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
 8   to   space 10240K,   0% used [0x00000000f9200000, 0x00000000f9200000, 0x00000000f9c00000)
 9  concurrent mark-sweep generation total 102400K, used 40960K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
10  Metaspace       used 3046K, capacity 4556K, committed 4864K, reserved 1056768K
11   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
  • 第3、5、9行可以看出， -XX:+UseConcMarkSweepGC 参数默认启用的是 ParNew + CMS 的回收器。
  • 第5、6行可以看出，eden 区还是会有6M左右的未知对象。
  • 第9行可以看出，CMS 负责的老年代内存大小为 102400K（100M），使用了 40960K（40M），就是代码中创建的 b1 对象。

因此可以确认，超过 -XX:PretenureSizeThreshold 参数设置的大对象将直接进入老年代。

# 长期存活的对象将进入老年代

对象诞生在 eden 区中，eden 区满了之后，就会触发 YoungGC，将 eden 区存活的对象复制到 survivor 中，此时对象的GC年龄设为1岁。对象每熬过一次GC，GC年龄就增加1岁，当它超过一定阀值的时候就会被晋升到老年代。GC年龄的阀值可以通过参数 -XX:MaxTenuringThreshold 设置，默认为 15。

设置如下JVM参数：eden 区80M，survivor 各占10M，GC年龄阀值为2。

-Xms200M -Xmx200M -Xmn100M -XX:MaxTenuringThreshold=2 -XX:PretenureSizeThreshold=40M -XX:+UseConcMarkSweepGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

首先运行如下代码，第4、5、6行将在eden区产生70M的垃圾对象，第8行再创建一个35M的对象时，eden区空间不足，将触发第一次YoungGC：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 2]; // b1 为长期存活对象 占 2M

    byte[] b2 = new byte[_1M * 35];
    b2 = new byte[_1M * 35];
    b2 = null;

    byte[] b3 = new byte[_1M * 35];
    //b3 = new byte[_1M * 35];
    //b3 = null;
    //
    //byte[] b4 = new byte[_1M * 35];
    //b4 = new byte[_1M * 35];
    //b4 = null;
    //
    //byte[] bx = new byte[_1M * 2];
    //byte[] b5 = new byte[_1M * 35];
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

查看GC日志：

1 2020-09-25T23:47:20.648+0800: 0.198: [GC (Allocation Failure) 2020-09-25T23:47:20.648+0800: 0.198: [ParNew: 78712K->2769K(92160K), 0.0013440 secs] 78712K->2769K(194560K), 0.0014923 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2 Heap
3  par new generation   total 92160K, used 41067K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
4   eden space 81920K,  46% used [0x00000000f3800000, 0x00000000f5d66800, 0x00000000f8800000)
5   from space 10240K,  27% used [0x00000000f9200000, 0x00000000f94b4600, 0x00000000f9c00000)
6   to   space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
7  concurrent mark-sweep generation total 102400K, used 0K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
8  Metaspace       used 3047K, capacity 4556K, committed 4864K, reserved 1056768K
9   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
  • 可以看出，第一次YoungGC后还存活2769K的对象，然后复制到 from survivor 区，占 27% 的空间大小，包含2M的b1对象+700K左右的未知对象。此时 b1 对象GC年龄为1。

再运行如下代码，同理，运行到第12行时，将触发第二次 YoungGC：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 2]; // b1 为长期存活对象 占 2M

    byte[] b2 = new byte[_1M * 35];
    b2 = new byte[_1M * 35];
    b2 = null;

    byte[] b3 = new byte[_1M * 35];
    b3 = new byte[_1M * 35];
    b3 = null;

    byte[] b4 = new byte[_1M * 35];
    //b4 = new byte[_1M * 35];
    //b4 = null;
    //
    //byte[] bx = new byte[_1M * 2];
    //byte[] b5 = new byte[_1M * 35];
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

查看GC日志：

 1 2020-09-25T23:53:57.325+0800: 0.196: [GC (Allocation Failure) 2020-09-25T23:53:57.325+0800: 0.196: [ParNew: 78712K->2770K(92160K), 0.0014935 secs] 78712K->2770K(194560K), 0.0016180 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 2 2020-09-25T23:53:57.331+0800: 0.201: [GC (Allocation Failure) 2020-09-25T23:53:57.331+0800: 0.201: [ParNew: 77693K->2888K(92160K), 0.0013393 secs] 77693K->2888K(194560K), 0.0013890 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 3 Heap
 4  par new generation   total 92160K, used 40367K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 5   eden space 81920K,  45% used [0x00000000f3800000, 0x00000000f5c99b30, 0x00000000f8800000)
 6   from space 10240K,  28% used [0x00000000f8800000, 0x00000000f8ad2130, 0x00000000f9200000)
 7   to   space 10240K,   0% used [0x00000000f9200000, 0x00000000f9200000, 0x00000000f9c00000)
 8  concurrent mark-sweep generation total 102400K, used 0K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
 9  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
10   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
  • 可以看出，第二次YoungGC后，还存活2888K对象，此时复制到另一块 survivor 区，占 28% 的内存，包含2M的b1对象+700K左右的未知对象。此时 b2 对象GC年龄加1，为2。

再运行如下代码，第17行将触发第三次YoungGC：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 2]; // b1 为长期存活对象 占 2M

    byte[] b2 = new byte[_1M * 35];
    b2 = new byte[_1M * 35];
    b2 = null;

    byte[] b3 = new byte[_1M * 35];
    b3 = new byte[_1M * 35];
    b3 = null;

    byte[] b4 = new byte[_1M * 35];
    b4 = new byte[_1M * 35];
    b4 = null;

    byte[] bx = new byte[_1M * 2];
    byte[] b5 = new byte[_1M * 35];
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

查看GC日志：

 1 2020-09-26T00:00:39.242+0800: 0.188: [GC (Allocation Failure) 2020-09-26T00:00:39.243+0800: 0.188: [ParNew: 78712K->2749K(92160K), 0.0012472 secs] 78712K->2749K(194560K), 0.0013625 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 2 2020-09-26T00:00:39.247+0800: 0.193: [GC (Allocation Failure) 2020-09-26T00:00:39.247+0800: 0.193: [ParNew: 77672K->2867K(92160K), 0.0013000 secs] 77672K->2867K(194560K), 0.0013396 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 3 2020-09-26T00:00:39.252+0800: 0.197: [GC (Allocation Failure) 2020-09-26T00:00:39.252+0800: 0.197: [ParNew: 78732K->2048K(92160K), 0.0031018 secs] 78732K->4716K(194560K), 0.0031488 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
 4 Heap
 5  par new generation   total 92160K, used 38707K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 6   eden space 81920K,  44% used [0x00000000f3800000, 0x00000000f5bcce50, 0x00000000f8800000)
 7   from space 10240K,  20% used [0x00000000f9200000, 0x00000000f9400010, 0x00000000f9c00000)
 8   to   space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
 9  concurrent mark-sweep generation total 102400K, used 2668K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
10  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
11   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
  • 可以看出，第三次YoungGC后，年轻代还存活 2048K（2M），其实就是 bx 这个对象，bx 被复制到 from survivor 区，from survivor 占用刚好20%（2M）。而此时老年代使用了 2668K，就是2M的 b1 对象+600K左右的未知对象。

所以可以判断出，第三次YoungGC时，在要复制 eden区+from survivor 区的存活对象时，发现 survivor 区存活对象的GC年龄已经超过设置的阀值了，这时就会将超过阀值的对象复制到老年代。

# 动态对象年龄判断

动态对象年龄判断是指，在复制前，如果 survivior 区域内年龄1+年龄2+年龄3+...+年龄n的对象总和大于survivor区的50%时，年龄n及以上存活的对象就会进入老年代，不一定要达到15岁。

设置如下JVM参数：

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=40M -XX:+UseConcMarkSweepGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

运行如下代码：

public static void main(String[] args) {
    byte[] x1 = new byte[_1M * 3];

    byte[] b1 = new byte[_1M * 30];
    b1 = new byte[_1M * 30];
    b1 = null;

    byte[] b2 = new byte[_1M * 30]; // 触发一次GC

    byte[] x2 = new byte[_1M * 2];

    b2 = new byte[_1M * 30];
    b2 = null;

    byte[] b3 = new byte[_1M * 30]; // 触发一次GC

    //byte[] x3 = new byte[_1M];
    //
    //b3 = new byte[_1M * 30];
    //b3 = null;
    //
    //byte[] b4 = new byte[_1M * 30]; // 触发一次GC
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24

查看GC日志：

 1 2020-09-26T00:50:51.099+0800: 0.211: [GC (Allocation Failure) 2020-09-26T00:50:51.099+0800: 0.211: [ParNew: 69496K->3787K(92160K), 0.0020708 secs] 69496K->3787K(194560K), 0.0021864 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 2 2020-09-26T00:50:51.104+0800: 0.217: [GC (Allocation Failure) 2020-09-26T00:50:51.104+0800: 0.217: [ParNew: 70513K->6007K(92160K), 0.0030657 secs] 70513K->6007K(194560K), 0.0031105 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 3 Heap
 4  par new generation   total 92160K, used 38366K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 5   eden space 81920K,  39% used [0x00000000f3800000, 0x00000000f5799b30, 0x00000000f8800000)
 6   from space 10240K,  58% used [0x00000000f8800000, 0x00000000f8dddf18, 0x00000000f9200000)
 7   to   space 10240K,   0% used [0x00000000f9200000, 0x00000000f9200000, 0x00000000f9c00000)
 8  concurrent mark-sweep generation total 102400K, used 0K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
 9  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
10   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
  • 结合代码和GC日志可以分析出，代码运行到第15行之后，触发了两次GC，这时 x1 的GC年龄为2，x2的GC年龄为1。from survivor 占了 58%了，从这里也可以看出是在复制前来判断动态年龄规则的。

再运行如下代码：

public static void main(String[] args) {
    byte[] x1 = new byte[_1M * 3];

    byte[] b1 = new byte[_1M * 30];
    b1 = new byte[_1M * 30];
    b1 = null;

    byte[] b2 = new byte[_1M * 30]; // 触发一次GC

    byte[] x2 = new byte[_1M * 2];

    b2 = new byte[_1M * 30];
    b2 = null;

    byte[] b3 = new byte[_1M * 30]; // 触发一次GC

    byte[] x3 = new byte[_1M];

    b3 = new byte[_1M * 30];
    b3 = null;

    byte[] b4 = new byte[_1M * 30]; // 触发一次GC
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24

查看GC日志：

 1 2020-09-26T00:57:03.279+0800: 0.197: [GC (Allocation Failure) 2020-09-26T00:57:03.279+0800: 0.197: [ParNew: 69496K->3785K(92160K), 0.0020626 secs] 69496K->3785K(194560K), 0.0021906 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 2 2020-09-26T00:57:03.285+0800: 0.203: [GC (Allocation Failure) 2020-09-26T00:57:03.285+0800: 0.203: [ParNew: 70511K->5980K(92160K), 0.0028174 secs] 70511K->5980K(194560K), 0.0028673 secs] [Times: user=0.16 sys=0.00, real=0.00 secs] 
 3 2020-09-26T00:57:03.290+0800: 0.208: [GC (Allocation Failure) 2020-09-26T00:57:03.290+0800: 0.208: [ParNew: 70832K->3072K(92160K), 0.0031929 secs] 70832K->6764K(194560K), 0.0032401 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 4 Heap
 5  par new generation   total 92160K, used 34611K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 6   eden space 81920K,  38% used [0x00000000f3800000, 0x00000000f56cce50, 0x00000000f8800000)
 7   from space 10240K,  30% used [0x00000000f9200000, 0x00000000f9500020, 0x00000000f9c00000)
 8   to   space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
 9  concurrent mark-sweep generation total 102400K, used 3692K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
10  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
11   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
  • 结合代码和GC日志可以分析出，代码运行到第22行时，触发了第三次GC，第三次GC复制时，survivor 中年龄为1的 x2 对象（2M）+年龄为2的 x1 对象（3M）+ 年龄为2的未知对象 已经超过 survivor 的50%了，此时就触发动态年龄判定规则，将年龄为2以上的对象晋升到老年代。
  • 从第7行看出，survivor 区还有30%（3M）的对象，就是回收后还存活的 x2（2M）+ x3（1M）。
  • 从第9行看出，老年代使用了 3692K（3.6M），说明 x1（3M）+ 未知对象（500K左右）通过动态年龄判断晋升到老年代了。

再运行如下代码：代码第19行，在第三次GC前将其变为垃圾对象了。

public static void main(String[] args) {
    byte[] x1 = new byte[_1M * 3];

    byte[] b1 = new byte[_1M * 30];
    b1 = new byte[_1M * 30];
    b1 = null;

    byte[] b2 = new byte[_1M * 30]; // 触发一次GC

    byte[] x2 = new byte[_1M * 2];

    b2 = new byte[_1M * 30];
    b2 = null;

    byte[] b3 = new byte[_1M * 30]; // 触发一次GC

    byte[] x3 = new byte[_1M];

    x1 = null; // x1 变为垃圾对象
    b3 = new byte[_1M * 30];
    b3 = null;

    byte[] b4 = new byte[_1M * 30]; // 触发一次GC
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25

查看GC日志：

 1 2020-09-29T12:48:49.695+0800: 0.179: [GC (Allocation Failure) 2020-09-29T12:48:49.695+0800: 0.179: [ParNew: 69496K->3781K(92160K), 0.0018195 secs] 69496K->3781K(194560K), 0.0019372 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 2 2020-09-29T12:48:49.701+0800: 0.184: [GC (Allocation Failure) 2020-09-29T12:48:49.701+0800: 0.184: [ParNew: 70508K->5955K(92160K), 0.0027981 secs] 70508K->5955K(194560K), 0.0028417 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 3 2020-09-29T12:48:49.706+0800: 0.189: [GC (Allocation Failure) 2020-09-29T12:48:49.706+0800: 0.189: [ParNew: 70807K->3072K(92160K), 0.0032486 secs] 70807K->3692K(194560K), 0.0032909 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
 4 Heap
 5  par new generation   total 92160K, used 34611K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
 6   eden space 81920K,  38% used [0x00000000f3800000, 0x00000000f56cce50, 0x00000000f8800000)
 7   from space 10240K,  30% used [0x00000000f9200000, 0x00000000f9500020, 0x00000000f9c00000)
 8   to   space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
 9  concurrent mark-sweep generation total 102400K, used 620K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
10  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
11   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
  • 从日志可以分析出，虽然年龄为2的 x1 对象变为垃圾对象了，但是第三次GC后，老年代还是多了620K的对象。说明第三次YoungGC时，在将 Eden 和 FromSurvivor 区存活对象复制到 ToSurvivor 区前，会先通过动态年龄判断 FromSurvivor 年龄1 + 年龄2 + ... 年龄n 的对象，而且其判断的是所有对象，而不是只有标记为存活的对象。但是在将年龄n以上的对象复制到老年代时，会只复制标记为存活的对象。

# 无法放入Survivor区直接进入老年代

YoungGC时，如果 eden区+ from survivor 区存活的对象无法放到 to survivor 区了，这个时候会直接将部分对象放入到老年代。

使用如下jvm参数：

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=40M -XX:+UseConcMarkSweepGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

运行如下代码：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 3];
    byte[] b2 = new byte[_1M * 8];

    byte[] b3 = new byte[_1M * 30];
    b3 = new byte[_1M * 30];
    b3 = null;

    byte[] b4 = new byte[_1M * 30]; // 触发GC
}
1
2
3
4
5
6
7
8
9
10
11

查看GC日志：

1 2020-09-26T01:20:03.727+0800: 0.186: [GC (Allocation Failure) 2020-09-26T01:20:03.727+0800: 0.186: [ParNew: 77688K->3799K(92160K), 0.0059624 secs] 77688K->11993K(194560K), 0.0060861 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2 Heap
3  par new generation   total 92160K, used 36977K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
4   eden space 81920K,  40% used [0x00000000f3800000, 0x00000000f5866800, 0x00000000f8800000)
5   from space 10240K,  37% used [0x00000000f9200000, 0x00000000f95b5e00, 0x00000000f9c00000)
6   to   space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
7  concurrent mark-sweep generation total 102400K, used 8194K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
8  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
9   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
  • 结合代码和GC日志可以看出，YoungGC后，存活的对象无法复制到一个 survivor 区中了，因此有部分对象直接晋升到老年代了。from survivor 区占了 37%（3.7M），可以认为是 b1对象（3M）+ 700K左右未知对象；老年代使用了 8194K（8M），就是b2对象（8M）。

需要注意的是，并不是把全部存活的对象晋升到老年代，而是把部分对象晋升到老年代，部分复制到 survivor 区中。

# 老年代空间分配担保原则

如果YougGC时新生代有大量对象存活下来，而 survivor 区放不下了，这时必须转移到老年代中，但这时发现老年代也放不下这些对象了，那怎么处理呢？其实JVM有一个老年代空间分配担保机制来保证对象能够进入老年代。

在执行每次 YoungGC 之前，JVM会先检查老年代最大可用连续空间是否大于新生代所有对象的总大小。因为在极端情况下，可能新生代 YoungGC 后，所有对象都存活下来了，而 survivor 区又放不下，那可能所有对象都要进入老年代了。这个时候如果老年代的可用连续空间是大于新生代所有对象的总大小的，那就可以放心进行 YoungGC。但如果老年代的内存大小是小于新生代对象总大小的，那就有可能老年代空间不够放入新生代所有存活对象，这个时候JVM就会先检查 -XX:HandlePromotionFailure 参数是否允许担保失败，如果允许，就会判断老年代最大可用连续空间是否大于历次晋升到老年代对象的平均大小，如果大于，将尝试进行一次YoungGC，尽快这次YoungGC是有风险的。如果小于，或者 -XX:HandlePromotionFailure 参数不允许担保失败，这时就会进行一次 Full GC。

在允许担保失败并尝试进行YoungGC后，可能会出现三种情况：

  • YoungGC后，存活对象小于survivor大小，此时存活对象进入survivor区中
  • YoungGC后，存活对象大于survivor大小，但是小于老年大可用空间大小，此时直接进入老年代。
  • YoungGC后，存活对象大于survivor大小，也大于老年大可用空间大小，老年代也放不下这些对象了，此时就会发生“Handle Promotion Failure”，就触发了 Full GC。如果 Full GC后，老年代还是没有足够的空间，此时就会发生OOM内存溢出了。

通过下图来了解空间分配担保原则：

img

分配担保规则在JDK7之后有些变化，不再判断 -XX:HandlePromotionFailure 参数。YoungGC发生时，只要老年代的连续空间大于新生代对象总大小，或者大于历次晋升的平均大小，就可以进行 YoungGC，否则就进行 FullGC。

下面来结合GC日志实际观察下，设置如下jvm参数：老年代100M，eden区80M，survivor区10M，大对象阀值为35M。

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=35M -XX:+UseConcMarkSweepGC 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3

运行如下代码：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M * 35];
    byte[] b2 = new byte[_1M * 35];

    byte[] b3 = new byte[_1M * 30];
    b3 = new byte[_1M * 30];
    b3 = null;

    byte[] b4 = new byte[_1M * 30]; // 触发GC
}
1
2
3
4
5
6
7
8
9
10
11

查看GC日志：

 1 2020-09-26T02:53:17.908+0800: 0.210: [GC (Allocation Failure) 2020-09-26T02:53:17.909+0800: 0.210: [ParNew: 66424K->707K(92160K), 0.0008820 secs] 138104K->72387K(194560K), 0.0010026 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 2 2020-09-26T02:53:17.911+0800: 0.213: [GC (CMS Initial Mark) [1 CMS-initial-mark: 71680K(102400K)] 103107K(194560K), 0.0002821 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 3 2020-09-26T02:53:17.912+0800: 0.213: [CMS-concurrent-mark-start]
 4 2020-09-26T02:53:17.912+0800: 0.213: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 5 2020-09-26T02:53:17.912+0800: 0.213: [CMS-concurrent-preclean-start]
 6 2020-09-26T02:53:17.912+0800: 0.213: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 7 2020-09-26T02:53:17.912+0800: 0.213: [CMS-concurrent-abortable-preclean-start]
 8 Heap
 9  par new generation   total 92160K, used 33885K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
10   eden space 81920K,  40% used [0x00000000f3800000, 0x00000000f5866800, 0x00000000f8800000)
11   from space 10240K,   6% used [0x00000000f9200000, 0x00000000f92b0f48, 0x00000000f9c00000)
12   to   space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
13  concurrent mark-sweep generation total 102400K, used 71680K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
14  Metaspace       used 3047K, capacity 4556K, committed 4864K, reserved 1056768K
15   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
  • b1、b2 两个对象超过大对象阀值，将直接进入老年代，因此可以认为历次进入老年大对象的平均大小为35M。此时老年代还剩余30M。
  • 代码第5、6、7行将产生60M垃圾对象，到第9行时 eden 区不足，这时判断老年代剩余空间（30M）是否大于新生代所有对象大小（60M），明显是否；再判断老年代大小（30M）是否大于历次晋升对象的平均大小（35M），也是否。

因此这时就触发了 Full GC，GC日志中第1行发生了一次YoungGC，第2~7行是CMS的OldGC。

# CMS触发OldGC

CMS回收器有个参数 -XX:CMSInitiatingOccupancyFraction 来控制当老年代内存占用超过这个比例后，就触发CMS回收。因为CMS要预留一些空间保证在回收期间，可以让对象进入老年代。

设置如下jvm参数：当老年代超过80%时，触发CMS回收，CMS GC线程每个2秒检查一次是否回收。

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=15M 
-XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSWaitDuration=2000 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3
4

运行如下代码：

public static void main(String[] args) {
    byte[] b3 = new byte[_1M * 30];
    b3 = new byte[_1M * 30];
    b3 = new byte[_1M * 20];

    try {
        Thread.sleep(3000);
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
}
1
2
3
4
5
6
7
8
9
10
11
12

查看GC日志：

2020-09-26T04:13:52.245+0800: 2.083: [GC (CMS Initial Mark) [1 CMS-initial-mark: 81920K(102400K)] 86904K(194560K), 0.0006366 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-09-26T04:13:52.245+0800: 2.084: [CMS-concurrent-mark-start]
2020-09-26T04:13:52.245+0800: 2.084: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-09-26T04:13:52.245+0800: 2.084: [CMS-concurrent-preclean-start]
2020-09-26T04:13:52.246+0800: 2.084: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2020-09-26T04:13:52.246+0800: 2.084: [CMS-concurrent-abortable-preclean-start]
Heap
 par new generation   total 92160K, used 6622K [0x00000000f3800000, 0x00000000f9c00000, 0x00000000f9c00000)
  eden space 81920K,   8% used [0x00000000f3800000, 0x00000000f3e77b80, 0x00000000f8800000)
  from space 10240K,   0% used [0x00000000f8800000, 0x00000000f8800000, 0x00000000f9200000)
  to   space 10240K,   0% used [0x00000000f9200000, 0x00000000f9200000, 0x00000000f9c00000)
 concurrent mark-sweep generation total 102400K, used 81920K [0x00000000f9c00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
  class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
  • 可以看到，老年代超过80%后，触发了一次CMS老年代回收，注意并不是Full GC，只是老年代回收。

还需注意的是，并不是超过80%就立即触发CMS回收，CMS自己有个间隔时间，通过 -XX:CMSWaitDuration 参数设置，其默认值为2000毫秒，从这里也可以看出，程序运行2秒后才触发了CMS的回收。

# G1垃圾回收

接下来看下G1某些场景的日志，首先设置如下jvm参数：

-Xms200M -Xmx200M -Xmn100M -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=1 
-XX:+UseG1GC -XX:+UnlockExperimentalVMOptions -XX:G1MaxNewSizePercent=50 -XX:G1HeapRegionSize=4M 
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./gc.log
1
2
3
4

这样设置后，堆内存200M，使用 G1 回收器，每个 Region 大小为 4M（注意设置为 2 的N次冥），共50个Region，新生代最大比例占50%，这样 Eden 区最多80M，占 20 个 Region，两个 Survivor 区最多20M， 占 5 个 Region。还有分代年龄设置为1。注意设置 -XX:G1MaxNewSizePercent参数时，必须要设置 -XX:+UnlockExperimentalVMOptions 参数。

# 新生代回收

运行如下代码，将创建50M的对象：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M];

    byte[] b2 = new byte[_1M];
    for (int i = 0; i < 49; i++) {
        b2 = new byte[_1M];
    }
}
1
2
3
4
5
6
7
8
9

查看GC日志：

1 Heap
2  garbage-first heap   total 204800K, used 69632K [0x00000000f3800000, 0x00000000f3c00190, 0x0000000100000000)
3   region size 4096K, 18 young (73728K), 0 survivors (0K)
4  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
5   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K 1 2020-09-27T20:46:49.585+0800: 0.197: [GC pause (G1 Evacuation Pause) (young), 0.0023352 secs]
 2    [Parallel Time: 1.1 ms, GC Workers: 10]
 3       [GC Worker Start (ms): Min: 197.2, Avg: 197.3, Max: 197.3, Diff: 0.1]
 4       [Ext Root Scanning (ms): Min: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 1.2]
 5       [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
 6          [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
 7       [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
 8       [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
 9       [Object Copy (ms): Min: 0.2, Avg: 0.3, Max: 0.9, Diff: 0.7, Sum: 3.3]
10       [Termination (ms): Min: 0.0, Avg: 0.6, Max: 0.6, Diff: 0.6, Sum: 5.6]
11          [Termination Attempts: Min: 1, Avg: 6.0, Max: 12, Diff: 11, Sum: 60]
12       [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
13       [GC Worker Total (ms): Min: 1.0, Avg: 1.0, Max: 1.1, Diff: 0.1, Sum: 10.4]
14       [GC Worker End (ms): Min: 198.3, Avg: 198.3, Max: 198.3, Diff: 0.0]
15    [Code Root Fixup: 0.0 ms]
16    [Code Root Purge: 0.0 ms]
17    [Clear CT: 0.5 ms]
18    [Other: 0.7 ms]
19       [Choose CSet: 0.0 ms]
20       [Ref Proc: 0.4 ms]
21       [Ref Enq: 0.0 ms]
22       [Redirty Cards: 0.3 ms]
23       [Humongous Register: 0.0 ms]
24       [Humongous Reclaim: 0.0 ms]
25       [Free CSet: 0.0 ms]
26    [Eden: 100.0M(100.0M)->0.0B(96.0M) Survivors: 0.0B->4096.0K Heap: 100.0M(200.0M)->2935.2K(200.0M)]
27  [Times: user=0.00 sys=0.00, real=0.00 secs] 
28 Heap
29  garbage-first heap   total 204800K, used 2935K [0x00000000f3800000, 0x00000000f3c00190, 0x0000000100000000)
30   region size 4096K, 2 young (8192K), 1 survivors (4096K)
31  Metaspace       used 3047K, capacity 4556K, committed 4864K, reserved 1056768K
32   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
  • 从第2行日志可以看出，总内存 204800K（200M），使用了 69632K（68M）。代码只创建了50M对象，却使用了68M内存，从这也可以看出，G1 比其它回收器要多占很多内存空间。
  • 从第3行日志可以看出，Region 的大小为 4096K（4M），eden 区使用了 18 个 Region，总大小为 73728K（72M），survivor 使用 0 个 Region。

再运行如下代码，大量垃圾对象将堆满 eden 区：

public static void main(String[] args) {
    byte[] b1 = new byte[_1M];

    byte[] b2 = new byte[_1M];
    for (int i = 0; i < 71; i++) {
        b2 = new byte[_1M];
    }
}
1
2
3
4
5
6
7
8
9

查看GC日志：

 1 2020-09-27T20:46:49.585+0800: 0.197: [GC pause (G1 Evacuation Pause) (young), 0.0023352 secs]
 2    [Parallel Time: 1.1 ms, GC Workers: 10]
 3       [GC Worker Start (ms): Min: 197.2, Avg: 197.3, Max: 197.3, Diff: 0.1]
 4       [Ext Root Scanning (ms): Min: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 1.2]
 5       [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
 6          [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
 7       [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
 8       [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
 9       [Object Copy (ms): Min: 0.2, Avg: 0.3, Max: 0.9, Diff: 0.7, Sum: 3.3]
10       [Termination (ms): Min: 0.0, Avg: 0.6, Max: 0.6, Diff: 0.6, Sum: 5.6]
11          [Termination Attempts: Min: 1, Avg: 6.0, Max: 12, Diff: 11, Sum: 60]
12       [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
13       [GC Worker Total (ms): Min: 1.0, Avg: 1.0, Max: 1.1, Diff: 0.1, Sum: 10.4]
14       [GC Worker End (ms): Min: 198.3, Avg: 198.3, Max: 198.3, Diff: 0.0]
15    [Code Root Fixup: 0.0 ms]
16    [Code Root Purge: 0.0 ms]
17    [Clear CT: 0.5 ms]
18    [Other: 0.7 ms]
19       [Choose CSet: 0.0 ms]
20       [Ref Proc: 0.4 ms]
21       [Ref Enq: 0.0 ms]
22       [Redirty Cards: 0.3 ms]
23       [Humongous Register: 0.0 ms]
24       [Humongous Reclaim: 0.0 ms]
25       [Free CSet: 0.0 ms]
26    [Eden: 100.0M(100.0M)->0.0B(96.0M) Survivors: 0.0B->4096.0K Heap: 100.0M(200.0M)->2935.2K(200.0M)]
27  [Times: user=0.00 sys=0.00, real=0.00 secs] 
28 Heap
29  garbage-first heap   total 204800K, used 2935K [0x00000000f3800000, 0x00000000f3c00190, 0x0000000100000000)
30   region size 4096K, 2 young (8192K), 1 survivors (4096K)
31  Metaspace       used 3047K, capacity 4556K, committed 4864K, reserved 1056768K
32   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
  • 第1行日志是触发G1回收的原因，G1 Evacuation Pause 表示疏散停顿，就是将活着的对象从一个区域拷贝到另一个区域。(young) 表示这是发生在年轻代的GC，即 Young GC。
  • 第2行，Parallel Time: 1.1 ms：并行用时1.1毫秒；GC Workers 10：表示 GC 的工作线程是 10 个。
  • 第3~25行就是 Young GC 的详细过程。
  • 第26行，Eden 区回收前是 100M，占用了100M，回收后是 96M，占用 0.0B，Survivor 区从 0.0B 涨到 4096.0K，占用一个 Region，整堆回收前200M，占用了100M，回收后整堆200M，占用 2935.2K。
  • 第29行，堆总大小 204800K（200M），使用了 2935K。
  • 第30行，每个 Region 大小4096K（4M），程序结束后，Eden 区使用了 2 个 Region，占 8192K（8M），Survivor 使用了一个 Region，占 4096K（4M）。

# 混合回收

当老年代的 Region 占了堆内存的 45% （90M）的时候，就会触发混合回收。

运行如下代码：第 2~5 行产生90M对象，第8~11行将触发两次 Young GC，由于GC年龄设置为1，所以 list 这80M对象在两次YoungGC后将进入老年代。

public static void main(String[] args) {
    List<byte[]> list = new ArrayList<>();
    for (int i = 0; i < 90; i++) {
        list.add(new byte[_1M]);
    }

    // 触发两次 Young GC
    byte[] b2 = new byte[_1M];
    for (int i = 0; i < 100; i++) {
        b2 = new byte[_1M];
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13

重点关注这几行日志：

 1 2020-09-27T23:16:05.118+0800: 0.217: [GC pause (G1 Evacuation Pause) (young), 0.0090108 secs]
 2    [Eden: 100.0M(100.0M)->0.0B(84.0M) Survivors: 0.0B->16.0M Heap: 100.0M(200.0M)->95.1M(200.0M)]
 3 2020-09-27T23:16:05.130+0800: 0.228: [GC pause (G1 Evacuation Pause) (young) (to-space exhausted), 0.0031955 secs]
 4    [Eden: 84.0M(84.0M)->0.0B(92.0M) Survivors: 16.0M->8192.0K Heap: 179.1M(200.0M)->124.0M(200.0M)]
 5 2020-09-27T23:16:05.136+0800: 0.235: [GC pause (G1 Evacuation Pause) (young) (initial-mark) (to-space exhausted), 0.0010715 secs]
 6    [Eden: 76.0M(92.0M)->0.0B(100.0M) Survivors: 8192.0K->0.0B Heap: 200.0M(200.0M)->128.0M(200.0M)]
 7  [Times: user=0.00 sys=0.00, real=0.00 secs] 
 8 2020-09-27T23:16:05.137+0800: 0.236: [GC concurrent-root-region-scan-start]
 9 2020-09-27T23:16:05.137+0800: 0.236: [GC concurrent-root-region-scan-end, 0.0000095 secs]
10 2020-09-27T23:16:05.137+0800: 0.236: [GC concurrent-mark-start]
11 2020-09-27T23:16:05.138+0800: 0.237: [GC concurrent-mark-end, 0.0012656 secs]
12 2020-09-27T23:16:05.138+0800: 0.237: [GC remark 2020-09-27T23:16:05.139+0800: 0.237: [Finalize Marking, 0.0001289 secs] 2020-09-27T23:16:05.139+0800: 0.238: [GC ref-proc, 0.0005058 secs] 2020-09-27T23:16:05.139+0800: 0.238: [Unloading, 0.0004047 secs], 0.0013203 secs]
13  [Times: user=0.00 sys=0.00, real=0.00 secs] 
14 2020-09-27T23:16:05.140+0800: 0.239: [GC cleanup 132M->132M(200M), 0.0005312 secs]
15  [Times: user=0.00 sys=0.00, real=0.00 secs] 
16 Heap
17  garbage-first heap   total 204800K, used 135168K [0x00000000f3800000, 0x00000000f3c00190, 0x0000000100000000)
18   region size 4096K, 2 young (8192K), 0 survivors (0K)
19  Metaspace       used 3048K, capacity 4556K, committed 4864K, reserved 1056768K
20   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
  • 第1行日志，由于Eden区满了触发 YoungGC
  • 第2行日志，Eden区回收前占100M（25个Region），使用了100M，回收后占84M（21个Region），使用了0M，Survivor区则占了16M（4个Region）；堆空间占95.1M。
  • 第3行日志，Eden区满了触发了 YoungGC，同时 To Survivor 区也耗尽了（to-space exhausted），就会将新生代存活的对象复制到老年代。
  • 第4行日志，第二次YoungGC前，Eden区占84M，使用了84M，回收后占92M（23个Region），Survivor 区则占8192.0K（2个Region）。堆空间占用124M。
  • 第5行日志，由于老年代的Region超过45%的堆空间了，触发了G1混合回收，混合回收会回收新生代+老年代，于是先执行了 YoungGC，同时进行初始标记（initial-mark）。
  • 第8、9行日志，扫描 GC Roots 分区。
  • 第10、11行日志，并发标记阶段。
  • 第12行日志，最终标记阶段。
  • 第14行日志，清理回收阶段。

从上面Eden区的变化可以看出，Eden区和Survivor区的比例是不断变化的，但是新生代总大小不会超过设定的百分比（默认60%）。

# G1 Full GC

运行如下代码：

public static void main(String[] args) {
    List<byte[]> list = new ArrayList<>();
    for (int i = 0; i < 70; i++) {
        list.add(new byte[_1M]);
    }

    // 触发 Young GC，list 的70M对象将进入老年代
    byte[] b2 = new byte[_1M];
    for (int i = 0; i < 10; i++) {
        b2 = new byte[_1M];
    }

    list = new ArrayList<>(); // 之前的 70M 变为垃圾对象
    for (int i = 0; i < 70; i++) {
        list.add(new byte[_1M]);
    }

    for (int i = 0; i < 70; i++) { // 再塞满 Eden 区，老年代将被塞满，触发 Full GC
        b2 = new byte[_1M];
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

主要看这部分日志：

 1 2020-09-27T22:07:58.115+0800: 0.212: [Full GC (Allocation Failure) 2020-09-27T22:07:58.124+0800: 0.221: [GC concurrent-mark-start]
 2  200M->71M(200M), 0.0104677 secs]
 3    [Eden: 0.0B(100.0M)->0.0B(100.0M) Survivors: 0.0B->0.0B Heap: 200.0M(200.0M)->71.6M(200.0M)], [Metaspace: 3045K->3045K(1056768K)]
 4  [Times: user=0.00 sys=0.00, real=0.01 secs] 
 5 2020-09-27T22:07:58.126+0800: 0.223: [GC concurrent-mark-abort]
 6 Heap
 7  garbage-first heap   total 204800K, used 130627K [0x00000000f3800000, 0x00000000f3c00190, 0x0000000100000000)
 8   region size 4096K, 15 young (61440K), 0 survivors (0K)
 9  Metaspace       used 3052K, capacity 4556K, committed 4864K, reserved 1056768K
10   class space    used 322K, capacity 392K, committed 512K, reserved 1048576K
1
2
3
4
5
6
7
8
9
10
11
  • 看日志第1行，Full GC (Allocation Failure)：最终因老年代放不下导致 Full GC；GC concurrent-mark-start：开始并发标记，因为—旦失败，就立马切换为停止系统程序，然后采用单线程进行标记、清理和压缩整理。

# G1 GC 日志详细参考

关于各种G1回收日志的详细解读参考：www.cnblogs.com/javaadu/p/1… (opens new window)

# 触发GC的原因

前面的GC日志中，括号中展示了触发GC的原因，如 CMS Initial Mark、Allocation Failure 等，还有很多其它的原因可能导致GC。而且不同的垃圾回收器触发GC的时机和原因也可能不同，但大体上来说就是前面提到的一些情况进而导致 YoungGC 或 FullGC。

#include "precompiled.hpp"
#include "gc/shared/gcCause.hpp"

const char* GCCause::to_string(GCCause::Cause cause) {
  switch (cause) {
    case _java_lang_system_gc:
      return "System.gc()";

    case _full_gc_alot:
      return "FullGCAlot";

    case _scavenge_alot:
      return "ScavengeAlot";

    case _allocation_profiler:
      return "Allocation Profiler";

    case _jvmti_force_gc:
      return "JvmtiEnv ForceGarbageCollection";

    case _gc_locker:
      return "GCLocker Initiated GC";

    case _heap_inspection:
      return "Heap Inspection Initiated GC";

    case _heap_dump:
      return "Heap Dump Initiated GC";

    case _wb_young_gc:
      return "WhiteBox Initiated Young GC";

    case _wb_conc_mark:
      return "WhiteBox Initiated Concurrent Mark";

    case _wb_full_gc:
      return "WhiteBox Initiated Full GC";

    case _update_allocation_context_stats_inc:
    case _update_allocation_context_stats_full:
      return "Update Allocation Context Stats";

    case _no_gc:
      return "No GC";

    case _allocation_failure:
      return "Allocation Failure";

    case _tenured_generation_full:
      return "Tenured Generation Full";

    case _metadata_GC_threshold:
      return "Metadata GC Threshold";

    case _metadata_GC_clear_soft_refs:
      return "Metadata GC Clear Soft References";

    case _cms_generation_full:
      return "CMS Generation Full";

    case _cms_initial_mark:
      return "CMS Initial Mark";

    case _cms_final_remark:
      return "CMS Final Remark";

    case _cms_concurrent_mark:
      return "CMS Concurrent Mark";

    case _old_generation_expanded_on_last_scavenge:
      return "Old Generation Expanded On Last Scavenge";

    case _old_generation_too_full_to_scavenge:
      return "Old Generation Too Full To Scavenge";

    case _adaptive_size_policy:
      return "Ergonomics";

    case _g1_inc_collection_pause:
      return "G1 Evacuation Pause";

    case _g1_humongous_allocation:
      return "G1 Humongous Allocation";

    case _dcmd_gc_run:
      return "Diagnostic Command";

    case _last_gc_cause:
      return "ILLEGAL VALUE - last gc cause - ILLEGAL VALUE";

    default:
      return "unknown GCCause";
  }
  ShouldNotReachHere();
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96

# 总结

# 内存参数设置

img

# 垃圾回收触发时机

img

# 文章来源

作者：bojiangzhou 链接：https://juejin.cn/post/6918906374332088327 来源：稀土掘金 著作权归作者所有。商业转载请联系作者获得授权，非商业转载请注明出处。

#JVM#GC#Java
上次更新: 2024-08-19
JVM - 垃圾回收机制
JVM - 内存分配和垃圾回收调优

← JVM - 内存分配和垃圾回收调优→

最近更新
01
开始
01-09
02
AI工具分享
01-09
03
AI 导读
01-07
更多文章>
Theme by Vdoing | Copyright © 2022-2025 Jason Huang | 闽ICP备2025088096号-1