记录一次log4j2导致的内存泄漏

线上服务突然告警，jvm疯狂触发老年代gc，登录后台查看gc并不能释放老年代空间，之前这个服务一直正常运行了几个月，第一时间下载jvm的dump文件，并对服务重启，防止内存不足影响线上业务。
使用MAT分析dump文件，先按照retained Heap排序，
发现ThreadLocal 和StringBuilder这两个类占用了大量内存，ThreadLocal也是引用的StringBuilder，点开StringBuilder发现内容是一些日志文件，初步确定是log文件导致的内存泄漏，先将线上的日志输出级别提高到error（我们系统支持动态调整日志输出级别）。
搜索Log4j2在什么地方使用了StringBuilder，排查发现org.apache.logging.log4j.message.ParameterizedMessage这个类中有一个复用StringBuilder的代码，线上使用log4j-api的版本是2.8

public String getFormattedMessage() {
        if (formattedMessage == null) {
            final StringBuilder buffer = getThreadLocalStringBuilder();
            formatTo(buffer);
            formattedMessage = buffer.toString();
        }
        return formattedMessage;
    }

    private static StringBuilder getThreadLocalStringBuilder() {
        StringBuilder buffer = threadLocalStringBuilder.get();
        if (buffer == null) {
            buffer = new StringBuilder(DEFAULT_STRING_BUILDER_SIZE);
            threadLocalStringBuilder.set(buffer);
        }
        buffer.setLength(0);
        return buffer;
    }

这段代码中Log4j2引用了一个ThreadLocal中的StringBuilder，这样复用StringBuilder可以大幅提高日志输出效率，但注意这段代码buffer.setLength(0),这个操作只会将StringBuilder的写入重置为从0开始写入，但不会回收StringBuilder已经占用的内存，类似于如果StringBuilder中原有值 “哈哈哈哈哈哈”，执行setLength(0)之后再写入"123"，那StringBuilder虽然存储的值是 “123”，但在Builder的数组中存储的其实是 “123哈哈哈”,只是覆盖了前三个位置，后面的三个位置仍然占用内存，释放不了。由于当前的ThreadLocal是tomcat的线程池里的线程，ThreadLocal就基本没啥可能会被释放，导致StringBuilder也不会被回收。这个StringBuilder的内存只会增加不会减少，由此导致内存泄漏。
后来查看log4j2-api的最新版本2.13.0

public static final int MAX_REUSABLE_MESSAGE_SIZE = size("log4j.maxReusableMsgSize", (128 * 2 + 2) * 2 + 2);
public String getFormattedMessage() {
        if (formattedMessage == null) {
            final StringBuilder buffer = getThreadLocalStringBuilder();
            formatTo(buffer);
            formattedMessage = buffer.toString();
            StringBuilders.trimToMaxSize(buffer, Constants.MAX_REUSABLE_MESSAGE_SIZE);
        }
        return formattedMessage;
    }

可以看到新版本中增加一个操作trimToMaxSize，代码如下：

/**
     * Ensures that the char[] array of the specified StringBuilder does not exceed the specified number of characters.
     * This method is useful to ensure that excessively long char[] arrays are not kept in memory forever.
     *
     * @param stringBuilder the StringBuilder to check
     * @param maxSize the maximum number of characters the StringBuilder is allowed to have
     * @since 2.9
     */
    public static void trimToMaxSize(final StringBuilder stringBuilder, final int maxSize) {
        if (stringBuilder != null && stringBuilder.capacity() > maxSize) {
            stringBuilder.setLength(maxSize);
            stringBuilder.trimToSize();
        }
    }

当buffer的长度大于某一直时会触发stringBuilder的trimToSize操作，这个方法会回收StringBuilder的缓存。
因此只要更新log4j2的版本即可解决这个内存泄漏的问题。
这次事件还有个深刻教训就是谨慎输出log日志，该输出的一定要输出，不该输出的尽量不要输出，这次事件的另一个原因在于我们之前为了方便查找问题在线上开启了debug日志输出，应用稳定之后没有修改为info级别输出，以后一定要吸取教训。