《频繁 Yong GC 问题处理》

今天出现了一个问题,初步定位下来是属于 GC 相关的。通过分析 GC 日志发现 YongGC 每隔 1 秒多就会发生一次,而且每次 GC 的时间还不是很短,导致系统频繁卡顿。这个问题在之前就出现过,后来重启服务就没有这个问题了。这次又出现了,趁着有时间记录一下处理流程。

1. 启用详细的 GC 日志

首先需要配置 JVM 参数生成详细的 GC 日志:

java -XX:+PrintGCDetails \
     -XX:+PrintGCDateStamps \
     -XX:+PrintHeapAtGC \
     -XX:+PrintTenuringDistribution \
     -XX:+PrintGCApplicationStoppedTime \
     -Xloggc:/path/to/gc.log \
     -XX:+UseGCLogFileRotation \
     -XX:NumberOfGCLogFiles=5 \
     -XX:GCLogFileSize=10M \
     -jar your-application.jar

2. 日志核心指标解读

2.1 GC 频率与耗时

2025-07-07T09:28:12.097+0800: 113.006: [GC (Allocation Failure) [PSYoungGen: 102400K->25600K(153600K)] 102400K->76800K(512000K), 0.0102345 secs] [Times: user=0.04 sys=0.01, real=0.01 secs]
  • 关键信息
    • 2025-07-07T09:28:12.097+0800:GC 发生时间。
    • 113.006:JVM 启动后的秒数。
    • GC (Allocation Failure):GC 类型(YGC)及触发原因(内存分配失败)。
    • PSYoungGen: 102400K->25600K(153600K):年轻代回收前 102400K,回收后 25600K,总容量 153600K。
    • 102400K->76800K(512000K):堆内存回收前 102400K,回收后 76800K,总容量 512000K。
    • 0.0102345 secs:GC 耗时(秒)。
    • real=0.01 secs:GC 导致应用暂停的时间。

分析重点

  • 若 YGC 每 2 秒发生一次,但real时间很短(如 < 10ms),可能无需优化。

  • real时间过长(如 > 50ms),需优化 GC 或调整堆内存。

2.2 内存使用与增长趋势

Heap before GC invocations=10 (full 0):
 garbage-first heap   total 2097152K, used 1048576K [0x0000000780000000, 0x00000007c0000000)
  region size 1024K, 12 young (12288K), 0 survivors (0K)
 Metaspace       used 3456K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 384K, capacity 480K, committed 512K, reserved 1048576K

2025-07-07T09:28:12.097+0800: 113.006: [GC (Allocation Failure) ...
  • 关键信息
    • garbage-first heap total 2097152K, used 1048576K:G1 堆总容量 2048MB,使用 1024MB。
    • 12 young (12288K), 0 survivors (0K):12 个年轻代区域(共 12MB),0 个 Survivor 区域。
    • Metaspace used 3456K:元空间使用 3456KB。

分析重点

  • Eden 区增长速度:若 Eden 区在短时间内(如 2 秒)被填满,说明对象创建速率过高。

  • 老年代增长趋势:若老年代持续增长,可能存在对象过早晋升或内存泄漏。

2.3 对象晋升情况

Desired survivor size 5242880 bytes, new threshold 15 (max 15)
- age   1:    4194304 bytes,    4194304 total
- age   2:    2097152 bytes,    6291456 total
- age   3:    1048576 bytes,    7340032 total
  • 关键信息

    • Desired survivor size 5242880 bytes:Survivor 区期望大小(5MB)。
    • new threshold 15:对象晋升到老年代的年龄阈值(默认 15)。
    • age 1: 4194304 bytes:年龄为 1 的对象占用 4MB(刚经历第一次 YGC)。

    分析重点

    • 过早晋升:若大量对象在低年龄(如 age=2)就达到或超过Desired survivor size,会触发提前晋升,导致老年代空间压力。
    • 晋升速率:若老年代增长过快,需检查晋升对象的来源(如大对象、长生命周期对象)。

2.4 GC 类型与触发原因

[GC (Allocation Failure) ...  # 普通YGC
[Full GC (Metadata GC Threshold) ...  # 因元空间不足触发的Full GC
  • 常见触发原因
  • Allocation Failure:新生代无法分配新对象。
  • Metadata GC Threshold:元空间不足。
  • System.gc():代码显式调用 GC。

3. 定位频繁 Yong GC 的步骤

3.1 确认 GC 频率和耗时

统计 YGC 的平均间隔时间和单次耗时:

# 使用grep和awk分析GC日志(示例)
grep "GC (Allocation Failure)" gc.log | awk '{print $1, $NF}'
  • 结果示例:

    2025-07-07T09:31:40.023+0800 real=0.02 secs
    2025-07-07T09:31:41.317+0800 real=0.01 secs
    2025-07-07T09:31:42.621+0800 real=0.02 secs
    
  • 结论:YGC 每 2 秒发生一次,每次耗时约 10-20ms。

3.2 分析内存使用模式

关注以下指标:

  • Eden 区填充速率:计算两次 YGC 之间 Eden 区的增长速度。
  • Survivor 区利用率:若 Survivor 区长期接近满(如 > 90%),可能导致对象提前晋升。
  • 老年代增长趋势:若老年代持续增长,需检查是否存在内存泄漏或大对象直接分配到老年代。

3.3 检查对象晋升情况

  • 晋升年龄分布:通过PrintTenuringDistribution输出,确认是否有大量对象过早晋升。
  • 晋升速率:计算单位时间内晋升到老年代的对象大小,判断是否超出老年代的承受能力。

3.4 识别 GC 瓶颈

  • GC 耗时过长:若单次 YGC 耗时超过 50ms,可能是堆内存过大或 GC 算法不适合。
  • STW 时间过长:若real时间远大于user+sys时间,说明 GC 线程与应用线程的并行度不足。

4. 基于分析结果的优化方向

4.1 新生代空间过小

  • 现象:Eden 区很快被填满,YGC 频繁。

  • 解决方案:

    -Xmn1g  # 增大新生代至1GB
    -XX:SurvivorRatio=8  # 调整Eden:Survivor比例为8:1:1
    

4.2 对象创建速率过高

  • 现象:Eden 区填充速率极快(如每秒增长 100MB 以上)。
  • 解决方案:
    • 优化代码,减少临时对象的创建(如避免在循环中创建大对象)。
    • 增大 Eden 区大小。

4.3 过早晋升

  • 现象:对象在低年龄(如 age=2)就晋升到老年代。

  • 解决方案

    -XX:MaxTenuringThreshold=15  # 提高晋升年龄阈值
    -XX:SurvivorRatio=16  # 增大Survivor区,减少对象因Survivor空间不足而提前晋升
    

4.4 大对象直接分配到老年代

  • 现象:老年代突然增长,伴随频繁 YGC 甚至 Full GC。

  • 解决方案

    -XX:PretenureSizeThreshold=1048576  # 超过1MB的对象直接进入老年代(根据实际情况调整)
    

5. 自动化分析工具

手动分析 GC 日志效率较低,推荐使用以下工具:

5.1 GCViewer

5.2 GCeasy

  • 在线工具,上传 GC 日志后生成详细报告,包含问题诊断和优化建议。
  • 网址:https://gceasy.io

5.3 JDK 自带工具

# 使用jstat分析GC统计信息
jstat -gc <PID> 1000 10

# 使用jcmd生成GC概要
jcmd <PID> GC.heap_info
jcmd <PID> GC.class_histogram

总结

通过 GC 日志分析,重点关注内存分配模式对象晋升行为GC 耗时,结合代码审查和性能监控工具,通常可以定位频繁 Yong GC 的根本原因。优先调整 JVM 参数(如新生代大小、晋升阈值),若仍无法解决,则需从代码层面优化内存使用。