背景:
介绍
天网风控灵玑系统是基于内存计算实现的高吞吐低延迟在线计算服务,提供滑动或滚动窗口内的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版本。
问题:
采用jdk17+zgc经过相关的压测后,一切都在向着好的方向发展,但是在一种特殊场景压测,需要将数据从北京数据中心同步给宿迁数据中心的时候,发现了一些诡异的事情
-
服务端容器的内存疯涨,并且停止压测后,内存只是非常缓慢的减少。
-
相关机器cpu一直保存在20%(已经无流量请求)
-
一直在次数不多的gc。大概每10s一次
排查之旅
内存泄漏排查
第一反应是遇到内存疯涨和无法释放该问题时,首先归纳为内存泄漏问题,感觉这题也简单明了。开始相关内存泄漏检查:先dump堆内存分析发现占用堆内存的是netty相关的对象,恰好前段时间也有个同学也分享了netty下的不合理使用netty byteBuf导致的内存泄漏,进一步增加了对netty内存泄露的怀疑。 于是开启netty内存泄漏严格检查模式 (加上jvm 参数Dio.netty.leakDetection.level=PARANOID),重新试跑并没有发现相关内存泄漏日志。好吧~!初步判定不是netty内存泄漏。
jdk与netty版本bug排查
会不会是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消费阻塞, 带着这个目的去查看相关的源码。
源码分析
- 一) netty 默认会用PooledByteBufAllocator来分配直接内存,采用类似jmelloc的内存池机制,每次内存不足的时候会通过创建io.netty.buffer.PoolArena.DirectArena#newChunk去预占申请内存。
protected PoolChunk<ByteBuffer> newChunk() {
// 关键代码
ByteBuffer memory = allocateDirect(chunkSize);
}
}
- 二) allocateDirect()是申请直接内存的逻辑。大致就是如果能采用底层unsafe去申请、释放直接内存和反射创建ByteBuffer对象,那么就采用unsafe。否则就直接调用java的Api ByteBuffer.allocateDirect来直接分配内存并且采用自带的Cleaner来释放内存。这里 PlatformDependent.useDirectBufferNoCleaner 是个关键点,其实就是USE_DIRECT_BUFFER_NO_CLEANER参数配置
PlatformDependent.useDirectBufferNoCleaner() ?
PlatformDependent.allocateDirectNoClea