Search code examples
log4j2asyncappender

Latest (2.14.1) Log4J2 async appender causes Java process to hang


I have a very basic (almost textbook) Log4J2 sample, using latest (2.14.1):

log4j2.xml (taken from the official appender doc):

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">
    <Appenders>
        <File name="MyFile" fileName="logs/app.log">
            <PatternLayout>
                <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
            </PatternLayout>
        </File>
        <Async name="Async">
            <AppenderRef ref="MyFile"/>
        </Async>
    </Appenders>
    <Loggers>
        <Root level="error">
            <AppenderRef ref="Async"/>
        </Root>
    </Loggers>
</Configuration>

Program, TestLog.java:

public class TestLog {
    private static final org.apache.logging.log4j.Logger l = org.apache.logging.log4j.LogManager.getLogger(TestLog.class);

    public static void main(String[] args) {
        l.error("Boo");
    }
}

pom.xml:

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="http://maven.apache.org/POM/4.0.0"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.tuna</groupId>
    <artifactId>log4j2-not-shutting-down</artifactId>
    <version>0</version>

    <dependencies>
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.14.1</version>
        </dependency>
    </dependencies>

    <properties>
        <maven.compiler.source>1.8</maven.compiler.source>
        <maven.compiler.target>1.8</maven.compiler.target>
    </properties>
</project>

When I run this, I do get the expected ERROR log line in logs/app.log; however the Java process hangs (does not shut down after main() completes). A thread dump shows (in addition to Java's native threads) a non-daemon async-appender thread that remains WAITING (most probably the cause for the hang).

"Log4j2-AsyncAppenderEventDispatcher-1-Async" #15 prio=5 os_prio=0 cpu=0.00ms elapsed=17.04s tid=0x000001bd5bc98000 nid=0x7324 waiting on condition  [0x0000006962bff000]
   java.lang.Thread.State: WAITING (parking)
    at jdk.internal.misc.Unsafe.park(java.base@12/Native Method)
    - parking to wait for  <0x00000007110c2618> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(java.base@12/LockSupport.java:194)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@12/AbstractQueuedSynchronizer.java:2081)
    at java.util.concurrent.ArrayBlockingQueue.take(java.base@12/ArrayBlockingQueue.java:417)
    at org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.dispatchAll(AsyncAppenderEventDispatcher.java:70)
    at org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.run(AsyncAppenderEventDispatcher.java:62)
  • Removing the Async appender (and directly appending to MyFile) causes the program to shut down properly.
  • Adding a shutdownTimeout to the Async appender definition has no effect. (Anyways the only log line already gets written to the file properly, so it could not possibly be a queueing issue.)
  • Switching log4j-core to a lower version (e.g. 2.9.1) also resolves the hang.

Is this the expected behavior, or a bug? Am I missing anything?


Solution

  • Appears to be already reported and fixed.

    Anyways 2.14.1 is no longer viable (due to the infamous CVE-2021-44228 RCE vulnerability), and given the several vulnerabilities discovered afterwards it is now recommended to upgrade to 2.17.0 or above - where the originally stated LOG4J2-3102 is also fixed.