Log4J日志打印引发的OOM问题排查
上周，充当回消防队员去救火，一个老的CRM系统，生产上一天出现了CPU占用高，两次OOM问题。从时间上看，CPU占用高的报警也是因为JVM为了自救的疯狂GC导致的。
查看Dump文件
OOM提供了堆Dump以及线程栈Dump。由于是内网，无法截图，也不方便拍照。在此就引用一篇来自老东家的，极度相似的博客：https://rdc.hundsun.com/portal/article/884.html
栈Dump
从栈Dump线程中，可以看到大部分线程都在com.lmax.disruptor.RingBuffer#next()的UNSAFE.park()方法中。其堆栈的入口全是log4j的append方法中。
堆Dump
用mat打开was的Dump phd文件（工具不一定，但是was的我还是第一次遇到这个格式）
堆Dump中可以看到4G的内存，3.8G均为RingBuffer占用，毫无疑问，这个类所占肯定过多，而且还没法回收。
排查问题
JVM 内存溢出无非两种大情况，内存泄露，或者内存不足。情况一不管分配多大内存都不会足够，情况二，需要考虑加大内存，或者减少、限制内存的使用。
对于log4j这种成熟的组件，我一般不会怀疑其是内存泄露。当然，我还是找到那个工程使用的版本，下载源码进行查看：
<!-- https://mvnrepository.com/artifact/com.lmax/disruptor --> <dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>3.3.6</version> </dependency> <!-- https://mvnrepository.com/artifact/org.apache.logging.log4j/log4j-core --> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.3</version> </dependency>
其版本为上述版本。对于RingBuffer，其使用的处理不加赘述，直接上代码证明其没有内存泄露，以及会释放内存的代码：
// org.apache.logging.log4j.core.async.RingBufferLogEventHandler#onEvent @Override public void onEvent(final RingBufferLogEvent event, final long sequence, final boolean endOfBatch) throws Exception { event.execute(endOfBatch); event.clear(); // notify the BatchEventProcessor that the sequence has progressed. // Without this callback the sequence would not be progressed // until the batch has completely finished. if (++counter > NOTIFY_PROGRESS_THRESHOLD) { sequenceCallback.set(sequence); counter = 0; } }
// org.apache.logging.log4j.core.async.RingBufferLogEvent#clear /** * Release references held by ring buffer to allow objects to be garbage-collected. */ public void clear() { setValues(null, // asyncLogger null, // loggerName null, // marker null, // fqcn null, // level null, // data null, // t null, // map null, // contextStack null, // threadName null, // location 0 // currentTimeMillis ); }
其通过clear方法，对所有属性都设置为null，引用释放，可以交给JVM进行内存释放的。
所以，应该和篇头博客遇到的问题一样，就是buffer声明的过大：
private static final int RINGBUFFER_DEFAULT_SIZE = 256 * 1024; private static int calculateRingBufferSize() { int ringBufferSize = RINGBUFFER_DEFAULT_SIZE; final String userPreferredRBSize = PropertiesUtil.getProperties().getStringProperty( "AsyncLoggerConfig.RingBufferSize", String.valueOf(ringBufferSize)); }
默认256k的条数缓存，在每条日志都很大的时候，肯定会撑爆内存。当然，我没因为监控没有历史记录，我们并不知道发生OOM时，是并发太高导致日质量堆积，还是IO（磁盘、网络）导致的写文件或者发送kafka太慢导致的堆积。
至于怎么找到这些源码的位置，暂时没时间写。
解决方案
设置AsyncLoggerConfig.RingBufferSize值为4096或者其他稍小的值，宁愿丢日志，也不愿意节点挂掉，自己选择取舍吧。
