GC日志格式及分析、heapdump文件獲取


==僅方便后續參考==

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)


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM