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