1. 程式人生 > >Java虛擬機系列(四)---查看GC日誌

Java虛擬機系列(四)---查看GC日誌

位置 最大堆 其他 asp alloc -s 調研 server pan

這一節穿插一點如何在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日誌

-Xloggc:d:/gc4.log //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日誌