java 七 如何查看 GC 日志

动手实验：自己动手模拟出频繁Young GC的场景体验一下！

如何打印出JVM GC日志？

需要在系统的JVM参数中加入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

解析：

-XX:InitialHeapSize : 初始堆大小
-XX:MaxHeapSize : 最大堆大小
-XX:NewSize : 初始新生代大小
-XX:MaxNewSize : 最大新生代大小
-XX:PretenureSizeThreshold=10485760 : 指定了大对象阈值是10MB。
-XX:+PrintGCDetils：打印详细的gc日志
-XX:+PrintGCTimeStamps：这个参数可以打印出来每次GC发生的时间
-Xloggc:gc.log：这个参数可以设置将gc日志写入一个磁盘文件

示例程序代码

对象是如何分配在Eden区内的

上面的这段代码非常简单，先通过“new byte[1024 * 1024]”这样的代码连续分配了3个数组，每个数组都是1MB
然后通过array1这个局部变量依次引用这三个对象，最后还把array1这个局部变量指向了null
那么在JVM中上述代码是如何运行的呢？
首先我们来看第一行代码：byte[] array1 = new byte[1024 * 1024];。
这行代码一旦运行，就会在JVM的Eden区内放入一个1MB的对象，同时在main线程的虚拟机栈中会压入一个main()方法的栈帧，在main()方法的栈帧内部，会有一个“array1”变量，这个变量是指向堆内存Eden区的那个1MB的数组，如下图。

接着我们看第二行代码：array1 = new byte[1024 * 1024];
此时会在堆内存的Eden区中创建第二个数组，并且让局部变量指向第二个数组，然后第一个数组就没人引用了，此时第一个数组就成了没人引用的“垃圾对象”了，如下图所示。

然后看第三行代码：byte[] array1 = new byte[1024 * 1024];。
这行代码在堆内存的Eden区内创建了第三个数组，同时让array1变量指向了第三个数组，此时前面两个数组都没有人引用了，就都成了垃圾对象，如下图所示。

接着我们来看第四行代码：array1 = null;。
这行代码一执行，就让array1这个变量什么都不指向了，此时会导致之前创建的3个数组全部变成垃圾对象，如下图。

最后看第五行代码：byte[] array2 = new byte[2 * 1024 * 1024];。
此时会分配一个2MB大小的数组，尝试放入Eden区中，因为Eden区总共就4MB大小，而且里面已经放入了3个1MB的数组了，所以剩余空间只有1MB了，此时你放一个2MB的数组是放不下的。所以这个时候就会触发年轻代的Young GC。

获得 gc.log 日志

打开gc.log文件，我们会看到如下所示的gc日志：

Java HotSpot(TM) 64-Bit Server VM (25.151-b12) for windows-amd64 JRE (1.8.0_151-b12), built on Sep  5 2017 19:33:46 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 33450456k(25709200k free), swap 38431192k(29814656k 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.268: [GC (Allocation Failure) 0.269: [ParNew: 4030K->512K(4608K), 0.0015734 secs] 4030K->574K(9728K), 0.0017518 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation   total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
concurrent mark-sweep generation total 5120K, used 62K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K

高级工程师的硬核技能：JVM的Young GC日志应该怎么看

程序运行采用的默认JVM参数如何查看

在GC日志中，可以看到如下内容：
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=5242880 .........
这就是告诉你这次运行程序采取的JVM参数是什么，基本都是我们设置的，同时还有一些参数默认就给设置了，不过一般关系不大。

一次GC的概要说明

接着我们看GC日志中的如下一行：

0.268: [GC (Allocation Failure) 0.269: [ParNew: 4030K->512K(4608K), 0.0015734 secs] 4030K->574K(9728K), 0.0017518 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
解析：
0.268 :系统运行以后过了多少秒发生了本次GC
GC (Allocation Failure) :对象分配失败，此时就要触发一次Young GC

ParNew: 4030K->512K(4608K), 0.0015734 secs
ParNew: 触发的是年轻代的Young GC，所以是用我们指定的ParNew垃圾回收器执行的 GC
(4608K): 年轻代可用空间是4608KB，也就是4.5MB。Eden区是4MB，两个Survivor中只有一个是可以放存活对象的，另外一个是必须一致保持空闲的，所以他考虑年轻代的可用空间，就是Eden+1个Survivor的大小，也就是4.5MB。
4030K->512K: 意思就是对年轻代执行了一次GC，GC之前都使用了4030KB了，但是GC之后只有512KB的对象是存活下来
0.0015734 secs: 这个就是本次gc耗费的时间，看这里来说大概耗费了1.5ms，仅仅是回收3MB的对象而已。

图解GC执行过程

第一个问题，看这行日志，ParNew: 4030K->512K(4608K), 0.0015734 secs
大家很奇怪，我们在GC之前，明明在Eden区里就放了3个1MB的数组，一共是3MB，也就是3072KB的对象，那么GC之前年轻代应该是使用了3072KB的内存啊，为啥是使用了4030KB的内存呢？
其实你创建的数组本身虽然是1MB，但是为了存储这个数组，JVM内置还会附带一些其他信息，所以每个数组实际占用的内存是大于1MB的；
除了你自己创建的对象以外，可能还有一些你看不见的对象在Eden区里，至于这些看不见的未知对象是什么，后面我们有专门的工具可以分析堆内存快照，以后会带你看到这些对象是什么。
所以如下图所示，GC之前，三个数组和其他一些未知对象加起来，就是占据了4030KB的内存。

接着你想要在Eden分配一个2MB的数组，此时肯定触发了“Allocation Failure“，对象分配失败，就触发了Young GC
然后ParNew执行垃圾回收，回收掉之前我们创建的三个数组，此时因为他们都没人引用了，一定是垃圾对象，如下图所示。

然后我们继续看gc日志，ParNew: 4030K->512K(4608K), 0.0015734 secs
gc回收之后，从4030KB内存使用降低到了512KB的内存使用
也就是说这次gc日志有512KB的对象存活了下来，从Eden区转移到了Survivor1区，其实我们可以把称呼改改，叫做Survivor From区，另外一个Survivor叫做Survivor To区，如下图。

GC过后的堆内存使用情况

接着我们看下面的GC日志：

Heap
par new generation   total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
concurrent mark-sweep generation total 5120K, used 62K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K

这段日志是在JVM退出的时候打印出来的当前堆内存的使用情况，其实也很简单，一点点看一下，先看下面这段。

par new generation   total 4608K, used 2601K，这就是说“ParNew”垃圾回收器负责的年轻代总共有4608KB（4.5MB）可用内存，目前是使用了2601KB（2.5MB）。

gc之后，我们这不是通过如下代码又分配了一个2MB的数组吗：byte[] array2 = new byte[2 * 1024 * 1024];
所以此时在Eden区中一定会有一个2MB的数组，也就是2048KB，然后上次gc之后在From Survivor区中存活了一个512KB的对象，大家也不知道是啥，先不用管他。
但是此时你疑惑了，2048KB + 512KB = 2560KB。
那为什么说年轻代使用了2601KB呢？
因为之前说过了每个数组他会额外占据一些内存来存放一些自己这个对象的元数据，所以你可以认为多出来的41KB可以是数组对象额外使用的内存空间。如下图所示。

接着我们继续看GC日志：

eden space 4096K,  51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
to   space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)

通过GC日志就能验证我们的推测是完全准确的，这里说的很清晰了，Eden区此时4MB的内存被使用了51%，就是因为有一个2MB的数组在里面。
然后From Survivor区，512KB是100%的使用率，此时被之前gc后存活下来的512KB的未知对象给占据了。
接着看GC日志：

concurrent mark-sweep generation total 5120K, used 62K，这个很简单，就是说Concurrent Mark-Sweep垃圾回收器，也就是CMS垃圾回收器，管理的老年代内存空间一共是5MB，此时使用了62KB的空间，这个是啥你也先不用管了，可以先忽略不计，以后我们有内存分析工具了，你都能看到。

Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K
上述两段日志就是 Metaspace元数据空间 和 Class空间，存放一些类信息、常量池之类的东西，此时他们的总容量，使用内存，等等。

动手实验：自己动手模拟出对象进入老年代的场景体验一下（上）

动态年龄判定规则

之前我们给大家总结过对象进入老年代的4个常见的时机：

• 躲过15次gc，达到15岁高龄之后进入老年代；
• 动态年龄判定规则，如果Survivor区域内年龄1+年龄2+年龄3+年龄n的对象总和大于Survivor区的50%，此时年龄n以上的对象会进入老年代，不一定要达到15岁
• 如果一次Young GC后存活对象太多无法放入Survivor区，此时直接计入老年代
• 大对象直接进入老年代

首先我们先通过代码给大家模拟出来最常见的一种进入老年代的情况，如果Survivor区域内年龄1+年龄2+年龄3+年龄n的对象总和大于Survivor区的50%，此时年龄n以上的对象会进入老年代，也就是所谓的动态年龄判定规则。
先来看看我们这次示例程序的JVM参数：

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

在这些参数里我们注意几点，新生代我们通过“-XX:NewSize”设置为10MB了
然后其中Eden区是8MB，每个Survivor区是1MB，Java堆总大小是20MB，老年代是10MB，大对象必须超过10MB才会直接进入老年代
但是我们通过“-XX:MaxTenuringThreshold=15”设置了，只要对象年龄达到15岁才会直接进入老年代。
一切准备就绪，先看看我们当前的内存分配情况，如下图，然后接下来我们开始来看看我们的示例代码。

动态年龄判定规则的部分示例代码

部分示例代码运行后产生的gc日志

接着我们把上述示例代码以及我们给出的JVM参数配合起来运行，此时会看到如下的GC日志，接着我们就开始一步一步分析一下这部分代码运行后的gc日志。

0.297: [GC (Allocation Failure) 0.297: [ParNew: 7260K->715K(9216K), 0.0012641 secs] 7260K->715K(19456K), 0.0015046 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation   total 9216K, used 2845K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
eden space 8192K,  26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)
from space 1024K,  69% used [0x00000000ff500000, 0x00000000ff5b2e10, 0x00000000ff600000)
to   space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
concurrent mark-sweep generation total 10240K, used 0K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K

部分代码的GC日志分析

首先我们先看下述几行代码：

在这里连续创建了3个2MB的数组，最后还把局部变量array1设置为了null，所以此时的内存如下图所示：

接着执行了这行代码：byte[] array2 = new byte[128 * 1024];。此时会在Eden区创建一个128KB的数组同时由array2变量来引用，如下图。

然后会执行下面的代码：byte[] array3 = new byte[2 * 1024 * 1024];
此时Eden区里已经有3个2MB的数组和1个128KB的数组，大小都超过6MB了，Eden总共才8MB，此时是不可能让你创建2MB的数组的。
因此此时一定会触发一次Young GC，接着我们开始看GC日志。

ParNew: 7260K->715K(9216K), 0.0012641 secs

这行日志清晰表明了，在GC之前年轻代占用了7260KB的内存，这里大概就是6MB的3个数组 + 128KB的1个数组 + 几百KB的一些未知对象
如下图所示：

接着看这里，7260K->715K(9216K)，一次Young GC过后，剩余的存活对象大概是715KB，大家还记得我们上篇文章分析的GC日志吗？
之前就说过大概年轻代刚开始会有512KB左右的未知对象，此时再加上我们自己的128KB的数组，大家想想，是不是差不多就是700KB？
接着看GC日志如下：

par new generation   total 9216K, used 2845K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
eden space 8192K,  26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)
from space 1024K,  69% used [0x00000000ff500000, 0x00000000ff5b2e10, 0x00000000ff600000)
to   space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
concurrent mark-sweep generation total 10240K, used 0K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

从上面的日志可以清晰看出，此时From Survivor区域被占据了69%的内存，大概就是700KB左右，这就是一次Young GC后存活下来的对象，他们都进入From Survivor区了。
同时Eden区域内被占据了26%的空间，大概就是2MB左右，这就是byte[] array3 = new byte[2 * 1024 * 1024];，这行代码在gc过后分配在Eden区域内的数组
如下图所示：

现在Survivor From区里的那700kb的对象，是几岁呢？答案是：1岁
他熬过一次gc，年龄就会增长1岁。而且此时Survivor区域总大小是1MB，此时Survivor区域中的存活对象已经有700KB了，绝对超过了50%。

完善示例代码

接着我们把示例代码给完善一下，变成上述的样子，我们要触发出来第二次Young GC，然后看看Survivor区域内的动态年龄判定规则能否生效。
先看下面几行代码:

这几行代码运行过后，实际上会接着分配2个2MB的数组，然后再分配一个128KB的数组，最后是让array3变量指向null，如下图所示。

此时接着会运行下面的代码：byte[] array4 = new byte[2 * 1024 * 1024];
这个时候，大家会发现，Eden区如果要再次放一个2MB数组下去，是放不下的了，所以此时必然会触发一次Young GC。
大家使用上述的JVM参数运行这段程序会看到如下的GC日志：

0.269: [GC (Allocation Failure) 0.269: [ParNew: 7260K->713K(9216K), 0.0013103 secs] 7260K->713K(19456K), 0.0015501 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.271: [GC (Allocation Failure) 0.271: [ParNew: 7017K->0K(9216K), 0.0036521 secs] 7017K->700K(19456K), 0.0037342 secs] [Times: user=0.06 sys=0.00, real=0.00 secs]
Heap
par new generation   total 9216K, used 2212K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
eden space 8192K,  27% used [0x00000000fec00000, 0x00000000fee290e0, 0x00000000ff400000)
from space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
to   space 1024K,   0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)
concurrent mark-sweep generation total 10240K, used 700K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K

分析最终版的GC日志

首先第一次GC的日志如下：

0.269: [GC (Allocation Failure) 0.269: [ParNew: 7260K->713K(9216K), 0.0013103 secs] 7260K->713K(19456K), 0.0015501 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

接着第二次GC的日志如下：

0.271: [GC (Allocation Failure) 0.271: [ParNew: 7017K->0K(9216K), 0.0036521 secs] 7017K->700K(19456K), 0.0037342 secs] [Times: user=0.06 sys=0.00, real=0.00 secs] 

第二次触发Yuong GC，就是我们上述代码执行的时候，此时大家发现ParNew: 7017K->0K(9216K)
这行日志表明，这次GC过后，年轻代直接就没有对象了，也就是说没有任何存活对象，你觉得可能吗？
要是这么简单的想，绝对是侮辱自己的智商了，大家还记得array2这个变量一直引用着一个128KB的数组，他绝对是存活对象，还有那500多KB的未知对象，此时都去哪里了呢？
首先我们先看看上面的图，在Eden区里有3个2MB的数组和1个128KB的数组，这绝对是会被回收掉的，如下图所示。

接着其实此时会发现Survivor区域中的对象都是存活的，而且总大小超过50%了，而且年龄都是1岁
此时根据动态年龄判定规则：年龄1+年龄2+年龄n的对象总大小超过了Survivor区域的50%，年龄n以上的对象进入老年代。
当然这里的对象都是年龄1的，所以直接全部进入老年代了，如下图。

大家看下面的日志可以确认这一点：

concurrent mark-sweep generation total 10240K, used 700K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

CMS管理的老年代，此时使用空间刚好是700KB，证明此时Survivor里的对象触发了动态年龄判定规则，虽然没有达到15岁，但是全部进入老年代了。
包括我们自己的那个array2变量一直引用的128KB的数组。
然后array4变量引用的那个2MB的数组，此时就会分配到Eden区域中，如下图所示。

此时大家看下面的日志：

eden space 8192K,  27% used [0x00000000fec00000, 0x00000000fee290e0, 0x00000000ff400000)

这里就说明Eden区当前就是有一个2MB的数组。
然后再看下面的日志：

from space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
to   space 1024K,   0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)

两个Survivor区域都是空的，因为之前存活的700KB的对象都进入老年代了，所以当然现在Survivor里都是空的了。
如果你每次Young GC过后存活的对象太多进入Survivor，特别是超过了Survivor 50%的空间，很可能下次Young GC的时候就会让一些对象触发动态年龄判定规则进入老年代中。

动手实验：自己动手模拟出对象进入老年代的场景体验一下（下）

示例代码

先来看看下面的示例代码：

GC日志

然后我们使用之前的JVM参数来跑一下上面的程序，可以看到下面的GC日志：

0.421: [GC (Allocation Failure) 0.421: [ParNew: 7260K->573K(9216K), 0.0024098 secs] 7260K->2623K(19456K), 0.0026802 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation   total 9216K, used 2703K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
eden space 8192K,  26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)
from space 1024K,  55% used [0x00000000ff500000, 0x00000000ff58f570, 0x00000000ff600000)
to   space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
concurrent mark-sweep generation total 10240K, used 2050K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K

一步一图来分析GC日志

接着我们一点点来分析一下，首先看如下几行代码：

上面的代码中，首先分配了3个2MB的数组，然后最后让array1变量指向了第三个2MB数组
接着创建了一个128K的数组，但是确让array2指向了null，同时我们一直都知道，Eden区里会有500KB左右的未知对象
此时如下图所示：

接着会执行如下代码：byte[] array3 = new byte[2 * 1024 * 1024];。此时想要在Eden区里再创建一个2MB的数组，肯定是不行的，所以此时必然触发一次Young GC。
先看如下日志：

ParNew: 7260K->573K(9216K), 0.0024098 secs。

这里清晰说明了，本次GC过后，年轻代里就剩下了500多KB的对象
这是为什么呢？此时明明array1变量是引用了一个2MB的数组的啊！
其实道理很简单，大家可以想一下，这次GC的时候，会回收掉上图中的2个2MB的数组和1个128KB的数组，然后留下一个2MB的数组和1个未知的500KB的对象,如下图所示。

那么此时剩下来的2MB的数组和500KB的未知对象能放入From Survivor区吗？
答案是：不能
因为Survivor区仅仅只有1MB。根据我们之前说过的规则，此时是不是要把这些存活对象全部放入老年代？
答案：也不是
大家看如下日志：

eden space 8192K,  26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)

首先Eden区内一定放入了一个新的2MB的数组，就是刚才最后想要分配的那个数组，由array3变量引用，如下图。

其次，看下面的日志：

from space 1024K,  55% used [0x00000000ff500000, 0x00000000ff58f570, 0x00000000ff600000)

大家发现此时From Survivor区中有500KB的对象，其实就是那500KB的未知对象！
所以在这里并不是让2MB的数组和500KB的未知对象都进入老年代，而是把500KB的未知对象放入From Survivor区中！
但是现在结合GC日志，大家可以清晰的看到，在这种情况下，是会把部分对象放入Survivor区的。
此时如下图所示。

接着我们看如下日志：

concurrent mark-sweep generation total 10240K, used 2050K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)

此时老年代里确有2MB的数组，因此可以认为，Young GC过后，发现存活下来的对象有2MB的数组和500KB的未知对象。
此时把500KB的未知对象放入Survivor中，然后2MB的数组直接放入老年代，如下图。

高级工程师的硬核技能：JVM的Full GC日志应该怎么看？

示例代码

GC日志

采用如下参数来运行上述程序：

"-XX:NewSize=10485760 -XX:MaxNewSize=10485760 -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:SurvivorRatio=8  -XX:MaxTenuringThreshold=15 -XX:PretenureSizeThreshold=3145728 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log"

这里最关键一个参数，就是“-XX:PretenureSizeThreshold=3145728”
这个参数要设置大对象阈值为3MB，也就是超过3MB，就直接进入老年代。
运行之后会得到如下GC日志：

“0.308: [GC (Allocation Failure) 0.308: [ParNew (promotion failed): 7260K->7970K(9216K), 0.0048975 secs]0.314: [CMS: 8194K->6836K(10240K), 0.0049920 secs] 11356K->6836K(19456K), [Metaspace: 2776K->2776K(1056768K)], 0.0106074 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap
par new generation   total 9216K, used 2130K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
eden space 8192K,  26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)
from space 1024K,   0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)
to   space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
concurrent mark-sweep generation total 10240K, used 6836K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
Metaspace       used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
class space    used 300K, capacity 386K, committed 512K, reserved 1048576K”

一步一图分析日志

首先我们看如下代码：

这行代码直接分配了一个4MB的大对象，此时这个对象会直接进入老年代，接着array1不再引用这个对象
此时如下图所示。

接着看下面的代码：

连续分配了4个数组，其中3个是2MB的数组，1个是128KB的数组，如下图所示，全部会进入Eden区域中

接着会执行如下代码：byte[] array6 = new byte[2 * 1024 * 1024];。此时还能放得下2MB的对象吗？不可能了，因为Eden区已经放不下了。因此此时会直接触发一次Young GC。
我们看下面的GC日志：

ParNew (promotion failed): 7260K->7970K(9216K), 0.0048975 secs

这行日志显示了，Eden区原来是有7000多KB的对象，但是回收之后发现一个都回收不掉，因为上述几个数组都被变量引用了。
所以此时大家都知道，一定会直接把这些对象放入到老年代里去，但是此时老年代里已经有一个4MB的数组了，还能放的下3个2MB的数组和1个128KB的数组吗？
明显是不行的，此时一定会超过老年代的10MB大小。
所以此时我们看gc日志：

[CMS: 8194K->6836K(10240K), 0.0049920 secs] 11356K->6836K(19456K), [Metaspace: 2776K->2776K(1056768K)], 0.0106074 secs]

大家可以清晰看到，此时执行了CMS垃圾回收器的Full GC，我们之前讲过Full GC其实就是会对老年代进行Old GC，同时一般会跟一次Young GC关联，还会触发一次元数据区（永久代）的GC。
在CMS Full GC之前，就已经触发过Young GC了，此时大家可以看到此时Young GC就已经有了，接着就是执行针对老年代的Old GC，也就是如下日志：

CMS: 8194K->6836K(10240K), 0.0049920 secs

这里看到老年代从8MB左右的对象占用，变成了6MB左右的对象占用，这是怎么个过程呢？
很简单，一定是在Young GC之后，先把2个2MB的数组放入了老年代，如下图。

此时要继续放1个2MB的数组和1个128KB的数组到老年代，一定会放不下，所以此时就会触发CMS的Full GC
然后此时就会回收掉其中的一个4MB的数组，因为他已经没人引用了，如下图所示。

接着放入进去1个2MB的数组和1个128KB的数组，如下图所示。

所以大家再看CMS的垃圾回收日志：

CMS: 8194K->6836K(10240K), 0.0049920 secs

他是从回收前的8MB变成了6MB，就是上图所示。
最后在CMS Full GC执行完毕之后，其实年轻代的对象都进入了老年代，此时最后一行代码要在年轻代分配2MB的数组就可以成功了，如下图。