GC日志分析

前言：

在处理一次现场问题时，发现服务还在运行，但是出现假死情况，后通过分析GC日志以及使用MAT分析确定问题是内存溢出OutOfMemery(OOM)；这里只记录GC分析学习过程

---------------------------------------
2023-01-10T09:00:08.485+0800
    日志打印时间 日期格式
---------------------------------------
20.878
    gc发生时，Java虚拟机启动以来经过的秒数
---------------------------------------
Full GC(Metadata GC Threshold)
    发生了一次垃圾回收，这是一次FULL GC。它不区分新生代GC还是老年代GC
    括号里的内容是GC发生的原因，这里的Metadata gC Threshold的原因是Metaspace区不够用了
        Full GC(Ergonomics)：JVM自适应调整导致的GC
        Full GC(System)：调用了System.gc()方法
---------------------------------------
[PSYoungGen: 5047K->0K(1390080K)]
    PSYoungGen：表示GC发生的区域，区域名称与使用的GC收集器是密切相关的。
        Serial收集器：Default New Generation 显示DefNew
        ParNew收集器：ParNew
        Parallel Scanvenge收集器：PSYoung
        老年代和新生代同理，也是和收集器名称相关
    5047K->0K(1390080K)：GC前该内存区域已使用容量->GC后该区域已使用容量（该区域总容量）
        如果是新生代，总容量则会显示整个新生代内存的9/10，即eden + from/to区
        如果是老年代，总容量则是全部内存大小，无变化。
---------------------------------------
[ParOldGen: 19464K->24085K(3495424K)]
    老年代区域没有发生GC，因为本次GC是metaspace引起的
---------------------------------------
24511K->24085K(4885504K),
    在显示完区域容量GC的情况之后，会接着显示整个堆内存区域的GC情况：
    GC前堆内存已使用容量->GC堆内存容量(堆内存总容量)
    堆内存总容量 = 9 / 10 新生代 + 老年代 < 初始化的内存大小
---------------------------------------
[Metaspace: 20604K->20604K(1069056K)],
    metaspace GC回收2K空间
---------------------------------------
0.1345727 secs
    整个GC所花费的时间，单位是秒
---------------------------------------
[Times: user=0.56 sys=0.11,real=0.14 secs]
    user：指的是CPU工作在用户态所花费的时间
    sys：指的是CPU工作在内核态所花费的时间
    real：指的是在此次GC事件中所花费的总时间

HotSpot VM中GC分类

• 部分收集（Partial GC）：不是完整收集整个Java堆的垃圾收集。
  • 新生代收集（Minor GC / Young GC）：只是新生代（Eden / S0, S1）的垃圾收集。
  • 老年代收集（Major GC / Old GC）：只是老年代的垃圾收集。目前，只有CMS GC会有单独收集老年代的行为。注意，很多时候Major GC会和Full GC混淆使用，需要具体分辨是老年代回收还是整堆回收。
• 混合收集（Mixed GC）：收集整个新生代以及部分老年代的垃圾收集。目前，只有G1 GC会有这种行为。
• 整堆收集（Full GC）：收集整个java堆和方法区的垃圾收集。

GC日志分类

GC日志格式的规律一般都是：GC前内存占用-＞GC后内存占用（该区域内存总大小）
中括号内：GC回收前年轻代堆大小，回收后大小，（年轻代堆总大小）
括号外：GC回收前年轻代和老年代大小，回收后大小，（年轻代和老年代总大小）
[PSYoungGen: 5986K->696K (8704K) ] 5986K->704K (9216K)

• Minor GC（Young GC,YGC）：
  

[GC (Allocation Failure) [PSYoungGen: 1434170K->42506K(1556480K)] 1472322K->80667K(5051904K), 0.0378357 secs] [Times: user=0.15 sys=0.00, real=0.04 secs]

• Full GC
  

[Full GC (Metadata GC Threshold) [PSYoungGen: 61144K->0K(1555968K)] [ParOldGen: 60728K->108132K(3495424K)] 121873K->108132K(5051392K), [Metaspace: 57548K->57548K(1101824K)], 0.2063855 secs] [Times: user=0.91 sys=0.04, real=0.20 secs]

触发Full GC

• 老年代空间不足；
• 方法区空间不足；
• 显示调用system.gc();
• Minor GC进入老年代的平均值大于老年代可用内存；
• 大对象直接进入老年代，而老年代空间不足；

垃圾收集器

• Serial收集器：新生代显示 DefNew，即 Default New Generation
• ParNew收集器：新生代显示 ParNew，即 Parallel New Generation
• Parallel Scavenge收集器：新生代显示PSYoungGen
• Parallel Old收集器：老年代显示ParoldGen
• G1收集器：显示garbage-first heap

GC原因

• Allocation Failure：表明本次引起GC的原因是因为新生代中没有足够的区域存放需要分配的数据
• Metadata GCThreshold：Metaspace区不够用了
• FErgonomics：JVM自适应调整导致的GC
• System：调用了System.gc()方法

GC时间

• user：进程执行用户态代码（核心之外）所使用的时间。这是执行此进程所使用的实际CPU 时间，其他进程和此进程阻塞的时间并不包括在内。在垃圾收集的情况下，表示GC线程执行所使用的 CPU 总时间。
• sys：进程在内核态消耗的 CPU 时间，即在内核执行系统调用或等待系统事件所使用的CPU 时间
• real：程序从开始到结束所用的时钟时间。这个时间包括其他进程使用的时间片和进程阻塞的时间（比如等待 I/O 完成）。对于并行gc，这个数字应该接近（用户时间＋系统时间）除以垃圾收集器使用的线程数。