My application is a sprint boot application that uses log4j2 and runs in a Wildfly server. After the zero day attak, we upgraded to the latest log4j2 version(2.16). But after the log4j upgrade, my application stops working once in a while. And when I looked at the threaddumps, I found that there is a deadlock created by log4j. Here is my log4j configuration. It was working fine before the upgrade.

<?xml version="1.0" encoding="UTF-8" ?>
<Configuration>

    <Properties>
        <Property name="LOGDIR">${sys:jboss.server.log.dir}/application</Property>
        <Property name="FILE_LOG_PATTERN">%d %-5p [%-8.8t] %-25.25c{1} | [%X{correlationId}] %m%n</Property>
    </Properties>

    <Appenders>

        <Console name="SYSOUT" target="SYSTEM_OUT" follow="true">
            <PatternLayout pattern="${FILE_LOG_PATTERN}"/>
        </Console>

        <RollingFile name="CSL" fileName="${LOGDIR}/csl.log"
                     filePattern="${LOGDIR}/csl.%d{yyyy-MM-dd}.log.gz" ignoreExceptions="false">
            <PatternLayout pattern="${FILE_LOG_PATTERN}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
            <DefaultRolloverStrategy>
                <Delete basePath="${LOGDIR}" maxDepth="1">
                    <IfAny>
                        <IfFileName glob="csl*.log.gz" />
                        <IfFileName glob="access_log*.log" />
                    </IfAny>
                    <IfLastModified age="7d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <RollingFile name="OTR" fileName="${LOGDIR}/otr.log"
                     filePattern="${LOGDIR}/otr.%d{yyyy-MM-dd}.log.gz" ignoreExceptions="true"
                     bufferedIO="true">
            <PatternLayout pattern="${FILE_LOG_PATTERN}"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
            <DefaultRolloverStrategy>
                <Delete basePath="${LOGDIR}" maxDepth="1">
                    <IfFileName glob="otr*.log.gz" />
                    <IfLastModified age="23d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

    </Appenders>

    <Loggers>
        <Logger name="org.apache.catalina.startup.DigesterFactory" level="error" />
        <Logger name="org.apache.catalina.util.LifecycleBase" level="error" />
        <Logger name="org.apache.coyote.http11.Http11NioProtocol" level="warn" />
        <logger name="org.apache.sshd.common.util.SecurityUtils" level="warn"/>
        <Logger name="org.apache.tomcat.util.net.NioSelectorPool" level="warn" />
        <Logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="error" />
        <Logger name="org.hibernate.validator.internal.util.Version" level="warn" />
        <logger name="org.springframework.boot.actuate.endpoint.jmx" level="warn"/>

        <logger name="org.springframework" level="info"/>
        <logger name="org.springframework.aop.framework" level="warn"/>
        <logger name="org.apache.jasper.servlet.JspServlet" level="trace"/>
        <logger name="com.zaxxer.hikari.pool.HikariPool" level="debug"/>
        <logger name="com.google.code.ssm.spring.SSMCache" level="warn"/>

        <logger name="com.faskan" level="info" additivity="false">
            <appender-ref ref="OTR" />
            <appender-ref ref="CSL" />
        </logger>

        <Root level="info">
            <AppenderRef ref="CSL"/>
            <AppenderRef ref="SYSOUT"/>
        </Root>
    </Loggers>

</Configuration>

When analysing this issue, I came through a possible defect in log4j code. Not sure if that can result in a deadlock.

Log4J possible bug - As per the release notes, there was a fix to Enable immediate flush on RollingFileAppender when buffered i/o is not enabled. (LOG4J2-3114). But the code just does the opposite in RollingFileAppenderBuilder.

private Appender createAppender(final String name, final Log4j1Configuration config, final Layout layout,
            final Filter filter, final boolean bufferedIo, boolean immediateFlush, final String fileName,
            final String level, final String maxSize, final String maxBackups) {
        org.apache.logging.log4j.core.Layout<?> fileLayout = null;
        if (bufferedIo) {
            immediateFlush = true;
        }
...

It should have been if(!bufferedIo) { immediateFlush = true; }. And one of my appender explicitly sets bufferedIo value to true. I know that log4j does a bufferedio by default and it is not necessary to set this flag explicitly. But unfortunately the code that I am working on is a legacy code and the configuration was working fine before the upgrade.

Threaddump "default task-128" #450 prio=5 os_prio=0 tid=0x00007f31f80cf800 nid=0x14c8 waiting for monitor entry [0x00007f31a7d88000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.logging.log4j.core.appender.OutputStreamManager.writeBytes(OutputStreamManager.java:352) - waiting to lock <0x00000000c0e70eb0> (a org.apache.logging.log4j.core.appender.OutputStreamManager) at org.apache.logging.log4j.core.layout.TextEncoderHelper.writeEncodedText(TextEncoderHelper.java:96) at org.apache.logging.log4j.core.layout.TextEncoderHelper.encodeText(TextEncoderHelper.java:65) at org.apache.logging.log4j.core.layout.StringBuilderEncoder.encode(StringBuilderEncoder.java:68) at org.apache.logging.log4j.core.layout.StringBuilderEncoder.encode(StringBuilderEncoder.java:32) at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:228) at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:60) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190) at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181) at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161) at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134) at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125) at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89) at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:542) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:500) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:483) at org.apache.logging.log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:533) at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:483) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:388) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63) at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:153) at org.apache.logging.slf4j.Log4jLogger.log(Log4jLogger.java:376) at org.apache.commons.logging.impl.SLF4JLocationAwareLog.error(SLF4JLocationAwareLog.java:203) at org.springframework.boot.web.support.ErrorPageFilter.handleCommittedResponse(ErrorPageFilter.java:225)