JVM实战（16）——模拟Young GC

作者简介：大家好，我是smart哥，前中兴通讯、美团架构师，现某互联网公司CTO

联系qq：184480602，加我进群，大家一起学习，一起进步，一起对抗互联网寒冬

学习必须往深处挖，挖的越深，基础越扎实！

阶段1、深入多线程

阶段2、深入多线程设计模式

阶段3、深入juc源码解析

阶段4、深入jdk其余源码解析

阶段5、深入jvm源码解析

一、简介

本章，我们将通过示例代码演示Young GC是如何发生的。同时，我们会讲解如何通过JVM参数去配置打印GC日日，然后通过GC日志分析JVM中的GC到底是如何运行的。

1.1 JVM内存参数

我们的示例程序基于JDK1.8，JVM参数如下：
-XX:NewSize=5242880 -XX:MaxNewSize=5242880 -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC

上述参数中：

-XX:NewSize=5242880 -XX:MaxNewSize=5242880：新生代大小5MB
-XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760：Java堆内存10MB
-XX:SurvivorRatio=8：Eden区占4MB，Survivor各占0.5MB
-XX:PretenureSizeThreshold=10485760：大对象阈值10MB
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC：新生代使用ParNew，老年代使用CMS

1.2 GC日志参数

我们需要在系统的JVM参数中加入GC日志的打印选型：

-XX:+PrintGCDetails：打印详细的GC日志
-XX:+PrintGCTimeStamps：打印每次GC发生的时间
-Xloggc:gc.log：设置将GC日志写入一个磁盘文件

加入日志参数后，JVM的参数如下：

-XX:NewSize=5242880 -XX:MaxNewSize=5242880 -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log

二、示例程序

2.1 程序源码

示例程序代码如下：

    public class Demo1 {
        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];
        }
    }

2.2 JVM内存模型

我们根据上述代码来分析下对象是如何在Eden区分配的。

首先，main方法里的第一行代码会为Eden区创建一个1MB的byte数组，第2-3行代码array1局部变量重新赋值引用：

第4行代码array1=null，这时之前的3个数组对象都失去了引用：

第5行代码byte[] array2 = new byte[2 * 1024 * 1024]，尝试创建一个2MB的对象放入Eden区，但是Eden区已经空间不足了，所以这时就会触发新生代的Young GC。

2.3 程序执行

当使用IDE执行程序时，我们先要进行JVM参数配置，以IDEA为例，配置如下：

运行完成后，工程目录下会出现GC日志文件：gc.log，内容如下：

    Java HotSpot(TM) 64-Bit Server VM (25.111-b14) for windows-amd64 JRE (1.8.0_111-b14), built on Sep 22 2016 19:24:05 by "java_re" with MS VC++ 10.0 (VS2010)
    Memory: 4k page, physical 12470176k(6211924k free), swap 14370720k(6127712k 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.242: [GC (Allocation Failure) 0.242: [ParNew: 4094K->512K(4608K), 0.0018168 secs] 4094K->1696K(9728K), 0.0020491 secs] [Times: user=0.05 sys=0.02, real=0.00 secs] 
    Heap
     par new generation   total 4608K, used 3702K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
      eden space 4096K,  77% used [0x00000000ff600000, 0x00000000ff91d978, 0x00000000ffa00000)
      from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
      to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
     concurrent mark-sweep generation total 5120K, used 1184K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
     Metaspace       used 3484K, capacity 4498K, committed 4864K, reserved 1056768K
      class space    used 387K, capacity 390K, committed 512K, reserved 1048576K

三、日志分析

本节，我们来分析下上述的gc.log日志。

3.1 GC情况概览

我们先来看下日志中的如下行，这是本次GC情况的概要说明：

    0.242: [GC (Allocation Failure) 0.242: [ParNew: 4094K->512K(4608K), 0.0018168 secs] 4094K->1696K(9728K), 0.0020491 secs] [Times: user=0.05 sys=0.02, real=0.00 secs]

GC (Allocation Failure) ： 说明了为啥发生GC，因为对象分配失败，也就是上述的Eden区空间不足了；

0.242： 系统运行了0.242秒以后，发生了本次GC；

ParNew: 4094K->512K(4608K), 0.0018168 secs： 使用ParNew进行新生代的GC，GC前新生代使用了4094K，GC完成后新生代使用了512K，4608K表示年轻代的总空间（Eden+1个Survivor），本次GC耗时0.0018168秒；

4094K->1696K(9728K), 0.0020491 secs： Java堆内存的总空间为8728K，GC前使用了4094K，GC后使用了1696K；

Times: user=0.05 sys=0.02, real=0.00 secs： 本次GC消耗的时间，与元数据区有关，后续讲解。

根据GC日志可以看出，本轮Young GC有512K对象存活下来了，从Eden区转移到了Survivor区：

3.2 JVM退出时堆内存

我们接着看下面的GC日志，这是 JVM退出时当前Java堆内存的使用情况 ：

    Heap
     par new generation   total 4608K, used 3702K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
      eden space 4096K,  77% used [0x00000000ff600000, 0x00000000ff91d978, 0x00000000ffa00000)
      from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
      to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)

par new generation total 4608K, used 3702K： ParNew负责的新生代总共有4608K内存，目前使用了3702K；

eden space 4096K, 77% used： Eden总共使用了4096K

from space 512K, 100% used： From Survivor区使用了100%（存放转移过来的未知存活对象）

to space 512K, 0% used： To Survivor区未使用

我们接着看：

    concurrent mark-sweep generation total 5120K, used 1184K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
    Metaspace       used 3484K, capacity 4498K, committed 4864K, reserved 1056768K
    class space    used 387K, capacity 390K, committed 512K, reserved 1048576K

concurrent mark-sweep generation total 5120K, used 1184K： 使用CMS管理的老年代总空间为5210K，已使用1184K

Metaspace used 3484K, capacity 4498K, committed 4864K, reserved 1056768K： 元数据区的空间信息

class space used 387K, capacity 390K, committed 512K, reserved 1048576K： Class空间信息