Java - 理解GC日志

阅读GC日志是处理java虚拟机内存问题的必备技能，以下是一条常见的GC日志

2.614: [GC [PSYoungGen: 695091K->2144K(695808K)] 1965832K->1273408K(2094080K), 0.0161160 secs] 
[Times: user=0.05 sys=0.00, real=0.02 secs]

• 2.614 : 代表GC发生的时间，这个数字的含意是Java虚拟机启动以来经过的秒数

• [GC : 表示这次垃圾回收的停顿类型，而不是用来区分此次回收是新生代GC或是老年代GC

  • 如果是[Full GC，说明这次GC是发生了Stop The World的

• [PSYoungGen : 表示使用什麽垃圾收集器

  • Serial收集器的新生代名称为[DefNew，ParNew收集器的新生代名称是[ParNew，Parallel Scavenge配套的新生代名称为[PSYoungGen

• 方框内的695091K->2144K(695808K) : 表示 GC前该内存区域已使用的容量 -> GC后该内存区域已使用的容量(该内存区域的总容量)

• 方框外的1965832K->1273408K(2094080K) : 表示 GC前heap堆中已使用的容量 -> GC后heap堆中已使用的容量(heap堆的总容量)

• 0.0161160 secs : 表示该内存区域GC所佔用的事件，单位是秒

  • 有的收集器会给出更具体的时间数据，像是后面的[Times: user=0.05 sys=0.00, real=0.02 secs]，这裡面的user、sys、real和Linux的time命令所输出的时间定义一致

    • user : 用户态消耗的cpu时间

    • sys : 内核态消耗的cpu时间

    • real : 此方法从开始到结束所经过的时间，其中包括cpu运算以及等待各种非运算的时间，像是I/O、线程阻塞等

  • 当系统有多cpu或是多核时，多线程操作会叠加这些cpu时间，因此看到 user+sys > real 时，是完全正常的