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)
Async
appender (and directly appending to MyFile
) causes the program to shut down properly.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.)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?
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.