Ref: https://www.cnblogs.com/klvchen/articles/11841337.html

1.GC 日志获取

1.1 如何打印出 JVM GC 日志

需要在系统的JVM参数中加入 GC 日志的打印选型,jvm参数如下所示:

  1. -XX:NewSize=5242880 -XX:MaxNewSize=5242880
  2. -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760
  3. -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10485760
  4. -XX:+UseParNewGC -XX:+UseConcMarkSweepGC
  5. -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 日志写入一个磁盘文件

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

    示例程序代码:
    image.png
    上面的这段代码非常简单,先通过 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 的数组,如下图:
image.png
接着我们看第二行代码:array1 = new byte[1024 * 1024]
此时会在堆内存的 Eden 区中创建第二个数组,并且让局部变量指向第二个数组,然后第一个数组就没人引用了,此时第一个数组就成了没人引用的“垃圾对象”了,如下图所示。
image.png
然后看第三行代码:byte[] array1 = new byte[1024 * 1024]
这行代码在堆内存的Eden区内创建了第三个数组,同时让array1变量指向了第三个数组,此时前面两个数组都没有人引用了,就都成了垃圾对象,如下图所示。
image.png
接着我们来看第四行代码:array1 = null
这行代码一执行,就让 array1 这个变量什么都不指向了,此时会导致之前创建的 3 个数组全部变成垃圾对象,如下图。
image.png
最后看第五行代码:byte[] array2 = new byte[2 * 1024 * 1024];
此时会分配一个 2MB 大小的数组,尝试放入 Eden 区中,因为 Eden 区总共就 4MB 大小,而且里面已经放入了 3 个 1MB 的数组了,所以剩余空间只有 1MB 了,此时你放一个 2MB 的数组是放不下的。所以这个时候就会触发年轻代的 Young GC。

1.3 获得 gc.log 日志

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

  1. 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)
  2. Memory: 4k page, physical 33450456k(25709200k free), swap 38431192k(29814656k free)
  3. 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
  4. 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]
  5. Heap
  6. par new generation total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  7. eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  8. from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
  9. to space 512K, 0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
  10. concurrent mark-sweep generation total 5120K, used 62K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
  11. Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
  12. class space used 300K, capacity 386K, committed 512K, reserved 1048576K

2.Young GC 日志分析

2.1 查看程序运行采用的 JVM 参数

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

2.2 一次 GC 的概要说明

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

  1. 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 的对象而已。

    2.3 图解 GC 执行过程

    第一个问题,看这行日志,ParNew: 4030K->512K(4608K), 0.0015734 secs
    GC 之前,明明在Eden区里就放了 3 个 1MB 的数组,一共是 3MB,也就是 3072KB 的对象,年轻代为啥使用了 4030KB 的内存呢?

创建的数组本身虽然是 1MB,但是为了存储这个数组,JVM 内置还会附带一些其他信息,所以每个数组实际占用的内存是大于 1MB 的;
除了创建的对象以外,可能还有一些你看不见的对象在 Eden 区里,至于这些看不见的未知对象是什么,后面我们有专门的工具可以分析堆内存快照。
如下图所示,GC 之前三个数组和其他一些未知对象加起来,就是占据了 4030KB 的内存。
image.png
接着你想要在 Eden 分配一个 2MB 的数组,此时肯定触发了“Allocation Failure”,对象分配失败,就触发了 Young GC。
然后 ParNew 执行垃圾回收,回收掉之前我们创建的三个数组,此时因为他们都没人引用了,一定是垃圾对象,如下图所示。
image.png
然后我们继续看 GC 日志:ParNew: 4030K->512K(4608K), 0.0015734 secs
gc 之后,从 4030KB 内存使用降低到了 512KB 的内存使用
这次 GC 日志有 512KB 的对象存活了下来,从 Eden 区转移到了 Survivor1 区(Survivor From),另外一个 Survivor 叫做 Survivor To 区,如下图:
image.png

2.4 GC 过后的堆内存使用情况

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

  1. Heap
  2. par new generation total 4608K, used 2601K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  3. eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  4. from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
  5. to space 512K, 0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
  6. concurrent mark-sweep generation total 5120K, used 62K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
  7. Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
  8. 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 可以是数组对象额外使用的内存空间。如下图所示:
image.png
继续看 GC 日志:

  1. eden space 4096K, 51% used [0x00000000ff600000, 0x00000000ff80a558, 0x00000000ffa00000)
  2. from space 512K, 100% used [0x00000000ffa80000, 0x00000000ffb00000, 0x00000000ffb00000)
  3. 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 的空间(暂不关注),后续使用内存分析工具查看。

  1. Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
  2. class space used 300K, capacity 386K, committed 512K, reserved 1048576K

上述两段日志就是 Metaspace 元数据空间 和 Class空间,存放一些类信息、常量池之类的东西,此时他们的总容量,使用内存,等等。

3.模拟对象进入老年代场景

3.1 动态年龄判定规则

之前我们给大家总结过对象进入老年代的 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 参数:

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

在这些参数里我们注意几点,新生代我们通过“-XX:NewSize”设置为 10MB 了,
然后其中 Eden 区是 8MB,每个 Survivor 区是 1MB,Java 堆总大小是 20MB,老年代是 10MB,大对象必须超过 10MB 才会直接进入老年代;
但是我们通过 -XX:MaxTenuringThreshold=15 设置了,只要对象年龄达到 15 岁才会直接进入老年代。

一切准备就绪,先看看我们当前的内存分配情况,如下图:
image.png
动态年龄判定规则的部分示例代码:
image.png
接着我们把上述示例代码以及我们给出的 JVM 参数配合起来运行,此时会看到如下的 GC 日志:

  1. 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]
  2. Heap
  3. par new generation total 9216K, used 2845K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  4. eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)
  5. from space 1024K, 69% used [0x00000000ff500000, 0x00000000ff5b2e10, 0x00000000ff600000)
  6. to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
  7. concurrent mark-sweep generation total 10240K, used 0K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  8. Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
  9. class space used 300K, capacity 386K, committed 512K, reserved 1048576K

3.2 部分代码的 GC 日志分析

首先我们先看下述几行代码:
image.png
连续创建了 3 个 2MB 的数组,最后还把局部变量 array1 设置为了 null,所以此时的内存如下图所示:
image.png
接着执行了这行代码:byte[] array2 = new byte[128 * 1024]
此时会在 Eden 区创建一个 128KB 的数组同时由 array2 变量来引用,如下图:
image.png
然后会执行下面的代码: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 的一些未知对象。
如下图所示:
image.png
接着看这里,7260K->715K(9216K),一次 Young GC 过后,剩余的存活对象大概是 715KB,年轻代刚开始会有 512KB 左右的未知对象,此时再加上我们自己的 128KB 的数组,大家想想,是不是差不多就是 700KB?

接着看 GC 日志如下:

  1. par new generation total 9216K, used 2845K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  2. eden space 8192K, 26% used [0x00000000fec00000, 0x00000000fee14930, 0x00000000ff400000)
  3. from space 1024K, 69% used [0x00000000ff500000, 0x00000000ff5b2e10, 0x00000000ff600000)
  4. to space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
  5. 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 区域内的数组
如下图所示:
image.png
现在 Survivor From 区里的那 700KB 的对象,是几岁呢?答案是:1岁
他熬过一次 gc,年龄就会增长 1 岁。而且此时 Survivor 区域总大小是 1MB,此时 Survivor 区域中的存活对象已经有 700KB 了,绝对超过了 50%。

接着我们把示例代码给完善一下,要触发出来第二次 Young GC,然后看看 Survivor 区域内的动态年龄判定规则能否生效。完善示例代码:
image.png
先看下面几行代码:
image.png
这几行代码运行过后,实际上会接着分配 2 个 2MB 的数组,然后再分配一个 128KB 的数组,最后是让 array3 变量指向 null,如下图所示。
image.png
此时接着会运行下面的代码:byte[] array4 = new byte[2 * 1024 * 1024]
这个时候,大家会发现,Eden 区如果要再次放一个 2MB 数组下去,是放不下的了,所以此时必然会触发一次 Young GC。
大家使用上述的 JVM 参数运行这段程序会看到如下的 GC 日志:

  1. 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]
  2. 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]
  3. Heap
  4. par new generation total 9216K, used 2212K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  5. eden space 8192K, 27% used [0x00000000fec00000, 0x00000000fee290e0, 0x00000000ff400000)
  6. from space 1024K, 0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
  7. to space 1024K, 0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)
  8. concurrent mark-sweep generation total 10240K, used 700K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  9. Metaspace used 2782K, capacity 4486K, committed 4864K, reserved 1056768K
  10. class space used 300K, capacity 386K, committed 512K, reserved 1048576K

3.3 分析最终版的 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 的数组,他绝对是存活对象,还有那 500KB 多的未知对象,此时都去哪里了呢?

首先我们先看看上面的图,在 Eden 区里有 3 个 2MB 的数组和 1 个 128KB 的数组,这绝对是会被回收掉的,如下图所示。
image.png
接着其实此时会发现 Survivor 区域中的对象都是存活的,而且总大小超过 50% 了,而且年龄都是 1 岁
此时根据动态年龄判定规则:年龄1+年龄2+年龄n的对象总大小超过了 Survivor 区域的 50%,年龄 n 以上的对象进入老年代。
当然这里的对象都是年龄 1 的,所以直接全部进入老年代了,如下图:
image.png
大家看下面的日志可以确认这一点:

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

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

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 的时候就会让一些对象触发动态年龄判定规则进入老年代中。

4.模拟对象进入老年代场景(下)

先来看看下面的示例代码:
image.png
然后我们使用之前的 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

接着我们一点点来分析一下,首先看如下几行代码:
image.png
上面的代码中,首先分配了 3 个 2MB 的数组,然后最后让 array1 变量指向了第三个 2MB 数组
接着创建了一个 128K 的数组,但是确让 array2 指向了 null,同时我们一直都知道,Eden 区里会有 500KB 左右的未知对象。此时如下图所示:
image.png
接着会执行如下代码:byte[] array3 = new byte[2 * 1024 * 1024]
此时想要在 Eden 区里再创建一个 2MB 的数组,肯定是不行的,所以此时必然触发一次 Young GC。
先看如下日志:
ParNew: 7260K->573K(9216K), 0.0024098 secs
这里清晰说明了,本次 GC 过后,年轻代里就剩下了 500KB 的对象
这是为什么呢?此时明明 array1 变量是引用了一个2MB的数组的啊!
其实道理很简单,大家可以想一下,这次 GC 的时候,会回收掉上图中的2个2MB的数组和1个128KB的数组,然后留下一个 2MB 的数组和 1 个未知的 500KB 的对象,如下图所示。
image.png
那么此时剩下来的 2MB 的数组和 500KB 的未知对象能放入 From Survivor 区吗?
答案是:不能
因为 Survivor 区仅仅只有1MB。根据我们之前说过的规则,此时是不是要把这些存活对象全部放入老年代?
答案:也不是
大家看如下日志:

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

首先 Eden 区内一定放入了一个新的 2MB 的数组,就是刚才最后想要分配的那个数组,由 array3 变量引用,如下图。
image.png
其次,看下面的日志:

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

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

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

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

5.Full GC 日志分析

示例代码:
image.png
采用如下参数来运行上述程序:

-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”

首先我们看如下代码:
image.png
这行代码直接分配了一个 4MB 的大对象,此时这个对象会直接进入老年代,接着 array1 不再引用这个对象。此时如下图所示:
image.png
接着看下面的代码:
image.png
连续分配了 4 个数组,其中 3 个是 2MB 的数组,1 个是 128KB 的数组,全部会进入 Eden 区域中。如下图所示:
image.png
接着会执行如下代码:byte[] array6 = new byte[2 * 1024 * 1024]
因为 Eden 区已经放不下了。因此此时会直接触发一次 Young GC。
我们看下面的 GC 日志:
ParNew (promotion failed): 7260K->7970K(9216K), 0.0048975 secs
这行日志显示了,Eden区原来是有 7000KB 的对象,但是回收之后发现一个都回收不掉,因为上述几个数组都被变量引用了。
所以此时大家都知道,一定会直接把这些对象放入到老年代里去,但是此时老年代里已经有一个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 的数组放入了老年代,如下图。
image.png
此时要继续放 1 个 2MB 的数组和 1 个 128KB 的数组到老年代,一定会放不下,所以此时就会触发 CMS 的 Full GC。
然后此时就会回收掉其中的一个 4MB 的数组,因为他已经没人引用了。如下图所示:
image.png
接着放入进去 1 个 2MB 的数组和 1 个 128KB 的数组,如下图所示。
image.png
所以大家再看 CMS 的垃圾回收日志:
CMS: 8194K->6836K(10240K), 0.0049920 secs
他是从回收前的 8MB 变成了 6MB,就是上图所示。
最后在 CMS Full GC 执行完毕之后,其实年轻代的对象都进入了老年代,此时最后一行代码要在年轻代分配 2MB 的数组就可以成功了,如下图。
image.png