我们动手模拟下 Young GC 的场景，结合 GC 日志去分析 JVM 到底是怎样运行的

参数配置

下面这些参数基于 JDK1.8 版本来配置的，忘记怎么设置的可以回看 07_动手实验：系统部署时如何设置JVM内存大小 的内容

//初始新生代大小 最大新生代大小    初始堆内存大小           最大堆内存大小       Eden区占比新生代比例 大对象阈值                      新生代垃圾器 ParNew 老年代垃圾器 CMS      打印详细 GC 日志     打印每次发生GC的时间    将GC 日志写入磁盘文件
-XX:NewSize=5M -XX:MaxNewSize=5M -XX:InitialHeapSize=10M -XX:MaxHeapSize=10M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log

模拟代码

public static void main(String[] args) {
    byte[] array1 = new byte[1024 * 1024];
    array1 = new byte[1024 * 1024];
    array1 = new byte[1024 * 1024];
    array1 = null;

    byte[] array2 = new byte[2 * 1024 * 1024];
}

上面代码通过 new byte[1024 * 1024] 连续分配了 3 个 1MB 数组，array1 这个局部变量依次引用这三个对象，最后 array1 指向 null

在我们配置的 JVM 参数中，新生代大小为 5M，Eden 区大小为 4M，当给 array2 局部变量分配 2MB 大小数组时，显然 Eden 区已放不下了，如下图所示，此时就会发生 Young GC

GC 日志分析

执行代码之后在当前项目下会有一个 gc.log 文件，内容如下，我们一点一点分析如何看日志

Java HotSpot(TM) 64-Bit Server VM (25.92-b14) for windows-amd64 JRE (1.8.0_92-b14), built on Mar 31 2016 21:03:04 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 25038040k(8306556k free), swap 47862644k(23664868k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
0.169: [GC (Allocation Failure) 0.169: [ParNew: 3660K->0K(4608K), 0.0120803 secs] 4289K->1138K(9728K), 0.0121267 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap
 par new generation   total 4608K, used 2089K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  from space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
  to   space 512K,   0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)
 concurrent mark-sweep generation total 5120K, used 1138K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3342K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 365K, capacity 388K, committed 512K, reserved 1048576K

一次 GC 的概要说明

0.169: [GC (Allocation Failure) 0.169: [ParNew: 3660K->0K(4608K), 0.0120803 secs] 4289K->1138K(9728K), 0.0121267 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

• GC (Allocation Failure)：发生 GC 的原因（分配失败），分配 2MB 内存大小数组时，但是 Eden 区内存不够了

• 0.169：系统运行多少秒发生的本次 GC

• ParNew: 3660K->0K(4608K), 0.0120803 secs

  • ParNew：使用指定的 ParNew 垃圾回收器执行 GC，触发的是 Young GC

  • 3660K->0K(4608K)：年轻代可以用空间是 4608K（4.5MB），Eden区 4MB + Survivor 0.5MB

  • 0.0120803 secs：本次 GC 耗费秒数

• 4289K->1138K(9728K), 0.0121267 secs

  • 9728K：整个 Java堆内存 总可用空间 9728K（9.5MB），年轻代 4.5MB + 老年代 5MB

  • 4289K：GC 前 Java堆内存 使用了 4289K，GC 之后 Java堆内存 使用了 1138K

• [Times: user=0.00 sys=0.00, real=0.01 secs]：本次 GC 耗时，单位为秒

3660K->0K(4608K), 0.0120803 secs，在 Eden 区我们就放了 3 个 1MB 的数组，一共是 3072KB（3MB），为什么日志显示 GC 之前年轻代使用了 3660KB 呢？

• 1、创建的数组本身是 1MB，但是为了存储这个数组，JVM 内置还会附带一些其他信息，所以每个数组实际占用内存是大于 1MB 的

• 2、除了自己创建的对象外，可能还有一些其他对象在 Eden 区，后面可以用专门的工具分析堆内存快照，看到这些其他对象

GC 过后的堆内存使用情况

Heap
 par new generation   total 4608K, used 2089K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  from space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
  to   space 512K,   0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)
 concurrent mark-sweep generation total 5120K, used 1138K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3342K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 365K, capacity 388K, committed 512K, reserved 1048576K

这段日志是 JVM 退出时候打印的当前堆内存使用情况

• par new generation total 4608K, used 2089K：ParNew 垃圾回收器负责的年轻代总共有 4608K（4.5MB） 可用内存，目前使用了 2089K（2MB），这 2MB 是我们代码最后创建的数组

• eden space 4096K, 51% used：Eden 区的 4MB 内存被使用了 51%

• from、to：表示两个 Survivor 的使用情况

• concurrent mark-sweep generation total 5120K, used 1138K：CMS（concurrent mark-sweep） 垃圾回收器管理的老年代空间一共是 5MB，此时使用了 1138KB

• Metaspace、class space：Metaspace元数据空间和 Class 空间，存放类信息、常量池之类的，此时他们的总容量、使用内存等信息

模拟时出现的意外情况

在前面的分析中，我们执行的代码只会发生一次 Young GC，但是在实际的 GC 日志中看到有两次，日志如下

Java HotSpot(TM) 64-Bit Server VM (25.92-b14) for windows-amd64 JRE (1.8.0_92-b14), built on Mar 31 2016 21:03:04 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 25038040k(8306556k free), swap 47862644k(23664868k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
0.167: [GC (Allocation Failure) 0.167: [ParNew: 3251K->512K(4608K), 0.0020524 secs] 3251K->1141K(9728K), 0.0021564 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.169: [GC (Allocation Failure) 0.169: [ParNew: 3660K->0K(4608K), 0.0120803 secs] 4289K->1138K(9728K), 0.0121267 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Heap
 par new generation   total 4608K, used 2089K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  from space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
  to   space 512K,   0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)
 concurrent mark-sweep generation total 5120K, used 1138K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3342K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 365K, capacity 388K, committed 512K, reserved 1048576K

实际上，执行 main 方法也会占用内存空间，我们做如下测试，只创建 1 个 1MB 的数组，也发生了一次 GC

public static void main(String[] args) {
    byte[] array1 = new byte[1024 * 1024];
}

Java HotSpot(TM) 64-Bit Server VM (25.92-b14) for windows-amd64 JRE (1.8.0_92-b14), built on Mar 31 2016 21:03:04 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 25038040k(8474452k free), swap 47862644k(23219700k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 -XX:NewSize=5242880 -XX:OldPLABSize=16 -XX:PretenureSizeThreshold=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
5.205: [GC (Allocation Failure) 5.227: [ParNew: 3153K->512K(4608K), 0.0443193 secs] 3153K->1112K(9728K), 0.0671418 secs] [Times: user=0.00 sys=0.00, real=0.07 secs] 
Heap
 par new generation   total 4608K, used 1701K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  29% used [0x00000000ff600000, 0x00000000ff7296b8, 0x00000000ffa00000)
  from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
  to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
 concurrent mark-sweep generation total 5120K, used 600K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3244K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 359K, capacity 388K, committed 512K, reserved 1048576K