曹工杂谈：手把手带你读懂 JVM 的 gc 日志

 1、前言

今天下午原本在划水，忽然看到微信联系人那一个红点点，看了下，应该是博客园的朋友。加了后，这位朋友问了我一个问题：

 

问我，这两块有什么关系？ 看到这段 gc 日志，一瞬间脑子还有点懵，嗯，这个可能要翻下书了，周志明的 Java 虚拟机那本神书里面有讲，我果断地打开了 pdf，找了起来，很快，找到了：

 

上面发的那个图里，6762k 就是 新生代 gc 前的容量，1006k 就是新生代 gc 后的容量，9216k就是新生代的10m中（8m的eden区+1m的 from survivor区）的大小。

 

再看后面的那几个数字，6762K-》3455K （19456K），意思就是，GC前，Java堆使用了 6762K，GC后，Java堆使用了 3455K，而19456K就是整个堆的容量（新生代9m+老年代10m）。

 

按理说，这么解释就足够了，可是，眼尖，他提出了下面的问题（大概意思是这个，我本身配的字）：

 

这他么就尴尬了。。。怎么都解释不通了啊。。。书上怕不是错了啊。。。通过咱们一番研究，得出一致结论：

 

 网上搜了下，感受都是些理论，感受你们都没问题，就我有问题？？？想起以前看虎扑帖子，有人发帖说浙江很富，没有穷人（确实富），有浙江网友回复：浙江就我一个穷人！

我如今就是那个感受，你们都没问题，就我有问题？？

固然，若是我就此止步了，也就不会写这个了，我和那位朋友捣鼓了一下，仍是理解清楚了 gc 日志。

 

2、gc 日志 的正确阅读方法

友情提示：你们跑不出来和我同样效果的话，记得看看本身打断点了没。

找这位朋友拿了他的测试代码，很简单的demo，以下：

 1 import java.util.concurrent.TimeUnit;  2 
 3 
 4 public class AllocationTest {  5 
 6     public static final int _1MB = 1024 * 1024;  7 
 8 
 9     public static void main(String[] args) throws InterruptedException { 10         byte[] allocation1, allocation2, allocation3, allocation4; 11 
12         allocation1 = new byte[2 * _1MB]; 13         allocation2 = new byte[2 * _1MB]; 14         allocation3 = new byte[2 * _1MB]; 15         //触发Minor GC
16         allocation4 = new byte[4 * _1MB]; 17  } 18 }

 

JVM参数以下：

 -verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8

 

我本地先跑了下，结果是下面这样的：

 

这个console，和这位朋友的也不一致，我这边连那行 gc 先后的堆大小的日志都没打。由于他发个人参数里，能够看出来，没有指定垃圾收集器，那就是用了默认垃圾收集器。 而默认的垃圾收集器在不一样版本的电脑上、不一样版本的 JVM 上可能不一致。为了方便统一认识，我就建议你们统一用 Serial new 收集器，因而加了下面参数：

-verbose:gc -XX:+UseSerialGC -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8

 

此次再运行，确实能够打印出来了

 

这里，只是重现了和这位朋友同样的问题，但问题自己，还没解决.。基于有问题就DEBUG的习惯，在下面这行打了个断点：

 1 import java.util.concurrent.TimeUnit;  2 
 3 public class AllocationTest {  4 
 5     public static final int _1MB = 1024 * 1024;  6 
 7     public static void main(String[] args) throws InterruptedException {  8         byte[] allocation1, allocation2, allocation3, allocation4;  9 
10         allocation1 = new byte[2 * _1MB]; 11         allocation2 = new byte[2 * _1MB]; 12         allocation3 = new byte[2 * _1MB]; 13         //触发Minor GC
14         allocation4 = new byte[4 * _1MB]; 15 
16 TimeUnit.SECONDS.sleep(100); 17  } 18 }

 

在16行打了个断点，断点停在 16 行之后，console 以下：

 

让我惊醒的是，此次只打了这一行，并无打印下图这部分：

 

 其实这里已经能够分析出来 gc 的大致过程了，不过为了方便咱们理解，咱们能够加上如下 JVM 参数：

-verbose:gc -XX:+UseSerialGC -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintGCApplicationStoppedTime 

 

此次，断点依然如约停在了那一行，咱们看看 console，首先，下面是 gc 前的堆占用状况

 

而后，看看 gc 后的状况：

 

这里，咱们就能够看出来了， 那3个 2m 大的对象，一开始占用了 eden区，eden区总共只有8m，那就只剩2m（实际上没剩2m，由于jvm本身占了一部分），这时候，咱们要分配一个 4m 大的对象，那，JVM 在收到这个分配 4m 内存的请求后，检查了 自身的 eden区，明显不够，那就 gc 吧，也没啥好gc 的，那三个2m的对象，生命周期还没结束，咱们当前的线程堆栈还维持着对它们的强引用，确定是无法回收了。 3个 2m 的对象，活过本次gc，原本要放到 to survivor 区，可是明显放不下，因而只好丢给 老年代了。

因而，老年代被占用了 6m 空间。

 

理清了上述过程，再看下面那行gc 日志：

 

你们能够拿计算器算下，1kb 都没差。6144 + 569 = 6713！有一种作对数学题的快感！

 

3、其余收集器的表现

咱们知道，有不少种收集器组合。

这里，我和你们试验几种，具体你们能够分析下：

一、上图红线组合3  -XX:+UseConcMarkSweepGC -XX:+UseParNewGC

 

二、红线组合4  -XX:+UseParNewGC

 

三、 红线组合7，G1收集器

-XX:+UseG1GC  这个表示看不懂了。

 

 更多的垃圾收集器组合，参数及配置，参考：

JVM垃圾收集器组合--各类组合对应的虚拟机参数实践

 

 

3、总结

计算机科学，真是一门实践的学问。道友们，一块儿加油！ 欢迎有兴趣的铜须，加群一块儿学习！