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

一、 2015-09-14T12:32:24.398-0700: 0.356 — 在這裏 2015-09-14T12:32:24.398-0700: 0.356 表示 GC 發生的時間，其中 0.356 表示 Java 進程啓動 356 毫秒以後發生了 GC。

二、GC pause (G1 Evacuation Pause) — 疏散停頓（Evacuation Pause）是將活着的對象從一個區域（young or young + old）拷貝到另外一個區域的階段。

三、(young) — 表示這是一個 Young GC 事件。

四、GC Workers: 8 – 表示 GC 的工做線程是 8 個。

五、[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。

六、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 事件。

一、2015-09-14T12:35:27.263-0700: 183.216 – 在這裏 2015-09-14T12:35:27.263-0700 表示 GC 發生的時間，其中 183.216 表示 Java 進程啓動 183 秒後發生了 GC.

二、Full GC (Allocation Failure) – 表示這是一個 Full GC 事件，觸發的緣由是由於空間分配失敗（allocation failure），當堆中有不少碎片時，在老年代進行直接內存分配也許會失敗，即便有許多空閒空間，這一般會致使分配失敗。

三、[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。

四、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。