Java虛擬機系列(四)---查看GC日誌
這一節穿插一點如何在eclipse中配置並查看某個Java應用GC日誌的知識點,我也是通過調研知道的,因為書中寫的不是很詳細,主要是為下一節做準備。
一、eclipse中配置GC
在eclipse中如果要給某個應用配置GC日誌,首先右擊該應用(main方法所在的類)->Run As->Run Configurations->Arguments,在VM arguments中配置如下參數:
-Xms20m //最小堆內存
-Xmx20m //最大堆內存
-XX:+PrintGCTimeStamps //打印GC時間
-XX:+PrintGCDetails //打印GC的詳細信息
-verbose:gc //開啟GC日誌
-Xmn10M //新生代內存區域的位置
-XX:SurvivorRatio=8 //在復制算法中Eden區和Survivor區的比例(後續章節會細說)
如下圖所示:
配置完成之後點擊Applay->Run,等程序運行完之後可以到剛才配置的日誌路徑中,找到相應的文件進行查看。
二、查看GC
下面以一個具體的實例來查看並分析一下GC日誌
1、創建三個互相引用的對象實例
2、配置GC
3、查看日誌內容
Java HotSpot(TM) 64-Bit Server VM (25.121-b13) for windows-amd64 JRE (1.8.0_121-b13), built on Dec 12 2016 18:21:36 by "java_re" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 4057600k(480696k free), swap 8113324k(3128576k free) CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 0.121: [GC (System.gc()) [PSYoungGen: 4219K->680K(9216K)] 4219K->3760K(19456K), 0.0024028 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 0.124: [Full GC (System.gc()) [PSYoungGen: 680K->0K(9216K)] [ParOldGen: 3080K->3639K(10240K)] 3760K->3639K(19456K), [Metaspace: 2587K->2587K(1056768K)], 0.0062622 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] Heap PSYoungGen total 9216K, used 82K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) eden space 8192K, 1% used [0x00000000ff600000,0x00000000ff614920,0x00000000ffe00000) from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000) to space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000) ParOldGen total 10240K, used 3639K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000) object space 10240K, 35% used [0x00000000fec00000,0x00000000fef8de58,0x00000000ff600000) Metaspace used 2593K, capacity 4486K, committed 4864K, reserved 1056768K class space used 286K, capacity 386K, committed 512K, reserved 1048576K
上面的就是生成的GC日誌,其中:
前兩行是虛擬機的一些信息,如使用的是HotSpot虛擬機,JRE版本等;第三行是剛才配置的參數信息,真正的GC信息是第4、5行,所以這裏直接將4、5兩行單獨拿出來進行分析:
0.121: [GC (System.gc()) [PSYoungGen: 4219K->680K(9216K)] 4219K->3760K(19456K), 0.0024028 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 0.124: [Full GC (System.gc()) [PSYoungGen: 680K->0K(9216K)] [ParOldGen: 3080K->3639K(10240K)] 3760K->3639K(19456K), [Metaspace: 2587K->2587K(1056768K)], 0.0062622 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
1)最前面的數字0.121、0.124代表了GC發生的時間,這個數字的含義是從JAVA虛擬機啟動以來經過的秒數;
2)GC日誌開頭的“[GC”和“[Full GC”說明了這次垃圾收集的停頓類型,而不是用來區分新生代GC還是老年代GC。如果有"Full",說明這次GC是發生了Stop-The-World的,就是指在執行GC操作的時候,會停止掉當前正在進行的其他線程,有一種“這是我的地盤,你們都給我讓開”的霸道有木有?如果是調用System.gc()的方法所觸發的收集,將會顯示“Full GC(System.gc)",本文的例子就是使用System.gc()進行的收集;
3)接下來的"[PSYoungGen"、“[ParOldGen”、“[Metaspace“標示GC發生的區域,這裏顯示的區域名稱與所使用的GC收集器密切相關(以後會對垃圾收集器進行詳細介紹),下面是常見收集器所代表的的區域名稱:
1>如果使用的是Serial(串行)收集器,新生代名為Default New Generation ,顯示就是DefNew
2>如果使用的是ParNew(並行)收集器,新生代名稱就會變為[Parnew,意思為Parallel New Generation
3>如果采用的是Parallel Scavenge收集器,新生代名稱為PSYongGen
老年代和永久代同理,名稱由垃圾收集器決定
如上面的日誌中新生代名稱為[PSYoungGen,使用的是Parallel Scavenge收集器;老年代名稱為[ParOldGen,使用的是Paralled Old收集器(Parallel Scavenge收集器的老年代版本),還有元空間區域,有些文章中使用的是”[PermGen“,這時jdk8之前的版本,由於我使用的是jdk8,所以已經被”[Metaspace“所代替,至於為什麽被代替,可以參考篇文章:https://blog.csdn.net/zhushuai1221/article/details/52122880
4)每個區域冒號後面,中括號內部的”680K->0K(9216K)]“含義是”GC前該內存區域已使用容量->GC後該內存區域已使用容量(該內存區域總容量)“。而在方括號之外的”3760K->3639K(19456K)“表示的是"GC前Java堆已使用容量->GC後Java堆已使用容量(Java堆總容量)"。
5)再往後 0.0062622 secs表示該內存區域GC所占用的時間單位是秒,有的收集器會給出具體的時間,如本例中的”[Times: user=0.06 sys=0.00, real=0.01 secs]“,這裏面的user、sys、real與Linux命令所輸出的時間含義一直,分別代表用戶態消耗的CPU時間、內核態消耗的CPU時間和操作從開始到結束所經過的墻鐘時間(Wall Clock Time)
TIPS:墻鐘時間與CPU時間的區別是,墻鐘時間包括各種非運算的等待耗時,例如等待磁盤的IO、等待線程阻塞;而CPU時間不包括這些耗時,但當系統中有對CPU或者多核的話,多線程操作會疊加這些CPU時間,所以讀者看到user或sys的時間超過real時間是完全正常的。
上面對GC日誌中各從參數的介紹摘自《深入理解Java虛擬機(第二版)》
再往下看,從第6行開始到結束的內容是各內存區域容量的變化情況!
備註:以上內容來源於《深入理解Java虛擬機》,根據自己的理解來總結,有些內容和書本內容相同是因為只有這麽描述才比較好懂,畢竟大神還是大神,是顏色不一樣的煙火!!
Java虛擬機系列(四)---查看GC日誌