淺談 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。