GC日志查看和分析

可以通过在java命令种加入参数来指定对应的gc类型，打印gc日志信息并输出至文件等策略。

GC的日志是以替换的方式()写入的，而不是追加()，如果下次写入到同一个文件中的话，以前的GC内容会被清空。

启动命令:

结果:

也是一次minor gc,但是与前两次的gc原因不一样,这次的gc原因是：[metadata GC Threshold],metadata即元数据的意思,我们可以看出这是与虚拟机的元数据区有关系的一次gc;元数据区,在jdk1.8以前又叫永久代,从JDK8开始,永久代(PermGen)的概念被废弃掉了,取而代之的就是这里的称为metaspace的存储空间;元空间和永久代是虚拟机对方法区这个概念的一个具体实现;对于元空间而言,这一块空间是存在本地内存当中的,因此,默认情况下,元空间的大小仅受本地内存限制,但我们可以通过参数来指定元空间的大小

这里元空间发生gc,说明元空间的内存不够了,到达了阀值;对元空间进行了一次垃圾回收,回收之前是245183K,回收之后是3769K

在元空间gc之后,紧接着发生了一次Full GC,且触发原因也是元空间不足

GC日志的分析

以下是一段GC日志。

0.244 ： 系统启动0.244秒后，发生。

GC (Allocation Failure) ： GC发生的原因，对象分配失败。

0.245：系统运行0.245秒的时候发生。

[ParNew: 3170K-512K(4608K), 0.0015722 secs] ：

ParNew进行了垃圾回收， 新生代可用的总空间大小=4608K = Eden区 + 1个Survivor区， 回收前占用了3170K ， 回收后，新生代还占用了512K。 本次回收使用了，0.0015722 秒。

3170K-1652K(9728K), 0.0028240 secs

这部分是对整个堆空间的内存回收情况的说明， 整个堆空间(新生代+老年代) = 9728K ， 回收前使用了3170K ， 回收后还有1652K的内存被使用。 本次GC总共使用了 0.0028240 secs 秒。

***行 ： parNew管理了 总共的内存是 4608K ， 已经使用掉3704K 。

第二行：eden区，一共有4096K ， 已经有 77% 的空间被使用了。

第三行：survivor from区，一共有512K， 已经有 100% 的空间被使用了，已经满了。

第四行：survivor to区，一共有512K， 还没有任何的使用。里面是空的。

***行 ：老年代一共有5120K空间，已经使用了1140K。

第二行： 老年代有 5120K的空间，已经使用了 22%的空间。

used：加载的类的空间量。

capacity： 当前分配块的元数据的空间。

committed： 空间块的数量。

reserved：元数据的空间保留（但不一定提交）的量。

最后的数据可以参考这篇文章：

GC日志中，metaspace的这几个参数你知道吗？

JVM GC 日志详解

本文采用的JDK版本：

设置JVM GC格式日志的主要参数包括如下8个：

本文假设读者已经熟悉JVM 内存结构。

如果想开启GC日志的信息，可以通过设置如下的参数任一参数：

如果只设置 -XX:+PrintGC 那么打印的日志如下所示：

1、 GC 表示是一次YGC（Young GC）

2、 Allocation Failure 表示是失败的类型

3、 68896K-5080K 表示年轻代从68896K降为5080K

4、 256000K 表示整个堆的大小

5、 0.0041139 secs 表示这次GC总计所用的时间

在JDK 8中， -verbose:gc 是 -XX:+PrintGC 一个别称，日志格式等价与： -XX:+PrintGC ，。

不过在 JDK 9 中 -XX:+PrintGC被标记为 deprecated 。

-verbose:gc 是一个标准的选项， -XX:+PrintGC 是一个实验的选项，建议使用 -verbose:gc 替代 -XX:+PrintGC

参考： Difference between -XX:+PrintGC and -verbose:gc

1、 GC 表示是一次YGC（Young GC）

2、 Allocation Failure 表示是失败的类型

3、PSYoungGen 表示年轻代大小

4、 53248K-2176K 表示年轻代占用从 53248K 降为 2176K

5、 59392K 表示年轻带的大小

6、 58161K-7161K 表示整个堆占用从 53248K 降为 2176K

7、 256000K 表示整个堆的大小

8、 0.0039189 secs 表示这次GC总计所用的时间

9、 [Times: user=0.02 sys=0.01, real=0.00 secs] 分别表示，用户态占用时长，内核用时，真实用时。

时间保留两位小数，四舍五入。

如果加上 -XX:+PrintGCTimeStamps 那么日志仅仅比1.1介绍的最前面多了一个时间戳： 1.963 ， 表示从JVM启动到打印GC时刻用了1.963秒。

如果加上 -XX:+PrintGCDateStamps 那么日志仅仅比1.1介绍的最前面多了一个日期时间： 2019-03-05T16:56:15.108+0800 ， 表示打印GC的时刻的时间是 2019-03-05T16:56:15.108+0800 。+0800表示是东8区。

这个参数开启后，

使用如下参数 -verbose:gc -XX:+PrintHeapAtGC -Xmn64M -Xms256M -Xmx256M

打印日志如下：

由此可以看出在，打印如下日志前后

详细打印出了日志信息

invocations 表示GC的次数，每次GC增加一次，每次GC前后的invocations相等

1、 Heap before GC invocations=1 表示是第1次GC调用之前的堆内存状况

2、 {Heap before GC invocations=1 (full 0): 表示是第1次GC调用之后的堆内存状况

如果使用该参数 -Xloggc 则默认开启如下两个参数

如果启动参数如下： -Xloggc:gc.log -Xmn64M -Xms256M -Xmx256M 则日志格式如下所示

gc.log 也可以指定绝对的路径。

在gc.log最前面还会默认打印系统的JDK版本与启动的参数

此设置 -XX:+PrintReferenceGC可以打印出SoftReference，WeakReference，FinalReference，PhantomReference，JNI Weak Reference几种引用的数量，以及清理所用的时长，该参数在进行YGC调优时可以排上用场。

具体可以参考占小狼的一篇实战： 一次 Young GC 的优化实践（FinalReference 相关）

CMS日志分为两个STW(stop the world)

分别是 init remark （1） 与 remark （7）两个阶段。一般耗时比YGC长约10倍（个人经验）。

（1）、 [GC (CMS Initial Mark) [1 CMS-initial-mark: 19498K(32768K)] 36184K(62272K), 0.0018083 secs][Times: user=0.01 sys=0.00, real=0.01 secs]

会STO(Stop The World)，这时候的老年代容量为 32768K， 在使用到 19498K 时开始初始化标记。耗时短。

（2）、 [CMS-concurrent-mark-start]

并发标记阶段开始

（3）、 [CMS-concurrent-mark: 0.011/0.011 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]

并发标记阶段花费时间。

（4）、 [CMS-concurrent-preclean-start]

并发预清理阶段，也是与用户线程并发执行。虚拟机查找在执行并发标记阶段新进入老年代的对象(可能会有一些对象从 新生代 晋升到老年代， 或者有一些对象被分配到老年代)。通过重新扫描，减少下一个阶段”重新标记”的工作，因为下一个阶段会Stop The World。

（5）、 [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

并发预清理阶段花费时间。

（6）、 [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time [CMS-concurrent-abortable-preclean: 0.558/5.093 secs][Times: user=0.57 sys=0.00, real=5.09 secs]

并发可中止预清理阶段，运行在并行预清理和重新标记之间，直到获得所期望的eden空间占用率。增加这个阶段是为了避免在重新标记阶段后紧跟着发生一次垃圾清除

（7）、 [GC (CMS Final Remark) [YG occupancy: 16817 K (29504 K)][Rescan (parallel) , 0.0021918 secs][weak refs processing, 0.0000245 secs][class unloading, 0.0044098 secs][scrub symbol table, 0.0029752 secs][scrub string table, 0.0006820 secs][1 CMS-remark: 19498K(32768K)] 36316K(62272K), 0.0104997 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

会STW(Stop The World)，收集阶段，这个阶段会标记老年代全部的存活对象，包括那些在并发标记阶段更改的或者新创建的引用对象

（8）、 [CMS-concurrent-sweep-start]

并发清理阶段开始，与用户线程并发执行。

（9）、 [CMS-concurrent-sweep: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

并发清理阶段结束，所用的时间。

（10）、 [CMS-concurrent-reset-start]

开始并发重置。在这个阶段，与CMS相关数据结构被重新初始化，这样下一个周期可以正常进行。

（11）、 [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

并发重置所用结束，所用的时间。

参考：

Geek-Yan : JVM 学习笔记(四) CMS GC日志详解

设置JVM GC 性能的有如下参数

新生代大小官网推荐的大小是 3/8 , 如果设置太小，比如 1/10会 导致 Minor GC 与 Major GC 次数增多。

其中n的大小为区间为[0,15],如果高于15，JDK7 会默认15，JDK 8会启动报错

发生在CMS GC运行期间，详情参考：

JVM 调优 —— GC 长时间停顿问题及解决方法

GC的悲观策略

发生在Minor GC期间

JVM-GC日志查看分析

首先了解关于输出GC日志的参数有以下几种

①GC日志开头的 [GC 和 [Full GC 说明了这次垃圾收集的类型.

② [PSYoungGen 和 [ParOldGen 是指GC发生的区域，分别代表使用 Parallel Scavenge 垃圾收集器的新生代和使用 Parallel old 垃圾收集器的老生代。为什么是这两个垃圾收集器组合呢？因为我的jvm开启的模式是 Server ，而 Server 模式的默认垃圾收集器组合便是这个，在命令行输入 java -version 就可以看到自己的jvm默认开启模式。还有一种是 client 模式，默认组合是 Serial 收集器和 Serial Old 收集器组合。

先了解下 Java memory 划分：

Java memory 主要分 heap memory 和 non-heap memory ，如下图：

⑧默认的，新生代 ( Young ) 与老年代 ( Old ) 的比例的值为 1:2 ( 该值可以通过参数 –XX:NewRatio 来指定 )，即：新生代 ( Young ) = 1/3 的堆空间大小。老年代 ( Old ) = 2/3 的堆空间大小。其中，新生代 ( Young ) 被细分为 Eden 和 两个 Survivor 区域，这两个 Survivor 区域分别被命名为 from 和 to ，以示区分。

⑨ ParOldGen 为老年代，大小为 125952K ，大约为 PSYoungGen 内存大小的 2 倍。 从JDK8开始，永久代( PermGen )的概念被废弃掉了，取而代之的是一个称为 metaspace (元空间)的存储空间。 metaspace 与 PermGen 之间***的区别在于： metaspace 并不在虚拟机中，而是使用本地内存。

文章参考:

JVM性能调优（2） —— 内存设置和查看GC日志

1）JVM内存分配有如下一些参数：

一般 -Xms 和 -Xmx 设置一样的大小，-XX:metaspaceSize 和 -XX:MaxmetaspaceSize 设置一样的大小。-Xms 等价于 -XX:InitialHeapSize，-Xmx等价于-XX:MaxHeapSize；-Xmn等价于-XX:MaxNewSize。

2）在IDEA中可以按照如下方式设置JVM参数：

3）命令行启动时可以按照如下格式设置：

1）设置GC参数：

可以在启动时加上如下参数来查看GC日志：

例如，我在IDEA中添加了如下JVM启动参数：

启动程序之后打印出了如下的一些日志：

从第三行 CommandLine flags 可以得到如下的信息：

2）查看默认参数：

如果要查看JVM的默认参数，就可以通过给JVM加打印GC日志的参数，就可以在GC日志中看到JVM的默认参数了。

还可以在启动参数中添加 -XX:+PrintFlagsFinal 参数，将会打印系统的所有参数，就可以看到自己配置的参数或系统的默认参数了：

3）GC日志：

之后的日志就是每次垃圾回收时产生的日志，每行日志说明了这次GC的执行情况，例如第四行GC日志：

详细内容如下：

2020-09-25T13:00:41.631+0800：GC发生的时间点。

4.013：系统运行多久之后发生的GC，单位秒，这里就是系统运行 4.013 秒后发生了一次GC。

GC (Allocation Failure)：说明了触发GC的原因，这里是指对象分配失败导致的GC。

PSYoungGen：指触发的是年轻代的垃圾回收，使用的是 Parallel Scavenge 垃圾回收器。

419840K-20541K：对年轻代执行了一次GC，GC之前年轻代使用了 419840K，GC之后有 20541K 的对象活下来了。

(472064K)：年轻代可用空间是 472064K，即 461 M，为什么是461M呢？因为新生代大小为 512M，Eden 区占 409.6M，两块 Survivor 区各占 51.2M，所以年轻代的可用空间为 Eden+1个Survivor的大小，即460.8M，约为461M。

419840K-20573K：GC前整个堆内存使用了 419840K，GC之后堆内存使用了 20573K。

(996352K)：整个堆的大小是 996352K，即 973M，其实就是年轻代的 461M + 老年代的 512 M

0.0118345 secs：本次GC耗费的时间

Times: user=0.00 sys=0.00, real=0.01 secs：本次GC耗费的时间

4）JVM退出时的GC情况：

程序结束运行后，还会打印一些日志，就是第12行之后的日志，这部分展示的是当前堆内存的使用情况：

详细内容如下：

gc工作日志怎么导入

gc工作日志导入方法如下：

1、双击GC的应用程序文件，打开GC软件。

2、点击窗口的***化按扭，使编辑窗口***化。

3、点选FILE-import（文件-导入）进入导入设置界面。

4、通过查找范围的下拉列表中找到需要打开的工作日志文件夹。

5、点击导入即可。

关于gc日志和gc日志默认路径的介绍到此就结束了，不知道你从中找到你需要的信息了吗 ？如果你还想了解更多这方面的信息，记得收藏关注本站。