浅谈 G1 GC 日志格式

Posted felixzh

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了浅谈 G1 GC 日志格式相关的知识,希望对你有一定的参考价值。

在 Java9 中,G1 GC 将成为默认的垃圾收集器,G1 垃圾收集器的关键特性之一是能够在不牺牲吞吐量的同时,限制 GC 暂停时间(即可以设置所需的最大停顿时间)。

由于 G1 GC 正在逐渐成为默认的垃圾收集器,它的使用与关注度也会逐渐增加。因此在调整 JVM 大小和排查问题的情况下,必须先理解 G1 GC 的日志格式,接下来将介绍如何理解 G1 GC 的日志格式。由于 G1 GC 日志中有许多与子任务相关的信息,因此为了更好地理解和利用这些信息,我推荐使用 GC 日志分析工具:http://gceasy.io/

打开 GC 日志

可以使用下面的参数打开 GC 日志:

-Xloggc:/home/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps

在这里 GC 日志会写入到 /home/gc.log 文件里。

Minor GC 日志

当发生 Minor GC 时,在 GC 日志文件里会有以下内容:

技术图片

上图展示了在 G1 垃圾收集日志中的 Young GC 事件。

1、 2015-09-14T12:32:24.398-0700: 0.356 — 在这里 2015-09-14T12:32:24.398-0700: 0.356 表示 GC 发生的时间,其中 0.356 表示 Java 进程启动 356 毫秒之后发生了 GC。

2、GC pause (G1 Evacuation Pause) — 疏散停顿(Evacuation Pause)是将活着的对象从一个区域(young or young + old)拷贝到另一个区域的阶段。

3、(young) — 表示这是一个 Young GC 事件。

4、GC Workers: 8 – 表示 GC 的工作线程是 8 个。

5、[Eden: 12.0M(12.0M)->0.0B(14.0M) Survivors: 0.0B->2048.0K Heap:12.6M(252.0M)->7848.3K(252.0M)] — 这里显示了堆的大小变化:

  • Eden: 12.0M(12.0M)->0.0B(14.0M) — 表示伊甸园(Eden)空间是 12mb,并且 12mb 空间全部被占用。在 GC 发生之后,年轻代(young generation)空间下降到0,伊甸园的空间增长到 14mb,但是没有提交。因为要求,额外的空间被添加给伊甸园。

  • Survivors: 0.0B->2048.0K - 表示在 GC 发生之前,幸存者空间(Survivor space)是 0 个字节,但是在 GC 发生之后,幸存者空间增长到 2048 kb,它表明对象从年轻代(Young Generation)提升到幸存者空间(Survivor space)。

  • Heap: 12.6M(252.0M)->7848.3K(252.0M) – 表示堆的大小是 252mb,被占用 12.6mb,GC 发生之后,堆占用率将至 7848.3kb(即5mb (12.6mb – 7848.3kb)的对象被垃圾回收了),堆的大小仍然是 252mb。

6、Times: user=0.08, sys=0.00, real=0.02 secs – 注意这里的 real 时间,它表示 GC 总共花了 0.02 秒,如果你对 user 和 sys 感兴趣,请查看这篇文章:GC LOGGING – USER, SYS, REAL – WHICH TIME TO USE? & GANDHI

Full GC 日志

当发生 Full GC 时,在 GC 日志文件里会有以下内容:

技术图片

上图展示了在 G1 垃圾收集日志中的 Full GC 事件。

1、2015-09-14T12:35:27.263-0700: 183.216 – 在这里 2015-09-14T12:35:27.263-0700 表示 GC 发生的时间,其中 183.216 表示 Java 进程启动 183 秒后发生了 GC.

2、Full GC (Allocation Failure) – 表示这是一个 Full GC 事件,触发的原因是因为空间分配失败(allocation failure),当堆中有很多碎片时,在老年代进行直接内存分配也许会失败,即使有许多空闲空间,这通常会导致分配失败。

3、[Eden: 3072.0K(194.0M)->0.0B(201.0M) Survivors: 0.0B->0.0B Heap: 3727.1M(4022.0M)->3612.0M(4022.0M)], [Metaspace: 2776K->2776K(1056768K)] – 这里显示了堆的大小变化,由于这是 Full GC 事件:

  • Eden: 3072.0K(194.0M)->0.0B(201.0M) - 表示伊甸园空间(Eden space)是194mb,被占用3072kb。在 GC 发生之后,年轻代(young generation)下降到0。伊甸园空间增长到201mb,但是没有提交。因为要求,额外的空间被添加给伊甸园。

  • Survivors: 0.0B->0.0B – 表示 GC 发生前后,幸存者空间是 0kb。

  • Heap: 3727.1M(4022.0M)->3612.0M(4022.0M) - 表示堆的大小是 4022mb,其中 3727.1mb 空间未被占用。在 GC 发生之后,堆占用率降至 3612mb,115.1mb (即3727.1 – 3612) 的对象被垃圾回收了,堆的大小仍然是 4022mb。

  • Metaspace: 2776K->2776K(1056768K) – 表示在 GC 发生前后,它被占用的空间大小是 2776k。基本上,意味着在这个阶段 metaspace 空间占用率是保持一致的,metaspace 的总大小是 1056768k。

4、Times: user=19.08, sys=0.01, real=9.74 secs – real 表示 GC 总共花了 9.74 秒,这个停顿时间很长。

本文基本概括了 G1 GC 日志的内容,如果你想看到可视化图形和指标,我建议使用 GC 分析工具:http://gceasy.io/

编译自:https://dzone.com/articles/understanding-g1-gc-log-format

以上是关于浅谈 G1 GC 日志格式的主要内容,如果未能解决你的问题,请参考以下文章

译深入理解G1的GC日志

GC垃圾回收 | 深入理解G1垃圾收集器和GC日志

G1 GC日志:Application time: 0.8766273 seconds

GC日志格式

hbase G1 GC优化

垃圾回收G1的GC过程