虚拟机：请问我刚刚回收的对象是干垃圾还是湿垃圾？|文末送书
Java的一大特色就是支持自動垃圾回收（GC），每一個Java開發人員都需要了解虛擬機的垃圾回收機制，本文，就來介紹下如何通過虛擬機的GC日志了解垃圾回收的情況。
最簡單的一個GC參數是-XX:+PrintGC（在JDK9、JDK10中建議使用-Xlog:gc），使用這個參數啟動Java虛擬機后，只要遇到GC，就會打印日志，如下所示：
[GC 4857K->377K(15936K), 0.0003595 secs]
[GC 4857K->377K(15936K), 0.0001755 secs]
[GC 4857K->377K(15936K), 0.0001957 secs]
該日志顯示，一共進行了4次GC，每次GC占用一行，在GC前，堆空間使用量約為4MB，在GC后，堆空間使用量為377KB，當前可用的堆空間總和約為16MB（15936KB）。最后，顯示的是本次GC所花的時間。
JDK9、JDK10默認使用G1作為垃圾回收器，使用參數-Xlog:gc來打印GC日志，如下所示：
[0.107s][info][gc] GC(0) Pause Full (System.gc()) 16M->7M(34M) 23.511ms
該日志顯示，一共進行了1次GC，在GC前，堆空間使用量為16MB，在GC后，堆空間使用量為7MB，當前可用的堆空間總和為34MB。最后，顯示的是本次GC所花的時間，為23.511ms。
如果需要更加詳細的信息，可以使用-XX:+PrintGCDetails參數。JDK8（JDK9、JDK10建議使用-Xlog:gc*，后面講述）中的輸出可能如下：
[GC[DefNew: 9791K->9791K(9792K), 0.0000350 secs][Tenured: 16632K->13533K(21888K),0.4063120 secs] 26424K->13533K(31680K), [Perm : 2583K->2583K(21248K)], 0.4064710 secs] [Times: user=0.41 sys=0.00, real=0.40 secs]
[GC[DefNew: 8704K->1087K(9792K), 0.0574610 secs] 22237K->16688K(31680K), 0.0575180 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
Heap
def new generation total 9792K, used 4586K [0x00000000f8e00000, 0x00000000f98a0000, 0x00000000f98a0000)
eden space 8704K, 40% used [0x00000000f8e00000, 0x00000000f916a8e0, 0x00000000f9680000)
from space 1088K, 99% used [0x00000000f9680000, 0x00000000f978ffe0, 0x00000000f9790000)
to space 1088K, 0% used [0x00000000f9790000, 0x00000000f9790000, 0x00000000f98a0000)
tenured generation total 21888K, used 15600K [0x00000000f98a0000, 0x00000000fae00000, 0x00000000fae00000)
the space 21888K, 71% used [0x00000000f98a0000, 0x00000000fa7dc278,
0x00000000fa7dc400, 0x00000000fae00000)
compacting perm gen total 21248K, used 2591K [0x00000000fae00000, 0x00000000fc2c0000, 0x0000000100000000)
the space 21248K, 12% used [0x00000000fae00000, 0x00000000fb087ca8,
0x00000000fb087e00, 0x00000000fc2c0000)
No shared spaces configured.
從這個輸出中可以看到，系統經歷了3次GC，第1次僅為新生代GC，回收的效果是新生代從回收前的8MB左右降低到1MB。整個堆從22MB左右降低到17MB。
第2次（加粗部分）為Full GC，它同時回收了新生代、老年代和永久區。日志顯示，新生代在這次GC中沒有釋放空間（嚴格來說，這是GC日志的一個小bug，事實上，在這次Full GC完成后，新生代被清空，由于GC日志輸出時機的關系，各個版本JDK的日志多少有些不太精確的地方，讀者需要留意），老年代從16MB降低到13MB。整個堆大小從26MB左右降低為13MB左右（這個大小完全與老年代實際大小相等，因此也可以推斷，新生代實際上已被清空）。永久區的大小沒有變化。日志的最后顯示了GC所花的時間，其中user表示用戶態CPU耗時，sys表示系統CPU耗時，real表示GC實際經歷的時間。
參數-XX:+PrintGCDetails還會使虛擬機在退出前打印堆的詳細信息，詳細信息描述了當前堆的各個區間的使用情況。如上輸出所示，當前新生代（new generation）總大小為9792KB，已使用4586KB。緊跟其后的3個16進制數字表示新生代的下界、當前上界和上界。
使用上界減去下界就能得到當前堆空間的最大值，使用當前上界減去下界，就是當前虛擬機已經為程序分配的空間。如果當前上界等于下界，說明當前的堆空間已經沒有擴大的可能性。在本例中（0x00000000f98a0000-0x00000000f8e00000）/1024=10880KB。這塊空間正好等于eden+from+to的總和。而可用的新生代9792KB為eden+from(to)的總和，對于兩者出現差異的原因，讀者可以參考本書第4章。
除了新生代，詳細的堆日志中還顯示了老年代（tenuredgeneration）和永久區（compactingperm gen）的使用情況，其格式和新生代相同。
JDK9、JDK10使用參數-Xlog:gc*來打印更加詳細的GC日志，如下所示：
[0.012s][info][gc ] Using G1
[0.013s][info][gc,heap,coops]Heap address: 0x00000000fe000000, size: 32 MB, Compressed Oops mode: 32-bit
[5.335s][info][gc,start ]GC(0) Pause Young (G1 Evacuation Pause)
[5.336s][info][gc,task ]GC(0) Using 8 workers of 8 for evacuation
[5.339s][info][gc,phases ]GC(0) Pre Evacuate Collection Set:0.0ms
[5.340s][info][gc,phases ]GC(0) Evacuate Collection Set: 3.3ms
[5.341s][info][gc,phases ]GC(0) Post Evacuate Collection Set:0.1ms
[5.341s][info][gc,phases ]GC(0) Other: 0.6ms
[5.341s][info][gc,heap ]GC(0) Eden regions: 14->0(17)
[5.341s][info][gc,heap ]GC(0) Survivor regions: 0->2(2)
[5.342s][info][gc,heap ]GC(0) Old regions: 0->0
[5.342s][info][gc,heap ]GC(0) Humongous regions: 0->0
[5.342s][info][gc,metaspace] GC(0) Metaspace: 3418K->3418K(1056768K)
[5.342s][info][gc ]GC(0) Pause Young (G1 Evacuation Pause) 14M->1M(32M) 7.028ms
[5.342s][info][gc,cpu ]GC(0) User=0.05s Sys=0.00s Real=0.01s
從這個輸出中可以看到，堆的最大可用大小為32MB，系統經歷了1次GC，為新生代GC，回收的效果是整個堆從14MB左右降低到了1MB。在JDK9、JDK10中，除了新生代、老年代，還新增了一個巨型區域，即上述輸出中的Humongousregions。
另外，日志中有詳細的時間信息，第一列顯示Java程序運行的時間，PauseYoung (G1 Evacuation Pause) 14M->1M(32M) 7.028ms 表示新生代垃圾回收花了7.028ms。
Pre Evacuate Collection Set、Evacuate Collection Set、Post Evacuate Collection Set、Other代表G1垃圾回收標記—清除算法不同階段所花費的時間。
最后一行的時間信息跟JDK8相同，不再贅述。
如果需要更全面的堆信息，還可以使用參數-XX:+PrintHeapAtGC（考慮到兼容性，從JDK9開始已經刪除此參數，查看堆信息可以使用VisualVM，第6章將會講述）。它會在每次GC前、后分別打印堆的信息，就如同-XX:+PrintGCDetails的最后輸出一樣。下面就是-XX:+PrintHeapAtGC的輸出樣式，限于篇幅，只給出部分輸出：
def new generation total 8576K, used 8575K [0x32680000,0x32fc0000, 0x33120000)
eden space 7680K, 100% used [0x32680000, 0x32e00000, 0x32e00000)
from space 896K, 99% used[0x32ee0000, 0x32fbffc0, 0x32fc0000)
to space 896K, 0% used [0x32e00000, 0x32e00000, 0x32ee0000)
tenured generation total 18880K, used 12353K [0x33120000,0x34390000, 0x34680000)
省略部分輸出
[GC[DefNew:8575K->895K(8576K), 0.0017210 secs] 20929K->14048K(27456K), 0.0017756secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap after GC invocations=9 (full 3):
def new generation total 8576K, used 895K [0x32680000,0x32fc0000, 0x33120000)
eden space 7680K, 0% used[0x32680000, 0x32680000, 0x32e00000)
from space 896K, 99% used[0x32e00000, 0x32edffc0, 0x32ee0000)
to space 896K, 0% used [0x32ee0000, 0x32ee0000, 0x32fc0000)
tenured generation total 18880K, used 13152K [0x33120000,0x34390000, 0x34680000)
the space 18880K, 69% used[0x33120000, 0x33df8288, 0x33df8400, 0x34390000)
省略部分輸出
}
可以看到，在使用-XX:+PrintHeapAtGC后，在GC日志輸出前、后都有詳細的堆信息輸出，分別表示GC回收前和GC回收后的堆信息，使用這個參數，可以很好地觀察GC對堆空間的影響。
如果需要分析GC發生的時間，還可以使用-XX:+PrintGCTimeStamps（JDK9、JDK10中使用-Xlog:gc*已經默認打印出時間，前文關于-Xlog:gc*已經有講述，這里不再贅述）參數，該參數會在每次GC時，額外輸出GC發生的時間，該輸出時間為虛擬機啟動后的時間偏移量。如下代碼表示在系統啟動后0.08s、0.088s、0.094s發生了GC。
0.088:[GC0.088: [DefNew: 4928K->511K(4928K), 0.0044292 secs]8305K->7751K(15872K), 0.0045321 secs] [Times:user=0.00 sys=0.00, real=0.00 secs]
0.094: [GC0.094: [DefNew: 4927K->511K(4928K), 0.0044136 secs]0.099:[Tenured: 11238K->11327K(11328K), 0.0113929 secs] 12167K->11750K(16256K),[Perm : 142K->142K(12288K)], 0.0160228 secs] [Times: user=0.02 sys=0.00, real=0.02secs]
由于GC會引起應用程序停頓，因此還需要特別關注應用程序的執行時間和停頓時間。使用參數-XX:+PrintGCApplicationConcurrentTime可以打印應用程序的執行時間，使用參數-XX:+PrintGCApplicationStoppedTime可以打印應用程序由于GC而產生的停頓時間，如下所示：
Total time for whichapplication threads were stopped: 0.0091600 seconds
Application time:0.0039006 seconds
Total time for whichapplication threads were stopped: 0.0024330 seconds
?
如果想跟蹤系統內的軟引用、弱引用、虛引用和Finallize隊列，可以打開-XX:+PrintReferenceGC（考慮到兼容性，從JDK9開始已經刪除此參數，查看堆信息可以使用VisualVM，第6章將會講述）開關，結果如下：
默認情況下，GC的日志會在控制臺中輸出，這不便于后續分析和定位問題。所以，虛擬機允許將GC日志以文件的形式輸出，可以使用參數-Xloggc指定。比如使用參數-Xloggc:log/gc.log（在JDK9、JDK10中建議使用-Xlog:gc:log/gc.log）啟動虛擬機，可以在當前目錄的log文件夾下的gc.log文件中記錄所有的GC日志。JDK9、JDK10生成的文件與JDK8相同，不再贅述。
文末福利
本文節選自 《實戰Java虛擬機———JVM故障診斷與性能優化（第2版）》一書，葛一鳴著，電子工業出版社出版。本書涵蓋JDK 7到JDK 10，通過200余示例詳解Java虛擬機中各種參數配置、故障排查、性能監控以及性能優化，技術全面，通俗易懂。
本書剛剛上市，第一時間送出5本給到大家。
參與方式：請掃描下方二維碼關注我的小號[Java之道]，公眾號對話回復：送書，即可參與抽獎。
如果你喜歡本文,
請長按二維碼，關注?Hollis.
轉發至朋友圈，是對我最大的支持。
總結
以上是生活随笔為你收集整理的虚拟机：请问我刚刚回收的对象是干垃圾还是湿垃圾？|文末送书的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： Weblogic部署web项目获取项目根
- 下一篇： 【日本の歌 秋桜】