GC-日志

GC日志配置

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:servers/%SERVER_NAME%_gc.log -XX:+HeapDumpOnOutOfMemoryError
注意，%SERVER_NAME%是win格式，linux下为${SERVER_NAME}。

JVM的GC日志的主要参数包括如下几个：
-XX:+PrintGC 输出简单GC日志
-XX:+PrintGCDetails 输出GC的详细日志
-XX:+PrintGCTimeStamps 输出GC的时间戳（相对JVM启动时间的秒数）
-XX:+PrintGCDateStamps 输出GC的时间戳（以日期的形式，如 2013-05-04T21:53:59.234+0800）
-XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log 日志文件的输出路径

gcutil使用

jstat -gcutil 17970 1000 10 (按百分比显式)

手工触发 Java heap dump

1、命令：jmap -dump:format=b,file=a.hprof <pid>

file：保存路径及文件名
pid：进程编号
2、在应用启动时配置参数 -XX:+HeapDumpOnOutOfMemoryError，当应用抛出OutOfMemoryError时自动生成dump文件。

例子（转载）

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:../logs/gc.log
输出的格式：
5.617: [GC 5.617: [ParNew: 43296K->7006K(47808K), 0.0136826 secs] 44992K->8702K(252608K), 0.0137904 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
5.617（时间戳）: [GC（Young GC） 5.617（时间戳）: [ParNew（使用ParNew作为年轻代的垃圾回收期）: 43296K（年轻代垃圾回收前的大小）->7006K（年轻代垃圾回收以后的大小）(47808K)（年轻代的总大小）, 0.0136826 secs（回收时间）]
44992K（堆区垃圾回收前的大小）->8702K（堆区垃圾回收后的大小）(252608K)（堆区总大小，年轻代+老年代）, 0.0137904 secs（回收时间）] [Times: user=0.03（Young GC用户耗时） sys=0.00（Young GC系统耗时）, real=0.02 secs（Young GC实际耗时）]

我们再对数据做一个简单的分析
7.429: [GC 7.429: [ParNew: 45278K->6723K(47808K), 0.0251993 secs] 46974K->10551K(252608K), 0.0252421 secs]
从这条GC记录中我们可以看到：
Young GC回收了 45278-6723 =38555K的内存
Heap区通过这次回收总共减少了 46974-10551=36423K的内存。
38555-36423=2132K说明通过该次Young GC有2132K的内存被移动到了Old Gen，

-XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
我们来验证一下
在最后一次Young GC的回收以前 Old Gen的大小为8702-7006=1696
回收以后Old Gen的内存使用为10551-6723=3828
Old Gen在该次Young GC以后内存增加了3828-1696=2132K 与预计的相符

[root@localhost ~]# jstat -gcutil 3517 5000
S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 0.00 35.84 34.48 33.22 5 0.687 2 0.683 1.370
0.00 0.00 36.27 34.48 33.22 5 0.687 2 0.683 1.370
0.00 0.00 36.38 34.48 33.23 5 0.687 2 0.683 1.370
0.00 0.00 36.81 34.48 33.23 5 0.687 2 0.683 1.370
0.00 0.00 37.15 34.48 33.23 5 0.687 2 0.683 1.370
0.00 0.00 38.11 34.48 33.23 5 0.687 2 0.683 1.370
0.00 0.00 38.25 34.48 33.23 5 0.687 2 0.683 1.370

其中3517为进程号，5000表示每5000毫秒刷一次，如果要限制次数后面可以继续加数字 例如jstat -gcutil 3517 5000 10 表示刷10次
S0：年轻代中第一个survivor（幸存区）已使用的占当前容量百分比
S1：年轻代中第二个survivor（幸存区）已使用的占当前容量百分比
E：年轻代中Eden（伊甸园）已使用的占当前容量百分比
O：old代已使用的占当前容量百分比
P：perm代已使用的占当前容量百分比
YGC：从应用程序启动到采样时年轻代中gc次数
YGCT：从应用程序启动到采样时年轻代中gc所用时间(s)
FGC：从应用程序启动到采样时old代(全gc)gc次数
FGCT：从应用程序启动到采样时old代(全gc)gc所用时间(s)
GCT：从应用程序启动到采样时gc用的总时间(s)