日志获取

命令：

jstat -gc <pid> [intervals] [count]

参数

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XLoggc:gc.log

垃圾回收类型

类型	收集区域
Minor GC	年轻代
Major GC	老年代
Full GC	内存堆

日志分析

为了垃圾回收更容易发生，设置以下虚拟机参数设置

-XX:NewSize=5M -XX:MaxNewSize=5M -XX:InitialHeapSize=10M -XX:MaxHeapSize=10M -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=10M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

模拟垃圾回收场景

public class MockGC {
    private static void minorGC() throws InterruptedException {

        byte[] x = new byte[2 * 1024 * 1024];
        x = new byte[2 * 1024 * 1024];

        Thread.sleep(1000);
    }

    public static void main(String[] args) throws InterruptedException {
        minorGC();
    }
}

部分日志输出如下

0.066: [GC (Allocation Failure) 0.066: [ParNew: 3921K->512K(4608K), 0.0012641 secs] 3921K->2771K(9728K), 0.0012991 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
...
2.117: [GC (CMS Initial Mark) [1 CMS-initial-mark: 3095K(5120K)] 5225K(9728K), 0.0001014 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.117: [CMS-concurrent-mark-start]
2.118: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.118: [CMS-concurrent-preclean-start]
2.118: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.118: [CMS-concurrent-abortable-preclean-start]
2.118: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.118: [GC (CMS Final Remark) [YG occupancy: 2129 K (4608 K)]2.118: [Rescan (parallel) , 0.0000850 secs]2.118: [weak refs processing, 0.0000047 secs]2.118: [class unloading, 0.0001180 secs]2.118: [scrub symbol table, 0.0001821 secs]2.118: [scrub string table, 0.0000555 secs][1 CMS-remark: 3095K(5120K)] 5225K(9728K), 0.0004671 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.118: [CMS-concurrent-sweep-start]
2.118: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2.118: [CMS-concurrent-reset-start]
2.118: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 4608K, used 2170K [0x00000000ff600000, 0x00000000ffb00000, 0x00000000ffb00000)
  eden space 4096K,  53% used [0x00000000ff600000, 0x00000000ff81ebb8, 0x00000000ffa00000)
  from space 512K,   0% used [0x00000000ffa00000, 0x00000000ffa00000, 0x00000000ffa80000)
  to   space 512K,   0% used [0x00000000ffa80000, 0x00000000ffa80000, 0x00000000ffb00000)
 concurrent mark-sweep generation total 5120K, used 3085K [0x00000000ffb00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 3840K, capacity 4536K, committed 4864K, reserved 1056768K
  class space    used 417K, capacity 428K, committed 512K, reserved 1048576K

日志分解

日志	解释
0.066	相对程序启动垃圾回收时间
GC (Allocation Failure)	对象分配内存失败
ParNew	年轻代垃圾回收器
3921->512K	垃圾回收前后年轻代内存占用
(4608K)	年轻代容量
0.0012641 secs	年轻代垃圾回收耗时
3921->2771	垃圾回收前后堆内存占用
(9728K)	堆容量
0.0010296 secs	堆垃圾回收耗时
2.117	相对程序启动垃圾回收时间
GC (CMS Initial Mark)	初始标记，标记老年代中被年轻代引用的对象与根对象(STW)
3095K(5120K)	老年代内存占用与容量
5225K(9728K)	堆内存占用与容量
CMS-concurrent-mark-start	并发标记，标记与上一阶段对象有引用关系的老年代对象
CMS-concurrent-mark: 0.001/0.001 secs	并发标记耗时
CMS-concurrent-preclean-start	预清理，标记上一阶段与年轻代标记有引用关系的老年代对象
CMS-concurrent-preclean: 0.000/0.000 secs	预清理耗时
CMS-concurrent-abortable-preclean-start	可中止预清理，标记上一阶段与年轻代标记存活的老年代有引用关系的对象
CMS-concurrent-abortable-preclean: 0.000/0.000 secs	可中止预清理耗时
GC (CMS Final Remark)	最终标记，根据年轻代、根对象与上一阶段标记老年代所有存活对象(STW)
YG occupancy：2129 K (4608 K)	年轻代内存占用与容量
Rescan (parallel)	存活对象最终标记
weak refs processing	弱引用处理
class unloading	卸载类
scrub symbol table、scrub string table	清理元数据、字符串表
3095K(5120K)	老年代内存占用与容量
5225K(9728K)	堆内存占用与容量
CMS-concurrent-sweep-start	并发清理所有未被标记的对象
CMS-concurrent-reset-start	重置垃圾回收器内部数据结构
Heap	虚拟机退出时堆内存快照情况

JVM GC 日志获取与分析

日志获取

垃圾回收类型

日志分析