一、前言

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

問我，這兩塊有什么關系？看到這段 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 日志。

二、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 日志：