jdk17下netty导致堆内存疯涨原因排查
【 介绍 】
天网风控灵玑系统是基于内存计算实现的高吞吐低延迟在线计算服务,提供滑动或滚动窗口内的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。不满足相关业务的需求。
【 jdk17+ZGC 】
为了解决上述延迟过高的相关问题,JDK 11 开始推出了一种低延迟垃圾回收器 ZGC。ZGC 使用了一些新技术和优化算法,可以将 GC 暂停时间控制在 10 毫秒以内,而在 JDK 17 的加持下,ZGC 的暂停时间甚至可以控制在亚毫秒级别。实测在平均停顿时间在10us左右,主要是基于一个染色指针和读屏障做到大多数gc阶段可以做到并发的,有兴趣的同学可以了解下,并且jdk17是一个lts版本。
服务端容器的内存疯涨,并且停止压测后,内存只是非常缓慢的减少。 相关机器cpu一直保存在20%(已经无流量请求) 一直在次数不多的gc。大概每10s一次。
【 内存泄漏排查 × 】
【 jdk与netty版本bug排查 × 】
【 直接原因定位与解决 】
经过上述两次排查,发现问题比想象中复杂,应该深入分析下为什么,重新梳理了下相关线索:
发现回滚至jdk8的时候,对应宿迁中心的集群接收到的备份数据量比北京中心发送的数据量低了很多
为什么没有流量了还一直有gc,cpu高应该是gc造成的(当时认为是zgc的内存的一些特性)
内存分析:为什么netty的MpscUnboundedArrayQueue引用了大量的AbstractChannelHandlerContext$WriteTask对象,。MpscUnboundedArrayQueue是生产消费writeAndFlush任务队列,WriteTask是相关的writeAndFlush的任务对象,正是因为大量的WriteTask对象及其引用导致了内存占用过高。
只有跨数据中心出现该问题,同数据中心数据压测不会出现该问题。
分析过后已经有了基本的猜想,因为跨数据中心下机房延迟更大,单channel信道下已经没法满足同步数据能力,导致netty的eventLoop的消费能不足导致积压。
解决方案:增加与备份数据节点的channel信道连接,采用connectionPool,每次批量同步数据的时候随机选择一个存活的channel进行数据通信。经过相关改造后发现问题得到了解决。
【 根因定位 】
虽然经过上述的改造,表面上看似解决了问题,但是问题的根本原因还是没有被发现
如果是eventLoop消费能力不足,为什么停止压测后,相关内存只是缓慢减少,按理说应该是疯狂的内存减少。 为什么一直cpu在23%左右,按照平时的压测数据,同步数据是一个流转批的操作,最多也就消耗5%cpu 左右,多出来的cpu应该是gc造成的,但是数据同步应该并不多,不应该造成这么多的gc压力。 为什么jdk8下不会存在该问题
[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);}}
2. allocateDirect()是申请直接内存的逻辑。大致就是如果能采用底层unsafe去申请、释放直接内存和反射创建ByteBuffer对象,那么就采用unsafe。否则就直接调用java的Api ByteBuffer.allocateDirect来直接分配内存并且采用自带的Cleaner来释放内存。这里 PlatformDependent.useDirectBufferNoCleaner 是个关键点,其实就是USE_DIRECT_BUFFER_NO_CLEANER参数配置。
PlatformDependent.useDirectBufferNoCleaner() ?PlatformDependent.allocateDirectNoCleaner(capacity) :ByteBuffer.allocateDirect(capacity);
if (maxDirectMemory == 0 || !hasUnsafe() || !PlatformDependent0.hasDirectBufferNoCleanerConstructor()) {USE_DIRECT_BUFFER_NO_CLEANER = false;} else {USE_DIRECT_BUFFER_NO_CLEANER = true;
// 伪代码,实际与这不一致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)}
5. 现在回到第2步骤,发现PlatformDependent.useDirectBufferNoCleaner()在jdk高版本下默认值是false。那么每次申请直接内存都是通过ByteBuffer.allocateDirect来创建。那么到这个时候就已经定位到相关根因了,通过ByteBuffer.allocateDirect来申请直接内存,如果内存不足的时候会强制系统System.Gc(),并且会同步等待DirectByteBuffer通过Cleaner的虚引用回收内存。下面是ByteBuffer.allocateDirect预占内存(reserveMemory)的关键代码。大概逻辑是 触达申请的最大的直接内存->判断是否有相关的对象在gc回收->没有在回收则主动触发System.gc()来触发回收->在同步循环最多等待MAX_SLEEPS次数看是否有足够的直接内存。整个同步等待逻辑在亲测在jdk17版本最多能1秒以上。
所以最根本原因:如果这个时候我们的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 processingSystem.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 luckthrow new OutOfMemoryError("Cannot reserve "+ size + " bytes of direct buffer memory (allocated: "+ RESERVED_MEMORY.get() + ", limit: " + MAX_MEMORY +")");} finally {if (interrupted) {// don't swallow interruptsThread.currentThread().interrupt();}}}
6. 虽然我们看到了阻塞的原因,但是为什么jdk8下为什么就不会阻塞从4步骤中看到java 9以下是设置了DIRECT_BUFFER_CONSTRUCTOR的,因此采用的是PlatformDependent.allocateDirectNoCleaner进行内存分配。以下是具体的介绍和关键代码:
步骤一:申请内存前:通过全局内存计数器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);}
【 反思与定位问题慢的原因 】
默认同步数据这里不会是系统瓶颈,没有加上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.tryReflectionSetAccessibletitan:jvm参数修改:io.netty.tryReflectionSetAccessible->titan.profiler.shade.io.netty.tryReflectionSetAccessibl