forrestajun

  博客园  :: 首页  :: 新随笔  :: 联系 :: 订阅 订阅  :: 管理

==仅方便后续参考==

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 -gc 17970 2000 20 (每隔2秒监控一次,共20次)
$ 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)

posted on 2015-02-10 22:33  forrestajun  阅读(10277)  评论(3编辑  收藏  举报