JVM GC日志（一）

1.JVM启动参数

-Xloggc:D:/gc.log   日志文件保存的路径
-XX:+PrintGCDetails     打印回收详情
-XX:+PrintGCTimeStamps  打印JVM执行时间
-XX:+UseSerialGC  指定JVM使用串行垃圾收集器

2.执行代码

public class SimpleGc {
    public static void main(String[] args) {
        List<byte[]> l=new ArrayList<byte[]>();
        for(int i=0;i<1000000;i++){
            byte[] bytes= new byte[64];
            l.add(bytes);
            if(l.size()*64/1024/1024>13){
                l.clear();
            }
        }
    }
}

3.输出日志
这样配置以后，发生GC时输出的日志就类似于下面这种格式(为了显示方便,已手动换行):

0.341: [GC (Allocation Failure) 
    0.341:[DefNew: 34944K->4352K(39296K), 0.0235464 secs] 34944K->13487K(126720K), 0.0237237 secs] 
    [Times: user=0.00 sys=0.01, real=0.02 secs] 

0.381: [GC (Allocation Failure) 
    0.381: [DefNew: 39296K->4351K(39296K), 0.0197736 secs] 48431K->21422K(126720K), 0.0198706 secs] 
    [Times: user=0.03 sys=0.00, real=0.02 secs]

这个日志片段中发生了 2 次垃圾回收事件(Garbage Collection events)。两次清理的都是年轻代(Young generation)。下面我们来看，如何解读第一次GC事件，发生在年轻代中的小型GC(Minor GC):

1.0.341 GC时间的开始时间,相对于JVM的启动时间,单位是秒(Measured in seconds)

2.GC 用来区分(distinguish)是 Minor GC 还是 Full GC 的标志(Flag). 这里的 GC 表明本次发生的是 Minor GC

3.Allocation Failure 引起垃圾回收的原因. 本次GC是因为年轻代中没有任何合适的区域能够存放需要分配的数据结构而触发的

4.DefNew 使用的垃圾收集器的名字. DefNew 这个名字代表的是: 单线程(single-threaded), 采用标记复制(mark-copy)算法的, 使整个JVM暂停运行(stop-the-world)的年轻代(Young generation) 垃圾收集器(garbage collector)

5.34944K->4352K 在本次垃圾收集之前和之后的年轻代内存使用情况(Usage)

6.（39296K） 年轻代的总的大小(Total size)

7.34944K->13487K 在本次垃圾收集之前和之后整个堆内存的使用情况(Total used heap)

8.（126720K） 总的可用的堆内存(Total available heap)

9.0.0237237 secs GC事件的持续时间(Duration),单位是秒

10.[Times: user=0.00 sys=0.01, real=0.02 secs] GC事件的持续时间,通过多种分类来进行衡量
（1）user – 此次垃圾回收, 垃圾收集线程消耗的所有CPU时间(Total CPU time)
（2）sys – 操作系统调用(OS call) 以及等待系统事件的时间(waiting for system event)
（3）real – 应用程序暂停的时间(Clock time). 由于串行垃圾收集器(Serial Garbage Collector)只会使用单个线程, 所以 real time 等于 user 以及 system time 的总和.

通过上面的分析, 我们可以计算出在垃圾收集期间, JVM 中的内存使用情况。在垃圾收集之前, 堆内存总的使用了 34.125M (34,944K)。其中, 年轻代也是34.125M(34,944K)。可以算出老年代使用的内存为0。

垃圾回收后，年轻带的内存下降了29.8M（30,592K），但总的堆内存使用(total heap usage)只减少了 20.9M(21457k) .通过这一点,我们可以计算出, 有 8.9M(9135K) 的年轻代对象被提升到老年代(Old)中。

这个GC事件可以用下面的示意图来表示, 上方表示GC之前的内存使用情况, 下方表示结束后的内存使用情况: