面试必问:系统频繁Fullgc，你有哪些优化思路？第一步分析gc日志（1）

，我遇到了一个Java GC问题。有个服务在高峰期耗时增加，触达上游超时配置，导致上游调用失败率增加。经过初步排查确认这并非因为个别接口的性能恶化，而是服务整体上性能恶化。

最终定位原因是，高峰期 YoungGC和 FullGC 频率过高，导致耗时增加。遂决定从GC方向优化性能，经过两周的治理，GC问题得到大幅改善，接口耗时下降30%。

这个经历很难得，我决定把问题排查经历转化知识点分享给大家

理解GC 日志，是GC 参数调优的第一步。

我把重要知识点和GC日志结合起来，逐行讲解 GC 日志，可以更容易理解Java GC原理。以下是 ParNew + CMS 垃圾回收器的 young gc 日志。

1) 历史GC次数

49590 {Heap before GC invocations=1807 (full 5):

代表 JVM 启动后，共发生 1807 次 young gc，5 次 full gc。

2) 新生代大小

49591 par new generation total 5976896K, used 5864962K [0x0000000540800000, 0x00000006c0800000, 0x00000006c0800000)

par new generation 代表 新生代大小 5976M，已使用 5864M。这是大约值，近似除以 1000 即可，无需精确到 1024。

3) Eden Space 新生代Eden大小

49592 eden space 5662336K, 100% used [0x0000000540800000, 0x000000069a1a0000, 0x000000069a1a0000)

eden space 5662336K, 100% used 代表新生代使用率100%，一般发生 ygc时，eden 区为 100%。

4) Survivor 区大小

vbnet

代码解读

复制代码

49593 from space 314560K, 64% used [0x00000006ad4d0000, 0x00000006b9ab08c0, 0x00000006c0800000) 49594 to space 314560K, 0% used [0x000000069a1a0000, 0x000000069a1a0000, 0x00000006ad4d0000)

from space 314560K 代表Survivor区大小 314M，Survivor区大小可通过 SurvivorRadio配置，默认为 8，即 Eden和 Survivor 比例=8:2，其中 Survivor区分为 From 和 TO，各占 1 半。实际比例Eden: From:TO=8:1:1

5) GC前老年代大小

49595 concurrent mark-sweep generation total 4194304K, used 1986511K [0x00000006c0800000, 0x00000007c0800000, 0x00000007c0800000)

这行代表发生 younggc 前，老年代总共 4194M，已使用 1986M。

6) 元空间大小

代码解读

复制代码

49596 Metaspace used 333223K, capacity 338440K, committed 338560K, reserved 1357824K

元空间大小，存储了类的二进制数据，注意非 Class 对象。其中 Meta 区分为 ClassSpace 和 NonClass Space，nonClass space包含常量池等。

used、capacity、committed、reserved 这 4 个值逐渐变大。 

7) YoungGC 失败原因

yaml

代码解读

复制代码

49597 class space used 30014K, capacity 30770K, committed 30848K, reserved 1048576K 49598 2024-05-22T11:08:43.619+0800: 157559.408: [GC (Allocation Failure) 2024-05-22T11:08:43.620+0800: 157559.409: [ParNew2024-05-22T11:08:43.678+0800: 157559.467: [SoftReference, 0 refs, 0.0004327 secs]202 4-05-22T11:08:43.678+0800: 157559.467: [WeakReference, 5244 refs, 0.0004675 secs]2024-05-22T11:08:43.679+0800: 157559.468: [FinalReference, 1436 refs, 0.0006603 secs]2024-05-22T11:08:43.679+0800: 1575 59.468: [PhantomReference, 1 refs, 0 refs, 0.0030363 secs]2024-05-22T11:08:43.683+0800: 157559.471: [JNI Weak Reference, 0.0000337 secs]

Allocation Failure 说明 ygc 原因是空间不足，一般都是这个原因

8) 为什么会发生提前晋升

49599 Desired survivor size 161054720 bytes, new threshold 15 (max 15) Desired survivor 一般是 Survivor 区的一半。假设年龄 1至N 的对象大小，超过了 Desired size，那么下一次 GC 的晋升阈值就会调整为 N。举个例子，假设 age=1的对象为 300M，超过了 161M，那么下一次GC 的晋升阈值就是 1，所有超过 1 的对象都会晋升到老年代，无需等到年龄到 15。

注意：调整的是 下一次 GC 的阈值，而非本次。

python

代码解读

复制代码

49600 - age 1: 154907320 bytes, 154907320 total 49601 - age 2: 3302040 bytes, 158209360 total  49602 - age 3: 2765624 bytes, 160974984 total

以上是每一代对象的大小，其中 total 部分是 1-N 代的总和。

为了能更好地适应不同程序的内存状况，虚拟机并不是永远地要求对象的年龄必须达到了MaxTenuringThreshold才能晋升老年代，如果在Survivor空间中相同年龄所有对象大小的总和大于Survivor空间的一半，年龄大于或等于该年龄的对象就可以直接进入老年代，无须等到MaxTenuringThreshold中要求的年龄

《深入理解Java虚拟机》一书中提到，对象晋升年龄的阈值是动态判定的。

JVM按年龄给对象分组，取total（累加值，小于等与当前年龄的对象总大小）最大的年龄分组，如果该分组的total大于survivor的一半，就将晋升年龄阈值更新为该分组的年龄

注意：不是是超过survivor一半就晋升，超过survivor一半只会重新设置晋升阈值（threshold），在下一次GC才会使用该新阈值

9) 并行GC 及耗时

49603 : 5864962K->245458K(5976896K), 0.0632069 secs] 7851473K->2231969K(10171200K), 0.0638268 secs] [Times: user=0.46 sys=0.01, real=0.07 secs]

[Times: user=0.46 sys=0.01, real=0.07 secs] 说明了 GC 耗时，其中 user+sys是 CPU的耗时，real是实际耗时，即应用实际感受到的暂停时间。由于新生代使用 ParNew 是多线程 GC，所以 real 是多线程并行后处理的时间。

ParallelGCThreads 可以设置 并行线程数，8 核及以下默认是 cpu 核数，8 核以上：3 +（（5*CPU）/ 8）。

所以越是强劲的硬件性能，GC 暂停时间越短！

10) 新生代 younggc耗时高的原因

ini

代码解读

复制代码

49604 Heap after GC invocations=1808 (full 5): 49605 par new generation total 5976896K, used 245458K [0x0000000540800000, 0x00000006c0800000, 0x00000006c0800000)

par new generation total 5976896K, used 245458K 此刻代表新生代 GC 后大小，GC 后，由于 Eden 区一般为 0，已使用部分一般是 From 区大小。

erlang

代码解读

复制代码

49606 eden space 5662336K, 0% used [0x0000000540800000, 0x0000000540800000, 0x000000069a1a0000) 49607 from space 314560K, 78% used [0x000000069a1a0000, 0x00000006a91548b0, 0x00000006ad4d0000) 49608 to space 314560K, 0% used [0x00000006ad4d0000, 0x00000006ad4d0000, 0x00000006c0800000)

from space 314560K, 78% used：注意这代表本次 GC 幸存下对象的大小，这个值越大，代表本次 GC，Survivor From 和 To 拷贝的对象越大！GC 耗时也就越长！据我的经验~ 要想younggc耗时在 50ms 以下，Survivor 幸存下对象最好少于 200M。

注意：拷贝内存对象有耗时，拷贝越多耗时越长，所以Survivor幸存对象大小影响了younggc的耗时。

11) 老年代增长较快的原因！

css

代码解读

复制代码

49609 concurrent mark-sweep generation total 4194304K, used 1986511K [0x00000006c0800000, 0x00000007c0800000, 0x00000007c0800000)

concurrent mark-sweep generation total 这是老年代 GC 后的内存使用情况。使用这个值减去 GC 前的 使用率，就是本次 younggc，老年代的增长情况

这个值要结合 new threshold N 即晋升阈值一起看，如果经常发生提前晋升，老年代增长速度一定会很快，就会导致更频繁的FullGC。

其根本原因大概率是：Survivor 空间不足，可以适当降低 SurvivorRadio，或者增加整个新生代大小，从而增加 Survivor 区大小，减少提前晋升现象的发现。

老年代增长较快的后果是：Full gc会更加频繁~ 系统耗时增加明显。

注意：提前晋升到老年代的对象越多，younggc 耗时越长，这是因为Cpu 大量拷贝对象时也是非常耗时的。我遇到的例子，有一次 提前晋升了 230M，gc 耗时增加到了 200ms+，而平常只有 90ms，这多出来的时间就是因为需要拷贝的对象变多了，并且相比新生代From拷贝到TO，跨代拷贝耗时更长。

12) 应用暂停时间，cpu核数越多，younggc越快

kotlin

代码解读

复制代码

49610 Metaspace used 333223K, capacity 338440K, committed 338560K, reserved 1357824K 49611 class space used 30014K, capacity 30770K, committed 30848K, reserved 1048576K 49612 } 49613 2024-05-22T11:08:43.684+0800: 157559.472: Total time for which application threads were stopped: 0.0663871 seconds, Stopping threads took: 0.0002652 seconds

Total time for which application threads were stopped: 0.0663871 seconds 这代表 应用暂停时间，和上面的 real 时间基本 一致。

注意：ParNew GC 是并行GC，cpu核数越多，younggc越快。

如何配置才能让 以上内容打在GC 日志中？

以上 GC 日志并不是默认就有的，需要额外配置，才会打印。

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintCommandLineFlags -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintReferenceGC

总结

1. 如果经常性的发生提前晋升情况，需要调整新生代大小和Survivor 区大小。
2. 调整 SurvivorRadio 比例
3. 调整整个新生代比例，例如 -xmn=2g调整到 -xmn=6g，gc情况会大大改善
4. 提前晋升会增加 younggc 耗时，因为跨代拷贝是很耗时的。
5. 注意 Survivor 区幸存对象大小是否过大，这也是影响 younggc 耗时的因素。