出现问题
我们公司主要是做理财业务的,平时的交易量也不少。突然有一天运维通知,生产环境的机器JVM内存占用率太高了,达到了70%左右,且伴随着频繁的YGC。这可不是个好征兆,我接到运维的通知后,第一时间怀疑是发生了内存泄漏,于是申请让运维把生产环境的堆内存dump下来。
排查问题
我们的生产环境机器配置是4C8G,堆内存分配了4G,生产环境已经平稳运行一年多了,没有发生过内存飙高的情况,而且最近也没有升级系统,不是修改代码导致的问题。在查看交易量监控后,发生最近的交易增加了很多,但是这些交易量也不至于把内存打到70%。将dump文件导入MAT(Memery Analyzer)工具后,发生堆中大部分内存都被一个叫RingBuffer的对象所占用。
经过分析代码后,发现RingBuffer类是Log4jjar包引入的,于是开始了解RingBuffer类的作用。
RingBuffer是log4j2组件为了提供异步写日志的效率,引入的Disruptor组件中的类。Disruptor异步写日志的大致原理是,生成一个类似redo log的环形队列,先进先出,可以覆盖写。
RingBuffer中有很多RingBufferLogEvent对象
RingBufferLogEvent是日志被打印前封装起来的对象类型
为什么会有这么多RingBufferLogEvent对象呢?在日志打印后,这些对象不会被回收吗?
在web应用中,RingBuffer默认的大小是256 * 1024;日志打印后,这些RingBufferLogEvent就不会再被引用了,但是需要等到GC线程扫描到这些对象,且执行GC时才能被回收。所以导致堆中内存占用过高的原因是RingBuffer太大了,我们需要手动将其设置的小些。
解决问题
在logj2.component.properties配置文件中添加配置
AsyncLogger.RingBufferSize=4096
复盘
手动将RingBuffer将调小可以防止RingBuffer过大,占用堆内存。但是也可能导致RingBuffer过小,日志消费速度慢,RingBuffer放不下新的日志,导致日志丢失。但是Disruptor的性能很高,一般不会出现日志丢失的情况。经过多次压测,4096的RingBuffer可以轻松承受并发1000的交易,至此JVM内存飙高的问题就排查完了。