深入学习GC之-GC日志解读

    想要查看GC日志首先要在jvm的参数中加入下面的选项:  

 -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:d:/GClogs/tomcat6-gc.log 。 

   GC日志实例:

4.231: [GC 4.231: [DefNew: 4928K->512K(4928K), 0.0044047 secs] 6835K->3468K(15872K), 0.0045291 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 4.445: [Full GC (System) 4.445: [Tenured: 2956K->3043K(10944K), 0.1869806 secs] 4034K->3043K(15872K), [Perm : 3400K->3400K(12288K)], 0.1870847 secs] [Times: user=0.05 sys=0.00, real=0.19 secs]

下面来逐点解读:

1.   25.067和45.079表示发生GC的时间戳,是从jvm启动开始计时的。

2.   [GC 和 [Full GC 是垃圾回收的停顿类型，而不是区分是新生代还是年老代，如果有Full 说明发生了Stop-The-World ，是Full GC 。同时，如果是调用System.gc() 触发的，那么将显示的是[Full GC (System) 。

3. 接下来的 [DefNew , [Tenured ,[Perm 表示 GC 发生的区域，区域的名称与使用的 GC 收集器相关。 Serial 收集器中新生代名为 "Default New Generation"，显示的名字为 "[DefNew"。对于ParNew收集器，显示的是 "[ParNew"，表示 “Parallel New Generation”。 对于 Parallel Scavenge 收集器，新生代名为 "PSYoungGen"。年老代和永久代也相同，名称都由收集器决定。

4. 方括号内部显示的 “4928K->512K(4928K)” 表示 “GC 前该区域已使用容量 -> GC 后该区域已使用容量 (该区域内存总容量) 。

5.  “0.0044047 secs” 表示该区域GC所用时间，单位是秒。

6. “6835K->3468K(15872K)” 表示 “GC 前Java堆已使用容量 -> GC后Java堆已使用容量 （Java堆总容量）”。

7.  “0.0045291 secs” 是Java堆GC所用的总时间。

8. “[Times: user=0.00 sys=0.00, real=0.00 secs]” 分别代表 用户态消耗的CPU时间、内核态消耗的CPU时间 和 操作从开始到结束所经过的墙钟时间。墙钟时间包括各种非运算的等待耗时，如IO等待、线程阻塞。CPU时间不包括等待时间，当系统有多核时，多线程操作会叠加这些CPU时间，所以user或sys时间会超过real时间。