JVM 探究（二）：JVM实验和GC日志解读
date
Nov 30, 2017
slug
experiment-on-jvm
status
Published
tags
Dev
summary
本文用于记录在学习 JVM 过程中的实验，在完成《深入理解Java虚拟机》第二版第三章中的实验的基础上，同时保证在
JDK1.8上实验的可重复性，并且针对不同的垃圾收集器做实验扩充。在对不能在JDK8上重现的实验代码做了修正，在实验结果中分析了JVM的部分特性, 介绍了GC日志的解读等。type
Post
本文用于记录在学习 JVM 过程中的实验，在完成《深入理解Java虚拟机》第二版第三章中的实验的基础上，同时保证在
JDK1.8上实验的可重复性，并且针对不同的垃圾收集器做实验扩充。在对不能在JDK8上重现的实验代码做了修正，在实验结果中分析了JVM的部分特性, 介绍了GC日志的解读等。GC 日志含义
GC 日志理解起来十分简单，因为日志本来就是要给开发人员看的，所以设计的很直观。
举个例子，我们来分别说明各个部分所代表的含义：
[GC (Allocation Failure) [ParNew: 7989K->424K(9216K), 0.0037834 secs] 7989K->6568K(19456K), 0.0038147 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]将上面 GC 日志抽象为各个部分，然后我们再分别说明各个部分的含义
[a(b)[c:d->e(f), g secs] h->i(j), k secs] [Times: user:l sys=m, real=n secs]a: GC 或者是 Full GC， 这里引用一句话
“GC日志开头的“[GC”和“[Full GC”说明了这次垃圾收集的停顿类型，而不是用来区分新生代GC还是老年代GC的。如果有“Full”，说明这次GC是发生了Stop-The-World的”摘录来自: 周志明. “深入理解Java虚拟机：JVM高级特性与最佳实践（第2版）”。 iBooks.
b: 用来说明发生这次 GC 的原因，我们例子中发生这次GC的原因是内存分配失败
c: 表示发生GC的区域，这里表示是新生代发生了GC，上面那个例子是因为在新生代中内存不够给新对象分配了，然后触发了 GC
d: GC 之前该区域已使用的容量
e: GC 之后该区域已使用的容量
f: 该内存区域的总容量
g: 表示该区域这次 GC 使用的时间
h: 表示 GC 前整个堆的已使用容量
i: 表示 GC 后整个堆的已使用容量
j: 表示 Java 堆的总容量
k: 表示 Java堆 这次 GC 使用的时间
l: 代表用户态消耗的 CPU 时间
m: 代表内核态消耗的 CPU 时间
n: 整个 GC 事件从开始到结束的墙钟时间（Wall Clock Time）
“CPU时间与墙钟时间的区别是，墙钟时间包括各种非运算的等待耗时，例如等待磁盘I/O、等待线程阻塞，而CPU时间不包括这些耗时，但当系统有多CPU或者多核的话，多线程操作会叠加这些CPU时间，所以读者看到user或sys时间超过real时间是完全正常的。”摘录来自: 周志明. “深入理解Java虚拟机：JVM高级特性与最佳实践（第2版）”。 iBooks.
名词解释
“新生代GC（Minor GC)：指发生在新生代的垃圾收集动作，因为Java对象大多都具备朝生夕灭的特性，所以Minor GC非常频繁，一般回收速度也比较快。老年代GC（Major GC/Full GC）：指发生在老年代的GC，出现了Major GC，经常会伴随至少一次的Minor GC（但非绝对的，在Parallel Scavenge收集器的收集策略里就有直接进行Major GC的策略选择过程）。Major GC的速度一般会比Minor GC慢10倍以上。”摘录来自: 周志明. “深入理解Java虚拟机：JVM高级特性与最佳实践（第2版）”。 iBooks.
常用垃圾收集器参数
参数 | 描述 |
UseSerialGC | 虚拟机在运行在 Client 模式下的默认值，打开此开关后，使用 Serial+Serial Old 收集器组合进行内存回收 |
UseParNewGC | 使用 ParNew + Serial Old 收集器组合进行内存回收 |
UseConcMarkSweepGC | 使用 ParNew + CMS + Serial Old 的收集器组合进行内存回收，当 CMS 出现 Concurrent Mode Failure 失败后会使用 Serial Old 作为备用收集器 |
UseParallelOldGC | 使用 Parallel Scavenge + Parallel Old 的收集器组合 |
UseParallelGC | 使用 Parallel Scavenge + Serial Old （PS MarkSweep）的收集器组合 |
SurvivorRatio | 新生代中 Eden 和任何一个 Survivor 区域的容量比值，默认为 8 |
PretenureSizeThreshold | 直接晋升到老年代对象的大小，单位是Byte |
MaxTenuringThreshold | 晋升到老年代的对象最大年龄 |
UseAdaptiveSizePolicy | 动态调整 Java 堆中各区域的大小以及进入老年代的年龄 |
HandlePromotionFailure | 是否允许分配担保失败 |
ParallelGCThreads | 设置并行 GC 时进行内存回收的线程数 |
GCTimeRatio | GC 时间站占时间的比率，默认值为99，只在 Parallel Scavenge 收集器的时候生效 |
MaxGCPauseMillis | 设置 GC 最大的停顿时间，只在 Parallel Scavenge 收集器的时候生效 |
CMSInitiatingOccupancyFraction | 设置 CMS 收集器在老年代空间被使用多少后触发垃圾收集，默认是 68%，仅在 CMS 收集器上生效 |
CMSFullGCsBeforeCompaction | 设置 CMS 收集器在进行多少次垃圾回收之后启动一次内存碎片整理 |
注：上表摘录来自: 周志明. “深入理解Java虚拟机：JVM高级特性与最佳实践（第2版）”，稍有调整.
实验代码
实验
实验一：使用ParNew+Serial Old的组合进行内存回收
对象优先在 Eden 区分配
实验结果：
实验分析：
通过上面的GC日志我们可以看出一开始出现了 MinorGC, 引起GC的原因是
内存分配失败，因为分配allocation4的时候，Eden区已经没有足够的区域来分配了，所以发生了本次 MinorGC ，经过 MinorGC 之后新生代的已使用容量从7989K减少到了424K，然而整个堆的内存总量却几乎没有减少，原因就是，由于发现新生代没有可以回收的对象，所以不得不使用内存担保将allocation1～3 三个对象提前转移到老年代。此时再在 Eden 区域为 allocation4 分配 4MB 的空间，因此最后我们发现 Eden 区域占用了 4MB，老年代占用了 6MB实验二：使用Parallel Scavenge+Serial Old的组合进行内存回收
对象优先在 Eden 区分配
实验结果
实验分析
第一眼看到日志惊奇的发现居然没有发生任何类型的 GC， 起初看到日志的时候我也很惊奇，于是乎请出了Java内存分析工具
VisualVM, JDK中会自带JVisualVM 效果类似，可以通过命令jvisualvm启动，具体分析方法可以参考我的另外一篇博客VisualVM使用指南。注： 如果想要重现下面的分析结果，除了JVM参数要和我一直外，在程序执行过程中务必设置几个断点，好让VisualVM能够出现这种阶梯图像，不然由于执行太快，看起来就像是一次性分配了内存一样。
堆内存占用情况分析
通过上图中我标出的五条线，可以看到在1位置的时候第一次在Eden中分配了 2MB 内存，然后在2，3，4 时刻分别又再次分配了 2MB 内存，此时 Eden 区域已经占用了 8MB 了，在 5 时刻当要分配 4MB 内存的时候，Eden 区域已经不够用了，直接分配到了
老年代。这是因为Parallel Scavenge收集器为了保证吞吐量而直接将Eden区中无法存放的大对象直接放到了老年代。注： 虚拟机参数 -XX：PretenureSizeThreshold 并不是实验二中的大对象分配到老年代的直接控制参数，该参数只针对 Serial 和 ParNew 两个新生代收集器有作用。 该参数的作用在下一节大对象直接进入老年代的实验中讲解。
使用其他收集器组合探究对象的分配情况
由于篇幅有限，其实是我想偷懒了（＾∇＾），各位可以参考上面的垃圾收集器参数章节，自己去验证。
实验三：使用参数XX:PretenureSizeThreshold来设置直接进入老年代的对象的大小
大对象直接进入老年代
虚拟机提供一个参数
-XX:PretenureSizeThreshold 用来设置直接在老年代分配的对象的大小，如果对象大于这个值就会直接在老年代分配。这样做的目的是避免在Eden区及两个Survivor区之间发生大量的内存复制。“比遇到一个大对象更加坏的消息就是遇到一群“朝生夕灭”的“短命大对象”，写程序的时候应当避免”摘录来自: 周志明. “深入理解Java虚拟机：JVM高级特性与最佳实践（第2版）”。 iBooks.
实验结果：
实验分析
通过上面的堆的内存占用情况很容易看出我们分配的4MB大小的对象直接被放到了老年代
实验四： 使用参数XX:MaxTenuringThreshold=1来设置进入老年代的对象年龄
长期存活的对象将进入老年代
实验结果：
实验4
通过上面的堆内存分配和visualGC的分析图片可以看出，当执行到最后一句话的时候，也就是进行第二次GC的时候，原本在
S0区域的一些对象被移动到了老年代，这是因为当发生MinorGC的时候发现该对象的年龄已经到达我们设置的MaxTenuringThreshold值。实验五： 使用参数XX:MaxTenuringThreshold=4来设置进入老年代的对象年龄
实验结果
实验5
实验分析
通过上面的日志和图片，可以看出与实验四不同的是，这里执行到最后的时候
S0区域中的对象并没有进入到老年代而是进入了S1区域,因为我们把进入老年代的年龄设置为了4.注：如果没有按照我的代码写的话，你可能会发现即使把MaxTenuringThreshold设置为了大于1的值，但还是有可能会在一次 GC 之后就进入了老年代，这是因为进入我们设置的只是一个最大值，真正的值可能比这个值更小，是动态变化的，这种情况会在下面的实验中介绍。
实验六：TenuringThreshold 是动态变化的
实验结果
实验结果
实验分析
看到上面的堆信息可以看到最后
from和to两个Survivor区域占用情况都为0，原因就是在allocation1被放到S1区域之后，由于该对象和一些附加信息的和占用了S1区域一半以上的空间，因为此时allocation1对象的年龄为1，所以此时TenuringThreshold的值也就变成了1，在GC的时候进入了老年代。通过上图中VisualGC左下角的TenuringThreshold值一直在变化也能得到验证。