GC之七--gc日誌分析工具

性能測試排查定位問題，分析調優過程當中，會遇到要分析gc日誌，人肉分析gc日誌有時比較困難，相關圖形化或命令行工具能夠有效地幫助輔助分析。

Gc日誌參數

經過在tomcat啓動腳本中添加相關參數生成gc日誌

-verbose.gc開關可顯示GC的操做內容。打開它，能夠顯示最忙和最空閒收集行爲發生的時間、收集先後的內存大小、收集須要的時間等。

打開-xx:+ printGCdetails開關，能夠詳細瞭解GC中的變化。

打開-XX: + PrintGCTimeStamps開關，能夠了解這些垃圾收集發生的時間，自JVM啓動之後以秒計量。

最後，經過-xx: + PrintHeapAtGC開關了解堆的更詳細的信息。

爲了瞭解新域的狀況，能夠經過-XX:=PrintTenuringDistribution開關了解得到使用期的對象權。

-Xloggc:$CATALINA_BASE/logs/gc.log gc日誌產生的路徑

XX:+PrintGCApplicationStoppedTime // 輸出GC形成應用暫停的時間

-XX:+PrintGCDateStamps // GC發生的時間信息

Gc日誌

2016-11-23T11:01:27.738+0800: 0.150: [GC [PSYoungGen: 331K->288K(5952K)] 331K->288K(19648K), 0.0006495 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2016-11-23T11:01:27.739+0800: 0.152: [Full GC (System) [PSYoungGen: 288K->0K(5952K)] [PSOldGen: 0K->164K(13696K)] 288K->164K(19648K) [PSPermGen: 3054K->3054K(21248K)], 0.0059625 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2016-11-23T11:01:27.852+0800: 0.264: [GC [PSYoungGen: 103K->64K(5952K)] 267K->228K(19648K), 0.0066830 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2016-11-23T11:01:27.859+0800: 0.271: [Full GC (System) [PSYoungGen: 64K->0K(5952K)] [PSOldGen: 164K->165K(13696K)] 228K->165K(19648K) [PSPermGen: 3060K->3060K(21248K)], 0.0052429 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 

日誌中顯示了gc發生的時間，young區回收狀況，總體回收狀況，fullGC狀況，回收所消耗時間等.

 

經常使用JVM參數

分析gc日誌後，常常須要調整jvm內存相關參數，經常使用參數以下

-Xms：初始堆大小，默認爲物理內存的1/64(<1GB)；默認(MinHeapFreeRatio參數能夠調整)空餘堆內存小於40%時，JVM就會增大堆直到-Xmx的最大限制

-Xmx：最大堆大小，默認(MaxHeapFreeRatio參數能夠調整)空餘堆內存大於70%時，JVM會減小堆直到 -Xms的最小限制

-Xmn：新生代的內存空間大小，注意：此處的大小是（eden+ 2 survivor space)。與jmap -heap中顯示的New gen是不一樣的。整個堆大小=新生代大小 + 老生代大小 + 永久代大小。 
在保證堆大小不變的狀況下，增大新生代後,將會減少老生代大小。此值對系統性能影響較大,Sun官方推薦配置爲整個堆的3/8。

-XX:SurvivorRatio：新生代中Eden區域與Survivor區域的容量比值，默認值爲8。兩個Survivor區與一個Eden區的比值爲2:8,一個Survivor區佔整個年輕代的1/10。

-Xss：每一個線程的堆棧大小。JDK5.0之後每一個線程堆棧大小爲1M,之前每一個線程堆棧大小爲256K。應根據應用的線程所需內存大小進行適當調整。在相同物理內存下,減少這個值能生成更多的線程。可是操做系統對一個進程內的線程數仍是有限制的，不能無限生成，經驗值在3000~5000左右。通常小的應用， 若是棧不是很深， 應該是128k夠用的，大的應用建議使用256k。這個選項對性能影響比較大，須要嚴格的測試。和threadstacksize選項解釋很相似,官方文檔彷佛沒有解釋,在論壇中有這樣一句話:"-Xss is translated in a VM flag named ThreadStackSize」通常設置這個值就能夠了。

-XX:PermSize：設置永久代(perm gen)初始值。默認值爲物理內存的1/64。

-XX:MaxPermSize：設置持久代最大值。物理內存的1/4。

 

Gc日誌分析工具

(1)GCHisto

http://java.net/projects/gchisto

優勢：能夠橫向對比，如jvm參數調整前和調整後進行對比等。

直接點擊gchisto.jar就能夠運行，點add載入gc.log

統計了總共gc次數，youngGC次數，FullGC次數，次數的百分比，GC消耗的時間，百分比，平均消耗時間，消耗時間最小最大值等

示例： jdk1.6，jvm參數爲：-Xmx20m -XX:MaxDirectMemorySize=10m -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:gc1.6.log

2016-11-23T11:01:27.738+0800: 0.150: [GC [PSYoungGen: 331K->288K(5952K)] 331K->288K(19648K), 0.0006495 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2016-11-23T11:01:27.739+0800: 0.152: [Full GC (System) [PSYoungGen: 288K->0K(5952K)] [PSOldGen: 0K->164K(13696K)] 288K->164K(19648K) [PSPermGen: 3054K->3054K(21248K)], 0.0059625 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2016-11-23T11:01:27.852+0800: 0.264: [GC [PSYoungGen: 103K->64K(5952K)] 267K->228K(19648K), 0.0066830 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2016-11-23T11:01:27.859+0800: 0.271: [Full GC (System) [PSYoungGen: 64K->0K(5952K)] [PSOldGen: 164K->165K(13696K)] 228K->165K(19648K) [PSPermGen: 3060K->3060K(21248K)], 0.0052429 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 

GCHisto展現：

統計的圖形化表示

YoungGC,FullGC不一樣消耗時間上次數的分佈圖，勾選能夠顯示youngGC或fullGC單獨的分佈狀況

整個時間過程詳細的gc狀況，能夠對整個過程進行剖析

 

   

(2)GCLogViewer

只支持jdk1.6（32位），jdk7，jdk8不支持。

http://code.google.com/p/gclogviewer/

點擊run.bat運行

整個過程gc狀況的趨勢圖，還顯示了gc類型，吞吐量，平均gc頻率，內存變化趨勢等

Tools裏還能比較不一樣gc日誌

(3)HPjmeter

獲取地址 http://www.hp.com/go/java
參考文檔 http://www.javaperformancetuning.com/tools/hpjtune/index.shtml

工具很強大，但只能打開由如下參數生成的GC log， -verbose:gc -Xloggc:gc.log,添加其餘參數生成的gc.log沒法打開。

 

(4)GCViewer

http://www.tagtraum.com/gcviewer.html

這個工具用的挺多的，但只能在JDK1.5如下的版本中運行，1.6之後沒有對應。

(5)garbagecat

http://code.google.com/a/eclipselabs.org/p/garbagecat/wiki/Documentation

 

其它監控方法

Jvisualvm動態分析jvm內存狀況和gc狀況，插件：visualGC

 

  

jvisualvm還能夠heapdump出對應hprof文件（默認存放路徑：監控的服務器 /tmp下），利用相關工具，好比HPjmeter能夠對其進行分析

grep Full gc.log粗略觀察FullGC發生頻率

jstat –gcutil [pid] [intervel] [count]

jmap -histo pid能夠觀測對象的個數和佔用空間
jmap -heap pid能夠觀測jvm配置參數，堆內存各區使用狀況

jprofiler,jmap dump出來用MAT分析

 

若是要分析的dump文件很大的話，就須要不少內存，很容易crash。

因此在啓動時，咱們應該加上一些參數： Java –Xms512M –Xmx1024M –Xss8M 

  

參考資料：

（一）探祕Java虛擬機——內存管理與垃圾回收http://sunbean.blog.51cto.com/972509/768034