1. 背景
UserService是负责子域内最高流量服务，在进入今年的3月下旬，开始较频繁出现单节点GC导致的接口响应超时问题，大概在服务重启后的3-5天，某些节点的在内存达到8-9GB时，分钟内触发G1的多次mixed GC，每次50ms-80ms，累计 pause时间可达300-450ms之间。最早的Event事件记录在0325。这之后，user的问题排查重心放在了GC上，这里也不得不承认，可能对于之前user的Event事件处理结果存在redis的误伤。
2. 先捋一下，可能导致服务报错的原因
2.1. 内存泄漏：
现象：我们拿 4.08 发布至 04.12 的UserService服务来看，期间内存使用情况只增不减，直到最后触发G1 mixed GC，内存回归到1-4G的波动范围。
结论：从现象来看，应该不是内存泄漏的问题；
2.2. 上游不合理的超时时间
现象：过去一段时间，我们多接口被上游配置为50ms超时时间，导致任何瞬时的小抖动，都会引发了多次上游超时报错Event。
结论&解决方案：经过多次磨合，我们的最大上游服务针对UserService服务的超时时间已经在合理范围内有所提升，避免了调用少，却报错多的现象。
2.3. 接口堆砌后的冗杂
现象：UserService中部分接口，存在字段堆砌的现象，在高流量面前，小问题就会放大，增加服务不必要负载，增加成本，目前已在整治。
结论&解决方案：
- 查询用户信息接口，返回值有58个，调研下来，调用方一次并不会需要这么多，通过入参分类，对于返回值进行精简；
- 根据uids查询用户信息方法的返回值同样进行了精简；
- 根据uids查询用户配置接口由上游操作逐步下线。
降本方面：占redis使用内存的63%的user前缀系列缓存，之前用于C端用户目的地的存储，目前已摘除此缓存，直接请求hbase。
2.4. mixed GC（重点）
现象：已在文章开头介绍，不再赘述，当下，最主要、高频次的问题，就是mixed GC。
方案：详见下方GC问题排查与思考，不过在开始之前，我认为要想解决一个问题，就要先了解它，首先我们来初步了解下mixed GC。
在G1收集器中，一次完整的mixedGC会包含以下几个阶段：
初始标记（Initial Mark）
- 这是一次STW（Stop-The-World）事件，它标志着Mixed GC开始。在这个阶段，G1会标记所有从GC根直接可达的对象。此阶段通常与年轻代GC（Minor GC）同时发生以减少STW的时间。
并发标记（Concurrent Marking）
- 在初始标记后，G1收集器并发地标记堆中的活对象。这个过程并不需要停止用户应用线程，因此并发标记与应用程序的运行是重叠进行的。
最终标记（Final Mark）
- 这又是一次STW事件，从并发标记阶段中断了应用线程来完成标记操作。最终标记是为了纠正并发标记阶段发生任何变化的对象的标记记录。G1会处理剩余工作，如处理SATB（Snapshot At The Beginning）记录的引用列表，以及处理稍早期间并发运行时遗漏的对象。
筛选存活区域（Live Data Counting and Region Sorting）
- G1会计算每个区域中存活对象的数量并将这些区域排序，以便在接下来的回收阶段优先回收那些垃圾最多的区域。
筛选回收集（Evacuation Pause）
- 这是Mixed GC中主要的STW阶段，G1会回收选定区域（Evacuation Set），包括一些老年代区域和年轻代区域。在这个阶段，活动的对象被复制到空闲的区域，未被占用的区域会被释放。
- 选定的老年代区域通常基于回收价值和预期停顿时间目标进行选择。
并发清理（Concurrent Cleanup）
- 清理那些完全没有存活对象的区域，并且将它们加入到空闲区域列表，供未来使用。这个步骤部分是并发的，不需要暂停应用线程。
压缩阶段（Optional）
- 如果需要，G1可以在特定情况下进行压缩来整理剩余的空间碎片。G1的压缩阶段可以是并发的也可以包含STW阶段，取决于G1的配置和当前Java堆的状况。
3. GC问题排查与思考：
GC的排查肯定离不开gc log 和 dump分析，我们就以此为切入点，以下为2024-03-28晚上22:29分左右触发的一次mixedGC log片段截取：
3.1. 怎样会触发 mixed GC ？
当达到 IHOP 阈值，-XX:InitiatingHeapOccupancyPercent（默认45%）时，老年代使用内存占到堆总大小的 45% 的时候，G1 将开始并发标记阶段 + Mixed GC。
GC 日志可以看到初始标记时老年代大概 5448.1M，堆内存 11.7G， 5448.1 / 11700 ≈ 46.56%。
3.2. GC ref-proc耗时72ms
- 首先，什么是GC ref-proc呢？
在G1垃圾收集器中的Mixed GC过程中，引用处理（Reference Processing, 简称 ref-proc）是指对于Java中的引用类型（软引用、弱引用、虚引用和终结器（Finalizer）引用）的处理。此过程是在Cleanup阶段之前的STW（Stop-The-World）的最终标记阶段（Final Mark）中进行的。
其中，引用处理时间受到以下因素影响：
- 引用的数量：如果系统中有大量的引用对象，处理这些引用的时间会更长。
- 回收策略：如何处理各种不同类型的引用（软引用、弱引用、虚引用和终结器引用）。
- 应用程序行为：应用创建和清理引用对象的频率。
引用处理阶段的处理时间会影响到Mixed GC中Cleanup阶段的性能。尽管这两个阶段是分开的，但引用处理的结果可以决定哪些对象是“可回收的”，从而直接影响到Cleanup阶段需要处理的对象的数量。如果引用处理阶段执行效率不高，或者有大量需要处理的引用对象，这将消耗更多的时间，进而会延长整个Mixed GC的STW暂停时间。
此过程默认单线程，可添加-XX:+ParallelRefProcEnabled参数，可优化为多线程处理，我们服务已配置；
还可以添加-XX:+PrintReferenceGC，帮助展示ref-proc过程各引用处理时长详情，我们并未加。
总结：Final Mark阶段的处理结果，会直接影响到后续清理阶段需要处理的数量，进而影响到Mixed GC的性能。
- 虚引用和虚引用队列是什么？
在Java中，虚引用（PhantomReference）与虚引用队列（ReferenceQueue）通常一起使用，主要用于跟踪对象被垃圾收集器回收的时机。虚引用不会阻止其引用的对象被垃圾收集器回收，也就是说，即便某个对象仅有虚引用指向它，垃圾收集器仍然可以回收这个对象。
虚引用队列的角色在于注册虚引用。当虚引用指向的对象被垃圾收集器准备回收时，这个虚引用会被添加到与之关联的虚引用队列中。通过这种方式，应用程序可以知道垃圾收集器何时回收了一个对象。
Mysql 5正是运用了jvm中虚引用的这一特性，来完成资源回收的♻️。
Mysql 8.0.22及以上，mysql-connector-java 的维护者应该是注意到了虚引用对 GC 的影响，在新增的AbandonedConnectionCleanupThread（专门用来清理已经不再使用但尚未正确关闭的数据库连接的线程）中的trackConnection方法内部进行了逻辑优化，虚引用的添加队列支持配置，开发者可通过com.mysql.cj.disableAbandonedConnectionCleanup配置的Boolean来自定义虚引用的生成。
有了这个配置，就可以在启动参数上设置属性：
java -jar app.jar -Dcom.mysql.cj.disableAbandonedConnectionCleanup=true
或者在代码里设置属性：
System.setProperty(PropertyDefinitions.SYSP_disableAbandonedConnectionCleanup,"true");
当 com.mysql.cj.disableAbandonedConnectionCleanup=true 时，生成数据库连接时就不会生成虚引用，对 GC 就没有任何影响了。
3.2.1. 此时肯定有小伙伴会问，关闭虚引用，资源回收怎么办？
此时的资源回收是交给连接池管理应用（Druid、HikariCP ）来处理的，当配合使用得当的连接池时，将此属性设置为 true 是安全的，因为连接池将负责连接的创建、监控和回收工作。
记一次线上RPC超时故障排查及后续GC调优思路 | HeapDump性能社区
排查到此处，我找到了一篇文档，该文档记录了一次和我们类似问题的解决方案，其中提到了Mysql 5在创建连接时会同时创建一个对应的虚引用，之前，我们的数据库集群的每个库空闲连接的最大存活时间（minEvictableIdleTimeMillis）在客户端配置15分钟。
而连接的引用在经历15次young gc后(大约3分钟)就可以进入老年代，这样再想清理它，只能等待mixed GC。
我们从4.12号user的dump的记录来看，结合12号之前最近一次的发布时间4.07，6天的时间，创建了5827个虚引用对象，平均每小时有40个连接的汰换，积攒的引用资源达到280+M，确实是一个GC负担。
3.3. 为什么连续6次mixed GC？
-XX:G1MixedGCCountTarget，默认为8，这个参数标识最后的混合回收阶段会执行8次，一次只回收掉一部分的Region，然后系统继续运行，过一小段时间之后，又再次进行混合回收，重复8次。执行这种间断的混合回收，就可以把每次的混合回收时间控制在我们需要的停顿时间之内了，同时达到垃圾清理的效果。
清理了 6 次就已经满足了回收效果，所以没有继续 mixed GC。
3.4. 为什么只有User服务会报错，而同样高Qps的兄弟子域服务不会频繁报错？
看近24小时Jvm表现，User的情况甚至还要比兄弟子域的高流量服务好一些。
| MyService | BroService |
|---|---|
通过主要上游的中间件配置我们发现，原来上游对于BroService的超时时间要比对User宽容很多，这就使得BroService即便遇到mixedGC，也几乎不会遇到上游超时取消。
| 上游 | 配置 |
|---|---|
| Bro1Service | |
| Bro2Service |
4. 采取措施
首先，这个问题可以分两步走，分别在DB连接配置和代码层面进行干预：
4.1. 连接配置优化
在意识到这个问题后，我们首先将连接的配置进行修改：
将minIdle(最小连接数)：由2调整为5；
将minEvictableIdleTimeMillis(minIdle ~ maxActive之间的连接，空闲超过此时间后会被回收)：由15分钟调整为2天。
目的：此连接存活时长的优化，旨在 在固定发布周期内，可以延长每个连接的存活时长，进而减少连接的新建次数，对应连接引用的创建个数也会同样减少，在mixed GC时可以减少回收引用的个数，从而减少GC需要消耗的时间。
4.2. 手动回收虚引用
在user新增一个job方法，每隔2小时去清一下connectionPhantomRefs的内容：
/**
* @author Bober
* @date 2024/4/18 19:57
*/
@Service
public class ClearPhantomRefsJob {
@PostConstruct
public void clearPhantomRefs() {
// 每两小时清理 connectionPhantomRefs，减少对 mixed GC 的影响
ThreadPools.getInstance().getScheduledExecutor().scheduleAtFixedRate(() -> {
//开关
Integer limitSize = ApolloConfig.getIntProperty(Consts.Apollo.CLEAR_PHANTOM_REFS_PARAM, 50);
if (ObjectUtil.isEmpty(limitSize) || ObjectUtil.isNotEmpty(limitSize) && limitSize <= 0) {
return;
}
try {
Field connectionPhantomRefs = NonRegisteringDriver.class.getDeclaredField("connectionPhantomRefs");
connectionPhantomRefs.setAccessible(true);
Map map = (Map) connectionPhantomRefs.get(NonRegisteringDriver.class);
if (limitSize > 0 && map.size() > limitSize) {
LogUtils.COMMON.warn("clearConnectionPhantomRefs success more than 50 :{}", map.size());
map.clear();
}
LogUtils.COMMON.warn("clearConnectionPhantomRefs :{},limitSize:{}", map.size(), limitSize);
} catch (Exception e) {
LogUtils.ERROR.error("connectionPhantomRefs clear error!", e);
}
}, 2, 2, TimeUnit.HOURS);
}
}
这个是事情的原理其实是：清除了connectionPhantomRefs中的内容，将连接对应的引用切断，但是真正连接本身所占用的内存和资源，还是需要靠mixed GC的时候去回收。
目前已上线5天时间，已经进行过10次调度，共清除了592个引用连接，具体mixed GC后的结果，还需待数据回收。
5. 虚引用处理结果回收
5.1. 截止第16天观察日志:
5.1.1. 实验组：加了手动回收虚引用
总计进行了4次mixed GC，总pause时长大约250ms，相比之前6次、330ms，次数少了2次，时间大约少了80ms，GC ref-proc由72ms降为29ms。
5.1.2. 对照组：原实例节点
总计进行了4次mixed GC，总pause时长大约290ms，相比之前6次、330ms，次数少了2次，时间大约少了40ms，GC ref-proc由72ms降为36ms。
5.1.3. 结论：
目前来看，从节前最后一次发布20240420至20240506并未发生过抖动导致的超时报错，从上线16天来的实验组和对照组日志的差别来看，并无很大差异。
修改调大连接池配置后，对于虚引用的生成起到了降低作用，进而减轻了mixed GC压力，也就是说，修改连接池的操作在一定程度上间接提升了mixed GC的效率，这个提升已经可以使服务满足mixed GC时对于时间的要求。
综合评估原因：主要修复点在于调大了连接池最小空闲连接数、空闲链接存活时间配置。
