Java虚拟机系列---查看GC日志

Posted 2020-12-05 HelloWhy

这一节穿插一点如何在eclipse中配置并查看某个Java应用GC日志的知识点，我也是通过调研知道的，因为书中写的不是很详细，主要是为下一节做准备。

一、eclipse中配置GC

在eclipse中如果要给某个应用配置GC日志，首先右击该应用（main方法所在的类）->Run As->Run Configurations->Arguments，在VM arguments中配置如下参数：

-Xms20m //最小堆内存
-Xmx20m //最大堆内存
-XX:+PrintGCTimeStamps  //打印GC时间
-XX:+PrintGCDetails      //打印GC的详细信息
-verbose:gc //开启GC日志
-Xloggc:d:/gc4.log  //GC日志存放的位置，后面就是查看这个日志文件
-Xmn10M  //新生代内存区域的位置
-XX:SurvivorRatio=8  //在复制算法中Eden区和Survivor区的比例（后续章节会细说）

如下图所示：

配置完成之后点击Applay->Run，等程序运行完之后可以到刚才配置的日志路径中，找到相应的文件进行查看。

二、查看GC

下面以一个具体的实例来查看并分析一下GC日志

1、创建三个互相引用的对象实例

 

2、配置GC

3、查看日志内容

Java HotSpot(TM) 64-Bit Server VM (25.121-b13) for windows-amd64 JRE (1.8.0_121-b13), built on Dec 12 2016 18:21:36 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 4057600k(480696k free), swap 8113324k(3128576k free)
CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
0.121: [GC (System.gc()) [PSYoungGen: 4219K->680K(9216K)] 4219K->3760K(19456K), 0.0024028 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.124: [Full GC (System.gc()) [PSYoungGen: 680K->0K(9216K)] [ParOldGen: 3080K->3639K(10240K)] 3760K->3639K(19456K), [Metaspace: 2587K->2587K(1056768K)], 0.0062622 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
Heap
 PSYoungGen      total 9216K, used 82K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 1% used [0x00000000ff600000,0x00000000ff614920,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 10240K, used 3639K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 35% used [0x00000000fec00000,0x00000000fef8de58,0x00000000ff600000)
 Metaspace       used 2593K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 286K, capacity 386K, committed 512K, reserved 1048576K

 

上面的就是生成的GC日志，其中：

前两行是虚拟机的一些信息，如使用的是HotSpot虚拟机，JRE版本等；第三行是刚才配置的参数信息，真正的GC信息是第4、5行，所以这里直接将4、5两行单独拿出来进行分析：

0.121: [GC (System.gc()) [PSYoungGen: 4219K->680K(9216K)] 4219K->3760K(19456K), 0.0024028 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.124: [Full GC (System.gc()) [PSYoungGen: 680K->0K(9216K)] [ParOldGen: 3080K->3639K(10240K)] 3760K->3639K(19456K), [Metaspace: 2587K->2587K(1056768K)], 0.0062622 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 

 

1）最前面的数字0.121、0.124代表了GC发生的时间，这个数字的含义是从JAVA虚拟机启动以来经过的秒数；

2）GC日志开头的“[GC”和“[Full GC”说明了这次垃圾收集的停顿类型，而不是用来区分新生代GC还是老年代GC。如果有"Full"，说明这次GC是发生了Stop-The-World的，就是指在执行GC操作的时候，会停止掉当前正在进行的其他线程，有一种“这是我的地盘，你们都给我让开”的霸道有木有？如果是调用System.gc()的方法所触发的收集，将会显示“Full GC(System.gc)"，本文的例子就是使用System.gc()进行的收集；

3）接下来的"[PSYoungGen"、“[ParOldGen”、“[Metaspace“标示GC发生的区域，这里显示的区域名称与所使用的GC收集器密切相关（以后会对垃圾收集器进行详细介绍），下面是常见收集器所代表的的区域名称：

1>如果使用的是Serial（串行）收集器，新生代名为Default New Generation ，显示就是DefNew

2>如果使用的是ParNew（并行）收集器，新生代名称就会变为[Parnew,意思为Parallel New Generation 

3>如果采用的是Parallel Scavenge收集器，新生代名称为PSYongGen

老年代和永久代同理，名称由垃圾收集器决定

如上面的日志中新生代名称为[PSYoungGen，使用的是Parallel Scavenge收集器；老年代名称为[ParOldGen，使用的是Paralled Old收集器（Parallel Scavenge收集器的老年代版本），还有元空间区域，有些文章中使用的是”[PermGen“，这时jdk8之前的版本，由于我使用的是jdk8，所以已经被”[Metaspace“所代替，至于为什么被代替，可以参考篇文章：https://blog.csdn.net/zhushuai1221/article/details/52122880

4）每个区域冒号后面，中括号内部的”680K->0K(9216K)]“含义是”GC前该内存区域已使用容量->GC后该内存区域已使用容量（该内存区域总容量）“。而在方括号之外的”3760K->3639K(19456K)“表示的是"GC前Java堆已使用容量->GC后Java堆已使用容量（Java堆总容量）"。

5）再往后 0.0062622 secs表示该内存区域GC所占用的时间单位是秒，有的收集器会给出具体的时间，如本例中的”[Times: user=0.06 sys=0.00, real=0.01 secs]“，这里面的user、sys、real与Linux命令所输出的时间含义一直，分别代表用户态消耗的CPU时间、内核态消耗的CPU时间和操作从开始到结束所经过的墙钟时间（Wall Clock Time）

TIPS:墙钟时间与CPU时间的区别是，墙钟时间包括各种非运算的等待耗时，例如等待磁盘的IO、等待线程阻塞；而CPU时间不包括这些耗时，但当系统中有对CPU或者多核的话，多线程操作会叠加这些CPU时间，所以读者看到user或sys的时间超过real时间是完全正常的。

上面对GC日志中各从参数的介绍摘自《深入理解Java虚拟机（第二版）》

 再往下看，从第6行开始到结束的内容是各内存区域容量的变化情况！

 

备注：以上内容来源于《深入理解Java虚拟机》，根据自己的理解来总结，有些内容和书本内容相同是因为只有这么描述才比较好懂，毕竟大神还是大神，是颜色不一样的烟火！！