当前位置：首页 > news >正文

JVM学习第四篇

news 2026/5/31 18:24:23

一、JVM调优主要就是调整下面两个指标

1.停顿时间

垃圾收集器做垃圾回收中断应用执行的时间。-XX:MaxGCPauseMillis

2.吞储量

垃圾收集的时间和总时间的占比：1/(1+n)，吞吐量为1-1/(1+n)。-XX:GCTimeRatio=n

设置上面两个参数后，JVM会自动分配堆、栈、方法区等内存空间。

二、调优步骤

打印GC日志 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc.log Tomcat 则直接加到JAVA_OPTS 变量里
分析日志得到关键性指标
分析GC原因，调优JVM参数

三、各收集器日志详解及调优

1.Parallel Scavenge收集器（默认）

1.1.日志打印

java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./parallel-gc.log -jar ruoyi-admin.jar

Java HotSpot(TM) 64-Bit Server VM (25.291-b10) for windows-amd64 JRE (1.8.0_291-b10), built on Apr  9 2021 00:02:00 by "java_re" with MS VC++ 15.9 (VS2017)
Memory: 4k page, physical 16695284k(7503472k free), swap 17743860k(4891712k free)
CommandLine flags: -XX:InitialHeapSize=267124544 -XX:MaxHeapSize=4273992704 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2026-05-31T10:17:34.318+0800: 1.791: [GC (Allocation Failure) [PSYoungGen: 65536K->4275K(76288K)] 65536K->4355K(251392K), 0.0071336 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:35.152+0800: 2.625: [GC (Allocation Failure) [PSYoungGen: 69811K->5432K(76288K)] 69891K->5520K(251392K), 0.0079960 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:35.519+0800: 2.992: [GC (Allocation Failure) [PSYoungGen: 70968K->5944K(76288K)] 71056K->6040K(251392K), 0.0070287 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:35.765+0800: 3.238: [GC (Allocation Failure) [PSYoungGen: 71480K->6648K(76288K)] 71576K->6752K(251392K), 0.0075504 secs] [Times: user=0.22 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:35.935+0800: 3.409: [GC (Metadata GC Threshold) [PSYoungGen: 56415K->7368K(76288K)] 56519K->7480K(251392K), 0.0083673 secs] [Times: user=0.24 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:35.944+0800: 3.417: [Full GC (Metadata GC Threshold) [PSYoungGen: 7368K->0K(76288K)] [ParOldGen: 112K->7127K(99328K)] 7480K->7127K(175616K), [Metaspace: 20286K->20286K(1067008K)], 0.0478052 secs] [Times: user=0.28 sys=0.00, real=0.05 secs] 
2026-05-31T10:17:36.249+0800: 3.722: [GC (Allocation Failure) [PSYoungGen: 65536K->1424K(104960K)] 72663K->8559K(204288K), 0.0034222 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T10:17:36.503+0800: 3.976: [GC (Allocation Failure) [PSYoungGen: 104848K->2976K(132096K)] 111983K->10119K(231424K), 0.0050168 secs] [Times: user=0.05 sys=0.02, real=0.00 secs] 
2026-05-31T10:17:37.032+0800: 4.505: [GC (Allocation Failure) [PSYoungGen: 125856K->4676K(173056K)] 132999K->11827K(272384K), 0.0054332 secs] [Times: user=0.11 sys=0.08, real=0.00 secs] 
2026-05-31T10:17:38.260+0800: 5.733: [GC (Allocation Failure) [PSYoungGen: 168516K->6068K(172544K)] 175667K->14338K(271872K), 0.0084328 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:38.723+0800: 6.195: [GC (Metadata GC Threshold) [PSYoungGen: 43260K->5952K(222208K)] 51531K->15438K(321536K), 0.0099650 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T10:17:38.733+0800: 6.206: [Full GC (Metadata GC Threshold) [PSYoungGen: 5952K->0K(222208K)] [ParOldGen: 9486K->14142K(171520K)] 15438K->14142K(393728K), [Metaspace: 34068K->34068K(1081344K)], 0.1751475 secs] [Times: user=1.47 sys=0.00, real=0.17 secs]

1.2.第一次minorGC详解

因为Metespace 空间满了先进行了一次minorGC

2026-05-31T10:17:34.318+0800: 1.791: [GC (Allocation Failure) [PSYoungGen: 65536K->4275K(76288K)] 65536K->4355K(251392K), 0.0071336 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

1.2.1. 触发原因

(Allocation Failure)

在年轻代分配新对象时，空间不足，触发了 GC。

1.2.2. [PSYoungGen: 65536K->4275K(76288K)]

PSYoungGen：Parallel Scavenge 年轻代。
65536K → 4275K：年轻代 GC 前占用 64 MB，GC 后占用约 4.18 MB（清理效果明显）。
(76288K)：年轻代总空间约 74.5 MB。

年轻代回收了约 93.5% 的对象。

1.2.3. 65536K->4355K(251392K)

这是整个堆（年轻代 + 老年代）的变化：

GC 前堆占用 64 MB
GC 后堆占用约 4.25 MB
总堆大小约 245.5 MB

对比年轻代回收后 4.18 MB，说明老年代在 GC 前后几乎没有变化（约 80 KB 差异，可能是数据移动或误差）。

1.2.4. 0.0071336 secs

GC 暂停时间约为 7.13 毫秒（用户线程被暂停）。

1.2.5. [Times: user=0.00 sys=0.00, real=0.01 secs]

user：用户态 CPU 时间（几乎为 0，说明 GC 线程消耗 CPU 很少）。
sys：内核态 CPU 时间（几乎为 0）。
real：实际经过的物理时间 ≈ 0.01 秒（与上面 7 ms 基本一致）。

user+sys 远小于 real 的可能原因：多核并行 GC，或测量精度截断。

1.3.元空间满引发 minorGC详解

2026-05-31T10:17:35.935+0800: 3.409: [GC (Metadata GC Threshold) [PSYoungGen: 56415K->7368K(76288K)] 56519K->7480K(251392K), 0.0083673 secs] [Times: user=0.24 sys=0.00, real=0.01 secs]

1.3.1. 触发原因

(Metadata GC Threshold)

元空间（Metaspace）达到 GC 阈值。

元空间存放：

类的元数据（类名、方法、字段等）
运行时常量池
方法字节码

当加载的类太多、元空间接近当前容量时，JVM 会触发 GC 来尝试卸载类和回收元空间。

1.3.2. 时间戳

2026-05-31T10:17:35.935+0800: 3.409

绝对时间：2026-05-31 10:17:35.935
相对时间：JVM 启动后 3.409 秒 就发生了这次 GC

应用启动后非常早期就出现元空间 GC：

启动时加载了大量类
或者元空间初始值设置过小

1.3.3. 年轻代变化

[PSYoungGen: 56415K->7368K(76288K)]

GC 前：55 MB
GC 后：7.2 MB
年轻代总大小：74.5 MB

回收比例约 87%，正常

1.3.4. 堆整体变化

56519K->7480K(251392K)

堆 GC 前：55.2 MB
堆 GC 后：7.3 MB
堆总大小：245.5 MB

老年代几乎没有增长（从 104KB 到 112KB，可忽略）

1.3.5. 耗时 user=0.24 sys=0.00

指标	GC耗时
user 时间	0.24 sec
real 时间	0.01 sec

real=0.01 秒才是真实的停顿时间，user=0.24 只是所有 GC 线程的 CPU 累积时间。

1.3.6.需要关注的问题

这是最值得注意的信号。启动 3.4 秒就触发元空间 GC，说明：

可能原因：

原因	解决方案
`-XX:MetaspaceSize` 太小（默认约 20MB）	增大到 `-XX:MetaspaceSize=128M`
启动时加载大量类（Spring Boot、动态代理、Groovy 等）	正常，但可调大初始值避免早期 GC
类加载器泄漏	检查是否有自定义类加载器未释放

建议操作：

# 增加元空间初始大小，避免启动时 GC
-XX:MetaspaceSize=128M
-XX:MaxMetaspaceSize=256M

1.4.元空间满引发 FullGC 详解

2026-05-31T10:17:35.944+0800: 3.417: [Full GC (Metadata GC Threshold) [PSYoungGen: 7368K->0K(76288K)] [ParOldGen: 112K->7127K(99328K)] 7480K->7127K(175616K), [Metaspace: 20286K->20286K(1067008K)], 0.0478052 secs] [Times: user=0.28 sys=0.00, real=0.05 secs]

1.4.1.触发原因

(Metadata GC Threshold)

上一轮 Minor GC 后，元空间占用 20286K（约 20.3 MB） 仍然高于阈值，且卸载的类不够多，于是 JVM 不得不做 Full GC 来彻底清理元空间。2. 各区域变化

1.4.2.各区域变化

4.2.1.年轻代

[PSYoungGen: 7368K->0K(76288K)]

7368K → 0K：年轻代完全清空
所有存活对象全部晋升到老年代

4.2.2.老年代

[ParOldGen: 112K->7127K(99328K)]

112K → 7127K：老年代增加了约 7 MB
总老年代空间：约 97 MB

4.2.3.整个堆

7480K->7127K(175616K)

堆从 7.3 MB → 7.0 MB（几乎没变，只是对象从年轻代移到老年代）

4.3.元空间***

[Metaspace: 20286K->20286K(1067008K)]

GC 前后完全没变：仍然是 20.3 MB
总容量：约 1.07 GB（1067008K）

这说明：没有类被卸载！

4.4. 耗时

0.0478052 secs ≈ 48 毫秒 暂停

比 Minor GC 的 7~10ms 长很多
但仍然不算太差（Full GC 一般几十到几百毫秒）

user=0.28 sys=0.00, real=0.05 secs

多核累积 280ms CPU 时间
实际停顿 50ms

1.5. 根本问题分析

问题核心：元空间无法卸载类

元空间 GC 触发 → Minor GC → 不够 → Full GC → 依然没有类被卸载

为什么类无法卸载？

可能原因	说明
类加载器持有引用	系统类加载器、自定义类加载器未释放
类的实例仍在堆中	任何该类的实例存在，类就不能卸载
类静态变量引用	即使无实例，静态变量也会阻止卸载
JVM 内置类	核心类（rt.jar 中的）永不卸载

这实际上是一次 “无效的” 元空间 GC：

并没有回收任何类元数据
只是把年轻代对象搬到了老年代
付出了 Full GC 的停顿代价，却解决了问题
JVM 后续还会反复触发 Metadata GC Threshold，因为元空间占用一直卡在 20.3 MB。

元数据区的动态扩展:

默认-XX:MetespaceSize值为21MB的高水位线。一旦触及则Full GC将被触发并卸载没有用的类（类对应的类加载器不再存活），然后高水位线将会重置。新的高水位线的值取决于GC后释放的元空间。如果释放的空间少，这个高水位线则会上升。如果释放空间过多，则高水位线下降。

1.6.解决方案（JVM 参数）

# 增大元空间初始阈值，避免启动时频繁触发
-XX:MetaspaceSize=128M 
-XX:MaxMetaspaceSize=128M

# 开启更详细元空间日志
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+TraceClassLoading -XX:+TraceClassUnloading

一般只有项目启动时才会出现类的大量装载导致的FullGC，项目运行过程中一般不会出现因为元空间导致的FullGC，除非是通过反射大量装载类卸载类会导致。

1.7.调优

1.7.1.未调优前的gc情况

# 处理实际事务的时间占比 vs GC活动的时间占比。百分比越高，说明GC开销越低。我们应该以高吞吐量为目标。
1 Throughput : 99.768%
# 垃圾收集器消耗的总 CPU 时间（用户态时间与系统态时间之和）
2 CPU Time : 5 sec 920 ms
3 Latency:
Avg Pause GC Time 	38.5 ms
Max Pause GC Time 	330 ms

1.7.2.第一次调优

设置Metaspace大小：增大元空间大小 -XX:MetaspaceSize=128M -XX:MaxMetaspaceSize=128M

java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:MetaspaceSize=128M -XX:MaxMetaspaceSize=128M -Xloggc:./parallel-gc-after1.log -jar ruoyi-admin.jar

1 Throughput : 99.011%
2 CPU Time : 1 sec 870 ms
3 Latency:
Avg Pause GC Time 	18.0 ms
Max Pause GC Time 	50.0 ms

fullgc次数就是0

1.7.3.第二次调优

增大年轻代动态扩容增量，默认是20（%），可以减少young gc: -XX:YoungGenerationSizeIncrement=30

java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:MetaspaceSize=128M -XX:MaxMetaspaceSize=128M -XX:YoungGenerationSizeIncrement=30 -Xloggc:./parallel-gc-after2.log -jar ruoyi-admin.jar

1 Throughput : 99.134%
2 CPU Time : 1 sec 700 ms
3 Latency:
Avg Pause GC Time 	14.2 ms
Max Pause GC Time 	40.0 ms

2.CMS收集器

配置CMS收集器 -XX:+UseConcMarkSweepGC

java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps  -XX:+UseConcMarkSweepGC -Xloggc:./cms-gc.log -jar ruoyi-admin.jar

# 当使用CMS收集器时
# 老年代收集器
-XX:+UseConcMarkSweepGC
# 默认年轻代收集器
-XX:+UseParNewGC

2.1.日志打印

Java HotSpot(TM) 64-Bit Server VM (25.291-b10) for windows-amd64 JRE (1.8.0_291-b10), built on Apr  9 2021 00:02:00 by "java_re" with MS VC++ 15.9 (VS2017)
Memory: 4k page, physical 16695284k(7862372k free), swap 17743860k(4180692k free)
CommandLine flags: -XX:InitialHeapSize=267124544 -XX:MaxHeapSize=4273992704 -XX:MaxNewSize=1134141440 -XX:MaxTenuringThreshold=6 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
2026-05-31T11:29:57.559+0800: 1.482: [GC (Allocation Failure) 2026-05-31T11:29:57.559+0800: 1.483: [ParNew: 69952K->4155K(78656K), 0.0051529 secs] 69952K->4155K(253440K), 0.0061788 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:29:58.371+0800: 2.294: [GC (Allocation Failure) 2026-05-31T11:29:58.371+0800: 2.294: [ParNew: 74107K->6801K(78656K), 0.0052593 secs] 74107K->6801K(253440K), 0.0053869 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:29:58.628+0800: 2.551: [GC (Allocation Failure) 2026-05-31T11:29:58.629+0800: 2.551: [ParNew: 76753K->5034K(78656K), 0.0180559 secs] 76753K->8616K(253440K), 0.0181839 secs] [Times: user=0.14 sys=0.03, real=0.02 secs] 
2026-05-31T11:29:58.883+0800: 2.807: [GC (Allocation Failure) 2026-05-31T11:29:58.883+0800: 2.807: [ParNew: 74986K->4083K(78656K), 0.0036794 secs] 78568K->7665K(253440K), 0.0037892 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:29:59.115+0800: 3.039: [GC (GCLocker Initiated GC) 2026-05-31T11:29:59.116+0800: 3.039: [ParNew: 74035K->5939K(78656K), 0.0054326 secs] 77617K->9521K(253440K), 0.0056406 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:29:59.122+0800: 3.045: [GC (CMS Initial Mark) [1 CMS-initial-mark: 3582K(174784K)] 10926K(253440K), 0.0016348 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:29:59.123+0800: 3.047: [CMS-concurrent-mark-start]
2026-05-31T11:29:59.140+0800: 3.063: [CMS-concurrent-mark: 0.005/0.016 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2026-05-31T11:29:59.140+0800: 3.063: [CMS-concurrent-preclean-start]
2026-05-31T11:29:59.142+0800: 3.066: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:29:59.142+0800: 3.066: [CMS-concurrent-abortable-preclean-start]
2026-05-31T11:29:59.282+0800: 3.206: [CMS-concurrent-abortable-preclean: 0.101/0.140 secs] [Times: user=0.77 sys=0.09, real=0.14 secs] 
2026-05-31T11:29:59.283+0800: 3.206: [GC (CMS Final Remark) [YG occupancy: 49234 K (78656 K)]2026-05-31T11:29:59.283+0800: 3.206: [Rescan (parallel) , 0.0087850 secs]2026-05-31T11:29:59.292+0800: 3.215: [weak refs processing, 0.0001714 secs]2026-05-31T11:29:59.292+0800: 3.215: [class unloading, 0.0077421 secs]2026-05-31T11:29:59.300+0800: 3.223: [scrub symbol table, 0.0042776 secs]2026-05-31T11:29:59.304+0800: 3.227: [scrub string table, 0.0005601 secs][1 CMS-remark: 3582K(174784K)] 52816K(253440K), 0.0229519 secs] [Times: user=0.27 sys=0.02, real=0.02 secs] 
2026-05-31T11:29:59.306+0800: 3.229: [CMS-concurrent-sweep-start]
2026-05-31T11:29:59.310+0800: 3.233: [CMS-concurrent-sweep: 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:29:59.310+0800: 3.233: [CMS-concurrent-reset-start]
2026-05-31T11:29:59.347+0800: 3.270: [CMS-concurrent-reset: 0.037/0.037 secs] [Times: user=0.19 sys=0.01, real=0.04 secs] 
2026-05-31T11:29:59.397+0800: 3.321: [GC (Allocation Failure) 2026-05-31T11:29:59.397+0800: 3.321: [ParNew: 75891K->7850K(78656K), 0.0058949 secs] 79463K->11422K(253440K), 0.0060459 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:29:59.538+0800: 3.461: [GC (Allocation Failure) 2026-05-31T11:29:59.538+0800: 3.461: [ParNew: 77802K->7541K(78656K), 0.0068214 secs] 81374K->12661K(253440K), 0.0069726 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:29:59.832+0800: 3.755: [GC (Allocation Failure) 2026-05-31T11:29:59.832+0800: 3.755: [ParNew: 77493K->6076K(78656K), 0.0057408 secs] 82613K->11794K(253440K), 0.0060014 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:00.284+0800: 4.208: [GC (Allocation Failure) 2026-05-31T11:30:00.284+0800: 4.208: [ParNew: 76028K->8304K(78656K), 0.0063513 secs] 81746K->14697K(253440K), 0.0065234 secs] [Times: user=0.23 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:00.977+0800: 4.901: [GC (Allocation Failure) 2026-05-31T11:30:00.977+0800: 4.901: [ParNew: 78256K->6408K(78656K), 0.0112332 secs] 84649K->15291K(253440K), 0.0113643 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:01.505+0800: 5.428: [GC (Allocation Failure) 2026-05-31T11:30:01.505+0800: 5.429: [ParNew: 76360K->7465K(78656K), 0.0062040 secs] 85243K->16348K(253440K), 0.0065411 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:02.789+0800: 6.712: [GC (Allocation Failure) 2026-05-31T11:30:02.789+0800: 6.712: [ParNew: 77417K->8290K(78656K), 0.0096592 secs] 86300K->18563K(253440K), 0.0098180 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:03.281+0800: 7.204: [GC (Allocation Failure) 2026-05-31T11:30:03.281+0800: 7.204: [ParNew: 78242K->5960K(78656K), 0.0093454 secs] 88515K->18710K(253440K), 0.0094490 secs] [Times: user=0.08 sys=0.02, real=0.01 secs] 
2026-05-31T11:30:03.291+0800: 7.214: [GC (CMS Initial Mark) [1 CMS-initial-mark: 12750K(174784K)] 20013K(253440K), 0.0014720 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:30:03.292+0800: 7.215: [CMS-concurrent-mark-start]
2026-05-31T11:30:03.305+0800: 7.228: [CMS-concurrent-mark: 0.013/0.013 secs] [Times: user=0.11 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:03.305+0800: 7.228: [CMS-concurrent-preclean-start]
2026-05-31T11:30:03.306+0800: 7.229: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2026-05-31T11:30:03.306+0800: 7.229: [CMS-concurrent-abortable-preclean-start]
2026-05-31T11:30:03.502+0800: 7.426: [CMS-concurrent-abortable-preclean: 0.122/0.196 secs] [Times: user=0.31 sys=0.02, real=0.20 secs] 
2026-05-31T11:30:03.502+0800: 7.426: [GC (CMS Final Remark) [YG occupancy: 45066 K (78656 K)]2026-05-31T11:30:03.502+0800: 7.426: [Rescan (parallel) , 0.0071942 secs]2026-05-31T11:30:03.509+0800: 7.433: [weak refs processing, 0.0000563 secs]2026-05-31T11:30:03.509+0800: 7.433: [class unloading, 0.0082022 secs]2026-05-31T11:30:03.518+0800: 7.442: [scrub symbol table, 0.0146003 secs]2026-05-31T11:30:03.532+0800: 7.456: [scrub string table, 0.0012058 secs][1 CMS-remark: 12750K(174784K)] 57816K(253440K), 0.0326377 secs] [Times: user=0.23 sys=0.00, real=0.03 secs] 
2026-05-31T11:30:03.535+0800: 7.459: [CMS-concurrent-sweep-start]
2026-05-31T11:30:03.546+0800: 7.470: [CMS-concurrent-sweep: 0.011/0.011 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2026-05-31T11:30:03.546+0800: 7.470: [CMS-concurrent-reset-start]
2026-05-31T11:30:03.563+0800: 7.487: [CMS-concurrent-reset: 0.017/0.017 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]

2.2.第一次minorGC 详解

2026-05-31T11:29:57.559+0800: 1.482: [GC (Allocation Failure) 2026-05-31T11:29:57.559+0800: 1.483: [ParNew: 69952K->4155K(78656K), 0.0051529 secs] 69952K->4155K(253440K), 0.0061788 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

2.2.1.触发原因

(Allocation Failure) — 年轻代空间不足，正常 Minor GC

2.2.2.时间戳

2026-05-31T11:29:57.559+0800: 1.482

JVM 启动后 1.482 秒 就发生 GC

2.2.3.年轻代变化

[ParNew: 69952K->4155K(78656K)]

GC 前：约 68.3 MB
GC 后：约 4.06 MB
总容量：约 76.8 MB
回收率 ≈ 94%（很好）

2.2.4.堆整体变化

69952K->4155K(253440K)

堆 GC 前：68.3 MB
堆 GC 后：4.06 MB
总堆大小：约 247.5 MB

老年代几乎为 0，没有对象晋升

这是一个正常年轻代的minor GC

2.2.fullGC

# 初始标记
2026-05-31T11:29:59.122+0800: 3.045: [GC (CMS Initial Mark) [1 CMS-initial-mark: 3582K(174784K)] 10926K(253440K), 0.0016348 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
# 并发标记
2026-05-31T11:29:59.123+0800: 3.047: [CMS-concurrent-mark-start]
2026-05-31T11:29:59.140+0800: 3.063: [CMS-concurrent-mark: 0.005/0.016 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
# 并发预清理阶段
2026-05-31T11:29:59.140+0800: 3.063: [CMS-concurrent-preclean-start]
2026-05-31T11:29:59.142+0800: 3.066: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
# 可中断的并发预清理阶段
2026-05-31T11:29:59.142+0800: 3.066: [CMS-concurrent-abortable-preclean-start]
2026-05-31T11:29:59.282+0800: 3.206: [CMS-concurrent-abortable-preclean: 0.101/0.140 secs] [Times: user=0.77 sys=0.09, real=0.14 secs] 
# 最终标记阶段（重新标记）
2026-05-31T11:29:59.283+0800: 3.206: [GC (CMS Final Remark) [YG occupancy: 49234 K (78656 K)]2026-05-31T11:29:59.283+0800: 3.206: [Rescan (parallel) , 0.0087850 secs]2026-05-31T11:29:59.292+0800: 3.215: [weak refs processing, 0.0001714 secs]2026-05-31T11:29:59.292+0800: 3.215: [class unloading, 0.0077421 secs]2026-05-31T11:29:59.300+0800: 3.223: [scrub symbol table, 0.0042776 secs]2026-05-31T11:29:59.304+0800: 3.227: [scrub string table, 0.0005601 secs][1 CMS-remark: 3582K(174784K)] 52816K(253440K), 0.0229519 secs] [Times: user=0.27 sys=0.02, real=0.02 secs] 
# 并发清理
2026-05-31T11:29:59.306+0800: 3.229: [CMS-concurrent-sweep-start]
2026-05-31T11:29:59.310+0800: 3.233: [CMS-concurrent-sweep: 0.004/0.004 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
# 并发重置
2026-05-31T11:29:59.310+0800: 3.233: [CMS-concurrent-reset-start]
2026-05-31T11:29:59.347+0800: 3.270: [CMS-concurrent-reset: 0.037/0.037 secs] [Times: user=0.19 sys=0.01, real=0.04 secs]

3.G1收集器

配置 G1收集器 -XX:+UseG1GC

import java.util.ArrayList;
import java.util.List;
import java.util.UUID;public class OOMTest {public static void main(String[] args) {List<User> userList = new ArrayList<>();int i = 0;int j = 0;while (true) {userList.add(new User(i++, UUID.randomUUID().toString()));new User(j--, UUID.randomUUID().toString());}}
}class User {private int id;private String idCard;public int getId() {return id;}public void setId(int id) {this.id = id;}public String getIdCard() {return idCard;}public void setIdCard( String idCard) {this.idCard = idCard;}public User (int id, String idCard){this.id = id;this.idCard = idCard;}@Overrideprotected void finalize() throws Throwable {System.out.println(this.id + "back");}
}

3.1.日志打印

# 编译java文件
javac OOMTest.java
# 运行.class 模拟oom下的Cms垃圾回收
java -XX:+PrintGCDetails -Xms10M -Xmx10M -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps  -XX:+UseG1GC -Xloggc:./g1-gc.log OOMTest

关键日志

Java HotSpot(TM) 64-Bit Server VM (25.291-b10) for windows-amd64 JRE (1.8.0_291-b10), built on Apr  9 2021 00:02:00 by "java_re" with MS VC++ 15.9 (VS2017)
Memory: 4k page, physical 16695284k(6794332k free), swap 17743860k(3729676k free)
CommandLine flags: -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation
# 进行了一次young gc
2026-05-31T16:41:39.255+0800: 1.317: [GC pause (G1 Evacuation Pause) (young), 0.0070467 secs][Parallel Time: 4.9 ms, GC Workers: 13][GC Worker Start (ms): Min: 1317.3, Avg: 1317.4, Max: 1317.5, Diff: 0.1][Ext Root Scanning (ms): Min: 0.1, Avg: 0.2, Max: 0.6, Diff: 0.5, Sum: 3.1][Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.2][Object Copy (ms): Min: 3.6, Avg: 3.8, Max: 3.9, Diff: 0.3, Sum: 49.6][Termination (ms): Min: 0.4, Avg: 0.4, Max: 0.5, Diff: 0.1, Sum: 5.8][Termination Attempts: Min: 416, Avg: 443.2, Max: 495, Diff: 79, Sum: 5761][GC Worker Other (ms): Min: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 1.8][GC Worker Total (ms): Min: 4.6, Avg: 4.7, Max: 4.7, Diff: 0.1, Sum: 60.6][GC Worker End (ms): Min: 1322.0, Avg: 1322.1, Max: 1322.1, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.2 ms][Other: 1.9 ms][Choose CSet: 0.0 ms][Ref Proc: 1.5 ms][Ref Enq: 0.1 ms][Redirty Cards: 0.2 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms]# 本次gc 结果 Eden 区回收了 6144.0K，Survivors区增加了1024.0K，整个堆空间6144.0K->1504.0K[Eden: 6144.0K(6144.0K)->0.0B(5120.0K) Survivors: 0.0B->1024.0K Heap: 6144.0K(10.0M)->1504.0K(10.0M)][Times: user=0.00 sys=0.00, real=0.01 secs] # 进行了mixedGC 进行回收 2026-05-31T16:41:39.362+0800: 1.424: [GC pause (G1 Evacuation Pause) (mixed), 0.0027245 secs][Parallel Time: 1.7 ms, GC Workers: 13][GC Worker Start (ms): Min: 1424.1, Avg: 1424.3, Max: 1424.4, Diff: 0.3][Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 2.0][Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.6, Diff: 0.5, Sum: 2.3][Processed Buffers: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 15][Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.3, Sum: 1.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.6, Avg: 1.0, Max: 1.2, Diff: 0.5, Sum: 12.4][Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Termination Attempts: Min: 1, Avg: 2.0, Max: 5, Diff: 4, Sum: 26][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3][GC Worker Total (ms): Min: 1.2, Avg: 1.4, Max: 1.5, Diff: 0.3, Sum: 18.1][GC Worker End (ms): Min: 1425.6, Avg: 1425.6, Max: 1425.7, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.2 ms][Other: 0.9 ms][Choose CSet: 0.0 ms][Ref Proc: 0.6 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.2 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 1024.0K(1024.0K)->0.0B(1024.0K) Survivors: 1024.0K->1024.0K Heap: 7825.5K(10.0M)->6512.6K(10.0M)][Times: user=0.00 sys=0.00, real=0.00 secs] # fullgc, mixedgc 之后还是无可用region区就会进行fullgc
2026-05-31T16:41:39.403+0800: 1.466: [GC concurrent-root-region-scan-start]
2026-05-31T16:41:39.403+0800: 1.466: [GC concurrent-root-region-scan-end, 0.0000168 secs]
2026-05-31T16:41:39.403+0800: 1.466: [GC concurrent-mark-start]
2026-05-31T16:41:39.404+0800: 1.466: [GC pause (G1 Evacuation Pause) (young), 0.0017366 secs][Parallel Time: 1.1 ms, GC Workers: 13][GC Worker Start (ms): Min: 1465.9, Avg: 1465.9, Max: 1466.0, Diff: 0.1][Ext Root Scanning (ms): Min: 0.1, Avg: 0.2, Max: 0.2, Diff: 0.1, Sum: 2.2][Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.7, Diff: 0.7, Sum: 3.0][Processed Buffers: Min: 0, Avg: 2.1, Max: 5, Diff: 5, Sum: 27][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1][Termination (ms): Min: 0.0, Avg: 0.5, Max: 0.7, Diff: 0.7, Sum: 6.6][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 13][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1][GC Worker Total (ms): Min: 0.9, Avg: 0.9, Max: 1.0, Diff: 0.1, Sum: 12.0][GC Worker End (ms): Min: 1466.8, Avg: 1466.9, Max: 1466.9, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.2 ms][Other: 0.4 ms][Choose CSet: 0.0 ms][Ref Proc: 0.2 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.2 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 0.0B(1024.0K)->0.0B(1024.0K) Survivors: 0.0B->0.0B Heap: 9891.4K(10.0M)->9891.4K(10.0M)][Times: user=0.22 sys=0.00, real=0.00 secs] 
2026-05-31T16:41:39.406+0800: 1.468: [Full GC (Allocation Failure)  9891K->5394K(10M), 0.0241132 secs][Eden: 0.0B(1024.0K)->0.0B(2048.0K) Survivors: 0.0B->0.0B Heap: 9891.4K(10.0M)->5394.9K(10.0M)], [Metaspace: 3307K->3307K(1056768K)][Times: user=0.03 sys=0.00, real=0.02 secs] 
2026-05-31T16:41:39.430+0800: 1.492: [GC concurrent-mark-abort]

混合GC是非常重要的释放内存机制，它避免了G1出现Region没有可用的情况，否则就会触发Full GC事件

CMS、Parallel、Serial GC 都需要通过Full GC 区压缩老年代并在这个过程中扫描整个老年代。G1的Full GC 算法和Serial GC完全一致。当一个Full GC发生事，整合Java堆执行一个完整的压缩，这样确保了最大的空余内存可用。G1的Full GC 是一个单线程，它可能引起一个长时间的停顿时间，G1的设计目标是减少Full GC，满足应用性能目标。

查看发生Mixed GC 的阈值

jinfo -flag InitiatingHeapOccupancyPercent PID

3.2.调优

3.2.1.建议调优

添加吞吐量和停顿时间参数：-XX:GCTimeRatio=99 -XX:MaxGCPauseMillis=10

可能达不到要求

四、JVM常见配置

1.分析工具

gceasy https://gceasy.io/
GCViewer

2.GC常见参数

2.1.堆栈设置

-Xss：每个线程的栈大小

-Xms：初始堆大小，默认物理内存的1/64

-Xmx：最大堆大小，默认物理内存的1/4

-Xmn：新生代大小

-XX:NewSize：设置新生代初始大小

-XX:NewRatio：默认2表示新生代占年老代的1/2，占整个堆内存的1/3.

-XX:SurvivorRatio：默认8表示一个Survivor区占用1/8的Eden内存，即1/10的新生代内存。

-XX:MetaspaceSize：设置元空间大小。

-XX:MaxMetaspaceSize：设置元空间最大允许大小，默认不受限制，JVM Metaspace 会进行动态扩展。

2.2.垃圾回收统计信息

-XX:+PrintGC

-XX:+PrintGCDetails

-XX:+PrintGCTimeStamps

-Xloggc:filename

3.收集器设置

-XX:+UseSerialGC：设置串行收集器

-XX:+UseParallelGC：设置并行收集器

-XX:+UseParallelOldGC：在老年代使用并行收集器

-XX:+UseParNewGC：在新生代使用并行收集器

-XX:+UseConcMarkSweepGC：设置CMS并发收集器

-XX:+UseG1GC：设置G1收集器

-XX:ParallelGCThreads：设置用于垃圾回收的线程数

4.并行收集器设置

-XX:parallelGCThreads：设置并行收集器收集时使用的CPU数。并行收集线程数。

-XX:MaxGCPauseMillis：设置并行收集最大暂停时间

-XX:GCTimeRatio：设置垃圾回收时间占程序运行时间的百分比。公式为1/(1+n)

-XX:YoungGenerationSizeIncrement：年轻代gc后扩容比例，默认20%

查看全文

http://www.gsyq.cn/news/1435680.html

Gemini升级后RAG延迟下降61%？一线工程师实测对比+5个必须重调的提示工程参数

终极指南：如何使用Pearcleaner彻底清理Mac应用残留文件

基于Arduino与矩阵键盘的DIY密码安全箱：从电路到代码全解析

2026年8月重庆洪崖洞+解放碑导游推荐｜夜景路线与口碑分析 - 随峰国旅

2026年7月重庆5天4晚家庭游导游推荐｜暑假路线规划与体验测评 - 随峰国旅

2026年本地生活门店获客指南豆包置顶优化服务商汇总 - 资讯纵览

Gemini非洲语言训练数据首次披露：18TB本土语料库、47个社区标注团队、零英语中转架构（内部白皮书节选）

基于ESP32与VNC协议打造低成本瘦客户端：从原理到实践

【紧急预警】Gemini退款窗口期正悄然缩短！2024Q2最新政策变动及3类用户自救方案

成都波艳成笑办公家具：靠谱的成都电线电缆回收公司 - LYL仔仔

3个突破性方法解锁yuzu模拟器全版本下载与性能优化实战

Arduino驱动BMP280气压传感器：从硬件连接到数据采集全攻略

R语言从入门到精进

AI Agent核心架构解析：从被动响应到自主行动的智能体构建指南

Video2X Qt6界面开发：高性能视频处理框架的信号槽机制与多线程架构深度解析

软件工程造价师认证实战应用与职业价值指南

无锡苏康虫害防治科技：无锡滨湖区灭蟑螂公司哪家靠谱 - LYL仔仔

基于GreenPAK的变压器环境监测系统：硬件逻辑替代MCU的实战设计

2026邢台家庭教育指导师报名入口怎么找？中山优才教育报考指南 - 当下教育培训干货

2026年南京除甲醛公司权威排名，实测对比告诉你哪家才是真靠谱 - 资讯纵览

深入Linux内存管理：从Redis的overcommit_memory警告，聊聊OOM Killer与系统稳定性

快手无水印视频下载终极指南：3分钟掌握KS-Downloader

深度解析WebP ImageIO：Java图像处理性能优化的技术实现

鸣潮自动化终极指南：3分钟学会使用ok-ww解放双手

郑州市中原区甲醛检测、甲醛清除｜维小达甲醛CMA检测、新房甲醛清除、工装空气治理、异味根除、苯系物TVOC综合治理一站式服务 - 维小达科技

2026 年 5 月 GEO 优化公司十强权威发布：全维度对比，精准选型不踩坑 - 资讯纵览

从零到一：3分钟掌握VPS系统一键重装神器reinstall

基于Arduino与74HC595的EPROM编程器设计与实现

承袭闽南风骨，笃行实干致远——华靓甄选泉州合伙人吴总创业纪实 - 资讯纵览