系统优化：真实系统中的 GC 分析_java cms gc参数优化-CSDN博客

本文链接：https://blog.csdn.net/weixin_45525272/article/details/144038838

系统优化：真实系统中的 GC 分析

GC 分析详解

Java 虚拟机 (JVM) 的垃圾回收 (GC) 是性能优化的核心环节，频繁的 GC 操作会显著降低系统吞吐量，增加响应时间，甚至引发服务不可用。为了理解 GC 的行为，GC 日志分析是必要的工具。以下内容详细解析 GC 日志的产生、如何分析及其优化方向。

1. GC 日志分析

在 Java 应用中，可以通过以下 JVM 参数开启 GC 日志记录：

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/apps/logs/gc/gc.log -XX:+UseConcMarkSweepGC

参数说明：

-XX:+PrintGCDetails：输出 GC 的详细信息。
-XX:+PrintGCDateStamps：记录 GC 事件的时间戳。
-Xloggc：指定 GC 日志输出文件路径。
-XX:+UseConcMarkSweepGC：启用 CMS 垃圾回收器。

以下是一个典型的 GC 日志示例：

2017-12-29T18:25:22.753+0800: 73143.256: [GC 2017-12-29T18:25:22.753+0800: 
73143.257: [ParNew: 559782K->1000K(629120K), 0.0135760 secs] 
825452K->266673K(2027264K), 0.0140300 secs] 
[Times: user=0.02 sys=0.00, real=0.02 secs]

日志解析：

时间戳
2017-12-29T18:25:22.753+0800: 表示 GC 事件发生的日期和时间。 73143.256: 表示 JVM 启动后的相对秒数。
GC 类型与回收器
[ParNew: 559782K->1000K(629120K)]: 表示新生代使用了 ParNew 收集器。
- 559782K：回收前新生代占用内存。
- 1000K：回收后新生代占用内存。
- 629120K：新生代的总分配内存。
[825452K->266673K(2027264K)]: 表示堆内存的变化。
- 825452K：GC 前堆内存占用。
- 266673K：GC 后堆内存占用。
- 2027264K：堆内存总大小。
GC 耗时
0.0140300 secs: 本次回收耗时，单位为秒。
Times 表示线程的耗时信息：
- user: 线程的 CPU 用户态耗时。
- sys: 线程的 CPU 内核态耗时。
- real: 实际停顿时间。

关键指标：

Stop-the-World (STW) 时间：指应用线程暂停时间，直接影响系统的响应能力。如果时间较长，需要优化 GC 参数或调整内存分配策略。

2. CMS GC 日志分析

CMS (Concurrent Mark Sweep) 是一种针对老年代的垃圾回收器，基于“标记-清除”算法。CMS 的主要特点是减少 STW 时间，以提高应用的响应能力。

CMS 回收过程：

初始标记 (STW Initial Mark)
- 暂停所有应用线程，仅扫描 GC Root 对象。
- 时间短，因为只标记直接关联对象。
并发标记 (Concurrent Marking)
- 与应用线程并发执行，追踪 GC Root 可达对象。
并发预清理 (Concurrent Precleaning)
- 标记过程中新进入老年代的对象。
重新标记 (STW Remark)
- 再次暂停应用线程，处理遗留标记对象。
并发清理 (Concurrent Sweeping)
- 清除垃圾对象，与应用线程并发执行。
并发重置 (Concurrent Reset)
- 重置 CMS 数据结构，准备下一次回收。

示例日志：

2017-11-02T09:27:03.989+0800: 558115.552: [GC [1 CMS-initial-mark: 
1774783K(1926784K)] 1799438K(2068800K), 0.0123430 secs] 
[Times: user=0.01 sys=0.01, real=0.02 secs]

初始标记
- 1774783K(1926784K)：老年代当前使用与总容量。
- 0.0123430 secs：初始标记耗时。

2017-11-02T09:27:04.714+0800: 558116.277: [CMS-concurrent-mark: 0.713/0.713 secs]
[Times: user=1.02 sys=0.03, real=0.71 secs]

并发标记
- user=1.02 sys=0.03 real=0.71：CPU 用户态和实际时间对比表明，并发回收充分利用了多核。

2017-11-02T09:27:05.259+0800: 558116.822: [weak refs processing, 0.0011240 secs]

重新标记
- weak refs processing：处理弱引用耗时。

3. CMS 回收失败场景及优化

CMS 可能在以下场景下失败：

内存碎片过多：导致无法为大对象分配连续空间。
回收速度慢：新对象分配速度超过回收速度。

优化措施：

参数调整
- 增大老年代内存：-XX:CMSInitiatingOccupancyFraction=70。
- 增加线程：-XX:ParallelGCThreads。
切换收集器：改用 G1 垃圾回收器。

4. G1 GC 日志分析

G1 (Garbage First) 是为低延迟应用设计的垃圾回收器。相比 CMS，它避免了碎片化问题，且支持并发和分区回收。

G1 日志示例：

[GC pause (G1 Evacuation Pause) (young), 0.0123456 secs]
   [Eden: 512M->0B(1024M)]
   [Survivors: 8M->16M(32M)]
   [Heap: 1024M->768M(2048M)]
[Times: user=0.03 sys=0.01 real=0.01 secs]

Heap：堆内存变化。
Eden/Survivors：Eden 区与 Survivor 区内存分配。

优化方向：

调整分区大小：-XX:G1HeapRegionSize=16m。
增大并行回收线程：-XX:ParallelGCThreads。

通过详细分析日志和优化 GC 参数，可以最大化系统吞吐量，同时降低延迟，提升整体性能。

通过 GC 日志发现生产中实际问题

GC 日志可以帮助我们发现性能问题，例如频繁的 GC 导致应用停顿时间过长，或者内存不足导致 Full GC 频繁发生。以下是通过 GC 日志分析问题的步骤，以及一个具体的案例。

步骤 1：识别问题类型

年轻代 GC 频繁
新生代的 Eden 区空间不足时会触发 Minor GC。如果 GC 太频繁且回收时间长，说明：
- Eden 区大小不合理。
- 对象分配速率过高。
- Survivor 区不足，导致对象直接晋升到老年代。
Full GC 过多
老年代空间不足时触发 Full GC，常见原因：
- 老年代配置太小。
- 晋升速率过高，年轻代对象频繁晋升。
- 大对象过多。
GC 时间过长
Stop-the-World (STW) 时间超过预期，可能因为：
- 单线程回收，导致回收速度慢。
- 对象过多或碎片化严重。
内存泄漏
如果每次 GC 后堆内存使用量持续增长，可能存在内存泄漏或对象未被正确回收。

步骤 2：案例分析

场景描述
某生产环境中，系统出现了明显的卡顿现象。通过分析 GC 日志发现如下记录：

2024-11-25T10:00:01.123+0800: [GC (Allocation Failure) [PSYoungGen: 512M->100M(600M)] 
[ParOldGen: 1024M->1024M(1024M)] 1536M->1124M(1624M), 0.345 secs] 
[Times: user=0.32 sys=0.01 real=0.34 secs]

2024-11-25T10:00:03.567+0800: [Full GC (Ergonomics) [PSYoungGen: 100M->0B(600M)] 
[ParOldGen: 1024M->900M(1024M)] 1124M->900M(1624M), 1.567 secs] 
[Times: user=1.55 sys=0.01 real=1.57 secs]

问题点分析

年轻代 GC 日志
- 新生代空间 PSYoungGen: 512M->100M(600M)：表示年轻代在 Minor GC 后清理了 412 MB，但仍然有 100 MB 存在。
- 触发原因是 Allocation Failure，即年轻代空间不足。
老年代问题
- 老年代空间 ParOldGen: 1024M->1024M(1024M)：满了，无法存放晋升对象。
- 触发 Full GC，但 Full GC 后老年代仍然占用 900 MB，表明晋升对象较多且无法完全清理。
回收时间长
- Minor GC 耗时 0.345 秒，Full GC 耗时 1.567 秒，显著高于正常值，表明垃圾回收严重影响系统性能。

步骤 3：优化方案

1. 调整堆内存分配

问题：老年代过小，导致频繁的 Full GC。
解决

：增大老年代的内存分配：
```
-Xmx4g -Xms4g -XX:NewRatio=2
```
- -Xmx 和 -Xms 设置堆最大和最小内存。
- -XX:NewRatio=2 调整新生代与老年代的比例为 1:2。

2. 增大年轻代空间

问题：年轻代空间不足导致对象频繁晋升到老年代。
解决

：增大 Eden 区空间：
```
-XX:NewSize=1g -XX:MaxNewSize=1g -XX:SurvivorRatio=8
```
- -XX:NewSize 和 -XX:MaxNewSize 设置新生代最小和最大值。
- -XX:SurvivorRatio 设置 Eden 区和 Survivor 区的比例为 8:1。

3. 启用 G1 回收器

问题：CMS 收集器在 Full GC 时回收时间长。
解决

：切换为 G1 垃圾回收器：
```
-XX:+UseG1GC -XX:MaxGCPauseMillis=200 -XX:InitiatingHeapOccupancyPercent=45
```
- -XX:MaxGCPauseMillis 设置最大暂停时间为 200 毫秒。
- -XX:InitiatingHeapOccupancyPercent 当堆使用率达到 45% 时触发回收。

4. 检查代码中大对象分配

问题：大对象直接晋升到老年代。
解决：优化代码，避免频繁创建大对象，例如缓存对象池。

5. 检查内存泄漏

问题：Full GC 后老年代仍然占用较多内存。
解决：使用工具如 MAT (Memory Analyzer Tool) 或 VisualVM 检查内存泄漏。

步骤 4：优化后的日志验证

优化后，再次分析日志发现：

2024-11-25T12:00:01.123+0800: [GC (G1 Evacuation Pause) (young), 0.012 secs] 
[Times: user=0.04 sys=0.00 real=0.01 secs]

2024-11-25T12:15:01.567+0800: [GC (G1 Mixed Pause) 512M->256M(4096M), 0.045 secs] 
[Times: user=0.09 sys=0.01 real=0.05 secs]