GC 日誌分析

不一樣的JVM及其選項會輸出不一樣的日誌。

GC 日誌

生成下面日誌使用的選項：-XX:+PrintGCTimeStamps   -XX:+PrintGCDetails  -Xloggc:d:/GClogs/tomcat6-gc.log。

4.231: [GC 4.231: [DefNew: 4928K->512K(4928K), 0.0044047 secs] 6835K->3468K(15872K), 0.0045291 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
 
4.445: [Full GC (System) 4.445: [Tenured: 2956K->3043K(10944K), 0.1869806 secs] 4034K->3043K(15872K), [Perm : 3400K->3400K(12288K)], 0.1870847 secs] [Times: user=0.05 sys=0.00, real=0.19 secs]

最前面的數字 4.231 和 4.445 表明虛擬機啓動以來的秒數。

[GC 和 [Full GC 是垃圾回收的停頓類型，而不是區分是新生代仍是年老代，若是有 Full 說明發生了 Stop-The-World 。若是是調用 System.gc() 觸發的，那麼將顯示的是 [Full GC (System) 。

接下來的 [DefNew,  [Tenured,  [Perm 表示 GC 發生的區域，區域的名稱與使用的 GC 收集器相關。
Serial 收集器中新生代名爲 「Default New Generation」，顯示的名字爲 「[DefNew」。對於ParNew收集器，顯示的是 「[ParNew」，表示 「Parallel New Generation」。 對於 Parallel Scavenge 收集器，新生代名爲 「PSYoungGen」。年老代和永久代也相同，名稱都由收集器決定。

方括號內部顯示的 「4928K->512K(4928K)」 表示 「GC 前該區域已使用容量  -> GC 後該區域已使用容量 (該區域內存總容量) 」。

再日後的 「0.0044047 secs」 表示該區域GC所用時間，單位是秒。

再日後的 「6835K->3468K(15872K)」 表示 「GC 前Java堆已使用容量  ->  GC後Java堆已使用容量 （Java堆總容量）」。

再日後的 「0.0045291 secs」 是Java堆GC所用的總時間。

最後的 「[Times: user=0.00 sys=0.00, real=0.00 secs]」 分別表明 用戶態消耗的CPU時間、內核態消耗的CPU時間 和 操做從開始到結束所通過的牆鍾時間。牆鍾時間包括各類非運算的等待耗時，如IO等待、線程阻塞。CPU時間不包括等待時間，當系統有多核時，多線程操做會 疊加這些CPU時間，因此user或sys時間會超過real時間。