曹工雜談：手把手帶你讀懂 JVM 的 gc 日誌

 1、前言

今天下午原本在划水，忽然看到微信聯繫人那一個紅點點，看了下，應該是博客園的朋友。加了後，這位朋友問了我一個問題：

 

問我，這兩塊有什麼關係？ 看到這段 gc 日誌，一瞬間腦子還有點懵，嗯，這個可能要翻下書了，周志明的 Java 虛擬機那本神書裏面有講，我果斷地打開了 pdf，找了起來，很快，找到了：

 

上面發的那個圖裏，6762k 就是 新生代 gc 前的容量，1006k 就是新生代 gc 後的容量，9216k就是新生代的10m中（8m的eden區+1m的 from survivor區）的大小。

 

再看後面的那幾個數字，6762K-》3455K （19456K），意思就是，GC前，Java堆使用了 6762K，GC後，Java堆使用了 3455K，而19456K就是整個堆的容量（新生代9m+老年代10m）。

 

按理說，這麼解釋就足夠了，可是，眼尖，他提出了下面的問題（大概意思是這個，我本身配的字）：

 

這他麼就尷尬了。。。怎麼都解釋不通了啊。。。書上怕不是錯了啊。。。通過咱們一番研究，得出一致結論：

 

 網上搜了下，感受都是些理論，感受你們都沒問題，就我有問題？？？想起以前看虎撲帖子，有人發帖說浙江很富，沒有窮人（確實富），有浙江網友回覆：浙江就我一個窮人！

我如今就是那個感受，你們都沒問題，就我有問題？？

固然，若是我就此止步了，也就不會寫這個了，我和那位朋友搗鼓了一下，仍是理解清楚了 gc 日誌。

 

2、gc 日誌 的正確閱讀方法

友情提示：你們跑不出來和我同樣效果的話，記得看看本身打斷點了沒。

找這位朋友拿了他的測試代碼，很簡單的demo，以下：

 1 import java.util.concurrent.TimeUnit;  2 
 3 
 4 public class AllocationTest {  5 
 6     public static final int _1MB = 1024 * 1024;  7 
 8 
 9     public static void main(String[] args) throws InterruptedException { 10         byte[] allocation1, allocation2, allocation3, allocation4; 11 
12         allocation1 = new byte[2 * _1MB]; 13         allocation2 = new byte[2 * _1MB]; 14         allocation3 = new byte[2 * _1MB]; 15         //觸發Minor GC
16         allocation4 = new byte[4 * _1MB]; 17  } 18 }

 

JVM參數以下：

 -verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8

 

我本地先跑了下，結果是下面這樣的：

 

這個console，和這位朋友的也不一致，我這邊連那行 gc 先後的堆大小的日誌都沒打。由於他發個人蔘數裏，能夠看出來，沒有指定垃圾收集器，那就是用了默認垃圾收集器。 而默認的垃圾收集器在不一樣版本的電腦上、不一樣版本的 JVM 上可能不一致。爲了方便統一認識，我就建議你們統一用 Serial new 收集器，因而加了下面參數：

-verbose:gc -XX:+UseSerialGC -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8

 

此次再運行，確實能夠打印出來了

 

這裏，只是重現了和這位朋友同樣的問題，但問題自己，還沒解決.。基於有問題就DEBUG的習慣，在下面這行打了個斷點：

 1 import java.util.concurrent.TimeUnit;  2 
 3 public class AllocationTest {  4 
 5     public static final int _1MB = 1024 * 1024;  6 
 7     public static void main(String[] args) throws InterruptedException {  8         byte[] allocation1, allocation2, allocation3, allocation4;  9 
10         allocation1 = new byte[2 * _1MB]; 11         allocation2 = new byte[2 * _1MB]; 12         allocation3 = new byte[2 * _1MB]; 13         //觸發Minor GC
14         allocation4 = new byte[4 * _1MB]; 15 
16 TimeUnit.SECONDS.sleep(100); 17  } 18 }

 

在16行打了個斷點，斷點停在 16 行之後，console 以下：

 

讓我驚醒的是，此次只打了這一行，並無打印下圖這部分：

 

 其實這裏已經能夠分析出來 gc 的大致過程了，不過爲了方便咱們理解，咱們能夠加上如下 JVM 參數：

-verbose:gc -XX:+UseSerialGC -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintGCApplicationStoppedTime 

 

此次，斷點依然如約停在了那一行，咱們看看 console，首先，下面是 gc 前的堆佔用狀況

 

而後，看看 gc 後的狀況：

 

這裏，咱們就能夠看出來了， 那3個 2m 大的對象，一開始佔用了 eden區，eden區總共只有8m，那就只剩2m（實際上沒剩2m，由於jvm本身佔了一部分），這時候，咱們要分配一個 4m 大的對象，那，JVM 在收到這個分配 4m 內存的請求後，檢查了 自身的 eden區，明顯不夠，那就 gc 吧，也沒啥好gc 的，那三個2m的對象，生命週期還沒結束，咱們當前的線程堆棧還維持着對它們的強引用，確定是無法回收了。 3個 2m 的對象，活過本次gc，原本要放到 to survivor 區，可是明顯放不下，因而只好丟給 老年代了。

因而，老年代被佔用了 6m 空間。

 

理清了上述過程，再看下面那行gc 日誌：

 

你們能夠拿計算器算下，1kb 都沒差。6144 + 569 = 6713！有一種作對數學題的快感！

 

3、其餘收集器的表現

咱們知道，有不少種收集器組合。

這裏，我和你們試驗幾種，具體你們能夠分析下：

一、上圖紅線組合3  -XX:+UseConcMarkSweepGC -XX:+UseParNewGC

 

二、紅線組合4  -XX:+UseParNewGC

 

三、 紅線組合7，G1收集器

-XX:+UseG1GC  這個表示看不懂了。

 

 更多的垃圾收集器組合，參數及配置，參考：

JVM垃圾收集器組合--各類組合對應的虛擬機參數實踐

 

 

3、總結

計算機科學，真是一門實踐的學問。道友們，一塊兒加油！ 歡迎有興趣的銅須，加羣一塊兒學習！