[深入理解Java虛擬機器]第三章 理解GC曰志

閱讀GC日誌是處理Java虛擬機器記憶體問題的基礎技能,它只是一些人為確定的規則,沒有太多技術含量。

每一種收集器的日誌形式都是由它們自身的實現所決定的,換而言之,每個收集器的曰志格式都可以不一樣。但虛擬機器設計者為了方便使用者閱讀,將各個收集器的日誌都維持一定的共性,例如以下兩段典型的GC日誌:

33.125:[GC[DefNew:3324K->152K(3712K),0.0025925 secs]3324K->152K(11904K),0.0031680 secs]
100.667:[Fu11GC[Tenured:0K->210K(10240K),0.0149142sec s]4603K->21OK(19456K),[Perm:2999K-> 2999K(21248K )] ,0.0150007 secs] [Times :user=0.01 sys=0.00 ,real=0.02 secs]

最前面的數字“33.125 : ”和“100.667 : ”代表了GC發生的時間,這個數字的含義是從Java 虛擬機器啟動以來經過的秒數。

GC 日誌開頭的“[GC” 和“[FullGC”說明了這次垃圾收集的停頓型別,而不是用來區分新生代GC還是老年代GC的。如果有“Full” , 說明這次GC是發生了Stop-The-World的 ,例如下面這段新生代收集器ParNew的日誌也會出現“[Full GC” (這一般是因為出現了分配擔保失敗之類的問題,所以才導致STW )。 如果是呼叫Systemgc()方法所觸發的收集,那麼在這裡將顯示“[FullGC(System)”。

[Full GC 283.736:[ParMew:261599K->261599K(261952K) ,0.0000288 secs]

接下來的“ [DefNew”、“ [Tenured”、“ [Perm”表示GC發生的區域 ,這裡顯示的區域名稱與使用的GC收集器是密切相關的,例如上面樣例所使用的Serial收集器中的新生代名為“Default New Generation” ,所以顯示的是“[DefNew”。如果是ParNew收集器,新生代名稱就會變為“[ParNew” ,意為“Parallel New Generation”。如果採用Parallel Scavenge收集器,那它配套 的新生代稱為“PSYoungGen” ,老年代和永久代同理,名稱也是由收集器決定的。

後面方括號內部的“3324K- > 152K ( 3712K ) ”含義是“GC前該記憶體區域已使用容量- > GC後該記憶體區域已使用容量(該記憶體區域總容量)”。而在方括號之外的“3324K->152K ( 11904K ) ”表示“GC前Java堆已使用容量- > GC後Java堆已使用容量(Java堆總容量)“。

再往後 ,“0.0025925 secs”表示該記憶體區域GC所佔用的時間,單位是秒。有的收集器會給出更具體的時間資料,如“[Times : user=0.01 sys=0.00 , real=0.02 secs]” ,這裡面的user、 sys和real與Linux的time命令所輸出的時間含義一致,分別決表使用者態消耗的CPU時間、核心態消耗的CPU事件和操作從開始到結束所經過的牆鍾時間(Wall Clock T ime)。 CPU時間與牆鍾時間的區別是,牆鍾時間包括各種非運算的等待耗時,例如等待磁碟I/O、等待執行緒阻塞 ,而CPU時間不包括這些耗時,但當系統有多CPU或者多核的話,多執行緒操作會疊加這些CPU時間,所以讀者看到user或sys時間超過real時間是完全正常的。

參考：快速解讀GC日誌