天网风控灵玑系统是基于内存计算实现的高吞吐低延迟在线计算服务,提供滑动或滚动窗口内的 count、distinctCout、max、min、avg、sum、std 及区间分布类的在线统计计算服务。客户端和服务端底层通过 netty 直接进行 tcp 通信,且服务端也是基于 netty 将数据备份到对应的 slave 集群。
灵玑第 1 个版本经过大量优化,系统能提供较大的吞吐量。如果对客户端设置 10ms 超时,服务端 1wqps/core 的流量下,可用率只能保证在 98.9% 左右,高并发情况下主要是 gc 导致可用率降低。如果基于 cms 垃圾回收器。当一台 8c16g 的机器在经过第二个版本优化后吞吐量超过 20wqps 的时候,那么大概每 4 秒会产生一次 gc。如果按照一次 gc 等于 30ms。那么至少分钟颗粒度在 gc 时间的占比至少在 (15*30/1000/60)=0.0075。也就意味着分钟级别的 tp992 至少在 30ms。不满足相关业务的需求。
为了解决上述延迟过高的相关问题,JDK 11 开始推出了一种低延迟垃圾回收器 ZGC。ZGC 使用了一些新技术和优化算法,可以将 GC 暂停时间控制在 10 毫秒以内,而在 JDK 17 的加持下,ZGC 的暂停时间甚至可以控制在亚毫秒级别。实测在平均停顿时间在 10us 左右,主要是基于一个染色指针和读屏障做到大多数 gc 阶段可以做到并发的,有兴趣的同学可以了解下,并且 jdk17 是一个 lts 版本。
采用 jdk17+zgc 经过相关的压测后,一切都在向着好的方向发展,但是在一种特殊场景压测,需要将数据从北京数据中心同步给宿迁数据中心的时候,发现了一些诡异的事情
服务端容器的内存疯涨,并且停止压测后,内存只是非常缓慢的减少。
相关机器 cpu 一直保存在 20%(已经无流量请求)
一直在次数不多的 gc。大概每 10s 一次
第一反应是遇到内存疯涨和无法释放该问题时,首先归纳为内存泄漏问题,感觉这题也简单明了。开始相关内存泄漏检查:先 dump 堆内存分析发现占用堆内存的是 netty 相关的对象,恰好前段时间也有个同学也分享了 netty 下的不合理使用 netty byteBuf 导致的内存泄漏,进一步增加了对 netty 内存泄露的怀疑。 于是开启 netty 内存泄漏严格检查模式(加上 jvm 参数 Dio.netty.leakDetection.level=PARANOID),重新试跑并没有发现相关内存泄漏日志。好吧~!初步判定不是 netty 内存泄漏。
会不会是 netty 与 jdk17 兼容不好导致的 bug? 回滚 jdk8 测试发现的确不存在这个问题,当时使用的是 jdk17.0.7 版本。正好官方发布了 jdk17.0.8 版本,并且看到版本介绍上有若干的 Bug Fixes。所以又升级了 jdk 一个小版本,然而发现问题仍然在。会不会是 netty 的版本过低?正好看见 gitup 上也有类似的 issue# https://github.com/netty/netty/issues/6125WriteBufferWaterMark's 并且在高版本疑似修复了该问题,修改了 netty 几个版本重新压测,然而发现问题仍然在。
经过上述两次排查,发现问题比想象中复杂,应该深入分析下为什么,重新梳理了下相关线索:
发现回滚至 jdk8 的时候,对应宿迁中心的集群接受到的备份数据量比北京中心发送的数据量低了很多
为什么没有流量了还一直有 gc,cpu 高应该是 gc 造成的(当时认为是 zgc 的内存的一些特性)
内存分析:为什么 netty 的 MpscUnboundedArrayQueue 引用了大量的 AbstractChannelHandlerContext$WriteTask 对象,。MpscUnboundedArrayQueue 是生产消费 writeAndFlush 任务队列,WriteTask 是相关的 writeAndFlush 的任务对象,正是因为大量的 WriteTask 对象及其引用导致了内存占用过高。
只有跨数据中心出现该问题,同数据中心数据压测不会出现该问题。
分析过后已经有了基本的猜想,因为跨数据中心下机房延迟更大,单 channel 信道下已经没法满足同步数据能力,导致 netty 的 eventLoop 的消费能不足导致积压。
解决方案:增加与备份数据节点的 channel 信道连接,采用 connectionPool,每次批量同步数据的时候随机选择一个存活的 channel 进行数据通信。经过相关改造后发现问题得到了解决。
虽然经过上述的改造,表面上看似解决了问题,但是问题的根本原因还是没有被发现
1.如果是 eventLoop 消费能力不足,为什么停止压测后,相关内存只是缓慢减少,按理说应该是疯狂的内存减少。
2.为什么一直 cpu 在 23% 左右,按照平时的压测数据,同步数据是一个流转批的操作,最多也就消耗 5%cpu 左右,多出来的 cpu 应该是 gc 造成的,但是数据同步应该并不多,不应该造成这么多的 gc 压力。
3.为什么 jdk8 下不会存在该问题
推测应该是有个 netty eventLoop 消费耗时阻塞的操作导致消费能力大幅度下降。所以感觉还是 netty 的问题,于是开了 netty 的相关 debug 日志。发现了一行关键日志
[2023-08-23 11:16:16.163] DEBUG [] - io.netty.util.internal.PlatformDependent0 - direct buffer constructor: unavailable: Reflective setAccessible(true) disabled
顺着这条日志找到了本次的问题根因,为什么一个直接内存的构造器不能使用会导致我们系统 WriteTask 消费阻塞, 带着这个目的去查看相关的源码。
protected PoolChunk<ByteBuffer> newChunk() {
// 关键代码
ByteBuffer memory = allocateDirect(chunkSize);
}
}
PlatformDependent.useDirectBufferNoCleaner() ?
PlatformDependent.allocateDirectNoCleaner(capacity) : ByteBuffer.allocateDirect(capacity);
三) USE_DIRECT_BUFFER_NO_CLEANER 参数逻辑配置在 PlatformDependent 类的 static{}里面。
关键逻辑:maxDirectMemory==0 和! hasUnsafe() 在 jdk17 下没有特殊配置都是不满足条件的,关键是 PlatformDependent0.hasDirectBufferNoCleanerConstructor 的判断逻辑
if (maxDirectMemory == 0 || !hasUnsafe() || !PlatformDependent0.hasDirectBufferNoCleanerConstructor()) {
USE_DIRECT_BUFFER_NO_CLEANER = false;
} else {
USE_DIRECT_BUFFER_NO_CLEANER = true;
1.开启条件一:jdk9 及其以上必须要开启 jvm 参数 -io.netty.tryReflectionSetAccessible 参数
2.开启条件二:能反射获取到一个 private DirectByteBuffer 构造器,该构造器是通过内存地址和大小来构造 DirectByteBuffer.(备注:如果在 jdk9 以上对 java.nio 有模块权限限制,需要加上 jvm 启动参数--add-opens=java.base/java.nio=ALL-UNNAMED ,否则会报 Unable to make private java.nio.DirectByteBuffer(long,int) accessible: module java.base does not "opens java.nio" to unnamed module)
所以这里我们默认是没有开启这两个 jvm 参数的,那么 DIRECT_BUFFER_CONSTRUCTOR 为空值,对应第二部 PlatformDependent.useDirectBufferNoCleaner() 为 false。
// 伪代码,实际与这不一致
ByteBuffer direct = ByteBuffer.allocateDirect(1);
if(SystemPropertyUtil.getBoolean("io.netty.tryReflectionSetAccessible",
javaVersion() < 9 || RUNNING_IN_NATIVE_IMAGE)) {
DIRECT_BUFFER_CONSTRUCTOR =
direct.getClass().getDeclaredConstructor(long.class, int.class)
}
所以最根本原因:如果这个时候我们的 netty 的消费者 EventLoop 处理消费因为申请直接内存在达到最大内存的场景,那么就会导致有大量的任务消费都会同步去等待申请直接内存上。并且如果没有足够的的直接内存,那么就会成为大面积的消费阻塞。
static void reserveMemory(long size, long cap) {
if (!MEMORY_LIMIT_SET && VM.initLevel() >= 1) {
MAX_MEMORY = VM.maxDirectMemory();
MEMORY_LIMIT_SET = true;
}
// optimist!
if (tryReserveMemory(size, cap)) {
return;
}
final JavaLangRefAccess jlra = SharedSecrets.getJavaLangRefAccess();
boolean interrupted = false;
try {
do {
try {
refprocActive = jlra.waitForReferenceProcessing();
} catch (InterruptedException e) {
// Defer interrupts and keep trying.
interrupted = true;
refprocActive = true;
}
if (tryReserveMemory(size, cap)) {
return;
}
} while (refprocActive);
// trigger VM's Reference processing
System.gc();
int sleeps = 0;
while (true) {
if (tryReserveMemory(size, cap)) {
return;
}
if (sleeps >= MAX_SLEEPS) {
break;
}
try {
if (!jlra.waitForReferenceProcessing()) {
Thread.sleep(sleepTime);
sleepTime <<= 1;
sleeps++;
}
} catch (InterruptedException e) {
interrupted = true;
}
}
// no luck
throw new OutOfMemoryError
("Cannot reserve "
+ size + " bytes of direct buffer memory (allocated: "
+ RESERVED_MEMORY.get() + ", limit: " + MAX_MEMORY +")");
} finally {
if (interrupted) {
// don't swallow interrupts
Thread.currentThread().interrupt();
}
}
}
步骤一:申请内存前:通过全局内存计数器DIRECT_MEMORY_COUNTER,在每次申请内存的时候调用 incrementMemoryCounter 增加相关的 size,如果达到相关 DIRECT_MEMORY_LIMIT(默认是-XX:MaxDirectMemorySize) 参数则直接抛出异常,而不会去同步 gc 等待导致大量耗时。。
步骤二:分配内存 allocateDirectNoCleaner:是通过 unsafe 去申请内存,再用构造器DIRECT_BUFFER_CONSTRUCTOR通过内存地址和大小来构造 DirectBuffer。释放也可以通过 unsafe.freeMemory 根据内存地址来释放相关内存,而不是通过 java 自带的 cleaner 来释放内存。
public static ByteBuffer allocateDirectNoCleaner(int capacity) {
assert USE_DIRECT_BUFFER_NO_CLEANER;
incrementMemoryCounter(capacity);
try {
return PlatformDependent0.allocateDirectNoCleaner(capacity);
} catch (Throwable e) {
decrementMemoryCounter(capacity);
throwException(e);
return null; }
}
private static void incrementMemoryCounter(int capacity) {
if (DIRECT_MEMORY_COUNTER != null) {
long newUsedMemory = DIRECT_MEMORY_COUNTER.addAndGet(capacity);
if (newUsedMemory > DIRECT_MEMORY_LIMIT) {
DIRECT_MEMORY_COUNTER.addAndGet(-capacity);
throw new OutOfDirectMemoryError("failed to allocate " + capacity
+ " byte(s) of direct memory (used: " + (newUsedMemory - capacity)
+ ", max: " + DIRECT_MEMORY_LIMIT + ')');
}
}
}
static ByteBuffer allocateDirectNoCleaner(int capacity) {
return newDirectBuffer(UNSAFE.allocateMemory(Math.max(1, capacity)), capacity);
}
1.流程图:
2.直接原因:
3.根本原因:
4.反思与定位问题慢的原因:
默认同步数据这里不会是系统瓶颈,没有加上 lowWaterMark 和 highWaterMark 水位线的判断(socketChannel.isWritable()),如果同步数据达到系统瓶颈应该提前能感知到抛出异常。
同步数据的时候调用 writeAndFlush 应该加上相关的异常监听器(以下代码 2),若果能提前感知到异常 OutOfMemoryError 那么更方便排查到相关问题。
(1)ChannelFuture writeAndFlush(Object msg)
(2)ChannelFuture writeAndFlush(Object msg, ChannelPromise promise);
jdk17 下监控系统看到的非堆内存监控并未与系统实际使用的直接内存统计一致,导致开始定位问题无法定位到直接内存已经达到最大值,从而并未往这个方案思考。
相关引用的中间件底层通信也是依赖于 netty 通信,如果有类似的数据同步也可能会触发类似的问题。特别 ump 在高版本和 titan 使用 netty 的时候是进行了 shade 打包的,并且相关的 jvm 参数也被修改,虽然不会触发该 bug,但是也可能导致触发系统 gc。
ump高版本:jvm参数修改(低版本直接采用了底层socket通信,未使用netty和创建ByteBuffer) io.netty.tryReflectionSetAccessible->ump.profiler.shade.io.netty.tryReflectionSetAccessible
titan:jvm参数修改:io.netty.tryReflectionSetAccessible->titan.profiler.shade.io.netty.tryReflectionSetAccessible
作者:京东零售 刘鹏
来源:京东云开发者社区 转载请注明来源