Java GC 日誌解析
JVM 在Java應用程序優化中是不可缺少的一大重項,如何合理配置Java參數,如果驗證配置參數的有效性,從GC日誌中可以獲得很重要的提示,以下是筆者對GC垃圾收集器默認開啟的組合日誌的部分的解析,希望能幫到想學習的同學O(∩_∩)O~~
工具/原料
- jdk1.6
- -XX:+PrintGCDetails
- XX:+PrintGCTimeStamps
- -Xloggc:filename
- glassfish
方法/步驟
-
1
Hotspot JVM GC 垃圾收集器的默認默認開啟的組合為:
-
2
使用GC日誌命令行選項為:
-XX:+PrintGCTimeStamps
-XX:+PrintGCDetails
-Xloggc:<filename>
-
3
JVM 【-server】
glassfish應用服務器 -server 啟動 垃圾收集器默認組合方式為
新生代:Parallel Scavenge 並行回收GC
年老代和持久代:Parallel Old並行GC
-
4
GC日誌打印信息:
-XX:+PrintGCTimeStamps輸出格式:
289.556: [GC [PSYoungGen: 314113K->15937K(300928K)] 405513K->107901K(407680K), 0.0178568 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
293.271: [GC [PSYoungGen: 300865K->6577K(310720K)] 392829K->108873K(417472K), 0.0176464 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
詳解:
293.271是從jvm啟動直到垃圾收集發生所經歷的時間,GC表示這是一次Minor GC(新生代垃圾收集);[PSYoungGen: 300865K->6577K(310720K)] 提供了新生代空間的信息,PSYoungGen,表示新生代使用的是多線程垃圾收集器Parallel Scavenge。300865K表示垃圾收集之前新生代占用空間,6577K表示垃圾收集之後新生代的空間。新生代又細分為一個Eden區和兩個Survivor區,Minor GC之後Eden區為空,6577K就是Survivor占用的空間。
括號裏的310720K表示整個年輕代的大小。
392829K->108873K(417472K),表示垃圾收集之前(392829K)與之後(108873K)Java堆的大小(總堆417472K,堆大小包括新生代和年老代)
由新生代和Java堆占用大小可以算出年老代占用空間,如,Java堆大小417472K,新生代大小310720K那麽年老代占用空間是417472K-310720K=106752k;垃圾收集之前老年代占用的空間為392829K-300865K=91964k 垃圾收集之後老年代占用空間108873K-6577K=102296k.
0.0176464 secs表示垃圾收集過程所消耗的時間。
[Times: user=0.06 sys=0.00, real=0.01 secs] 提供cpu使用及時間消耗,user是用戶模式垃圾收集消耗的cpu時間,實例中垃圾收集器消耗了0.06秒用戶態cpu時間,sys是消耗系統態cpu時間,real是指垃圾收集器消耗的實際時間。
-
5
-XX:+PrintGCDetails輸出格式:
293.289: [Full GC [PSYoungGen: 6577K->0K(310720K)]
[PSOldGen: 102295K->102198K(134208K)] 108873K->102198K(444928K)
[PSPermGen: 59082K->58479K(104192K)], 0.3332354 secs]
[Times: user=0.33 sys=0.00, real=0.33 secs]
說明:
Full GC表示執行全局垃圾回收
[PSYoungGen: 6577K->0K(310720K)] 提供新生代空間信息,解釋同上
[PSOldGen: 102295K->102198K(134208K)]提供了年老代空間信息;
108873K->102198K(444928K)整個堆空間信息;
[PSPermGen: 59082K->58479K(104192K)]提供了持久代空間信息;
-
6
JVM【-client】
glassfish應用服務器 默認 -client啟動 垃圾收集器默認組合方式為
新生代:Serial串行GC (新生代使用-XX:+UseSerialGC收集器)
年老代和持久代:Serial Old 串行GC
-
7
GC日誌打印信息:
-XX:+PrintGCTimeStamps輸出格式:
9.007: [GC 9.007: [DefNew: 13526K->1060K(14400K), 0.0041350 secs] 44692K->32226K(46108K), 0.0041767 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
9.259: [GC 9.259: [DefNew: 13924K->1089K(14400K), 0.0042760 secs] 45090K->32650K(46108K), 0.0043143 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
說明:
DefNew表示新生代使用Serial串行GC垃圾收集器,defNew提供新生代空間信息;
DefNewGeneration 就是 default new generation
-
8
-XX:+PrintGCDetails輸出格式:
9.348: [GC 9.348: [DefNew: 13953K->976K(14400K), 0.0040943 secs]9.352: [Tenured: 32163K->32220K(32220K), 0.1182207 secs] 45514K->32338K(46620K), [Perm : 30467K->30467K(65536K)], 0.1224318 secs] [Times: user=0.12 sys=0.00, real=0.13 secs]
DefNew:表示新生代使用Serial串行GC垃圾收集器,defNew提供新生代空間信息;
Tenured:提供年老代空間信息;
45514K->32338K(46620K):整個堆空間大小信息;
Perm :提供持久代空間信息;
Java GC 日誌解析