You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "Philip Hachey (Jira)" <ji...@apache.org> on 2021/06/04 03:02:00 UTC
[jira] [Created] (LOG4J2-3102) Asynchronous Logger WAITS
indefinitely after end of main method
Philip Hachey created LOG4J2-3102:
-------------------------------------
Summary: Asynchronous Logger WAITS indefinitely after end of main method
Key: LOG4J2-3102
URL: https://issues.apache.org/jira/browse/LOG4J2-3102
Project: Log4j 2
Issue Type: Bug
Components: Appenders
Affects Versions: 2.14.1
Reporter: Philip Hachey
When running a Java 8 console application on Linux while a Log4j2 asynchronous logger is configured, the "Log4j2-AsyncAppenderEventDispatcher-1-AsynAppenders" thread remains in a "WAITING (parking)" state even after the end of the application's "main" method is reached. This prevents the JVM from exiting and the console application from terminating.
*This is a NEW issue as of 2.14.1. Log4j 2.14.0 does not have this problem.*
Here is jstack output:
{code:java}
2021-06-03 22:48:25
Full thread dump OpenJDK 64-Bit Server VM (25.292-b10 mixed mode):"Attach Listener" #16 daemon prio=9 os_prio=0 tid=0x00007fa228001000 nid=0x2bf6b6 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"DestroyJavaVM" #15 prio=5 os_prio=0 tid=0x00007fa29000b000 nid=0x2bf67f waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"Log4j2-AsyncAppenderEventDispatcher-1-AsynAppenders" #13 prio=5 os_prio=0 tid=0x00007fa29089e800 nid=0x2bf695 waiting on condition [0x00007fa2714e8000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x000000064981b2c0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403)
at org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.dispatchAll(AsyncAppenderEventDispatcher.java:70)
at org.apache.logging.log4j.core.appender.AsyncAppenderEventDispatcher.run(AsyncAppenderEventDispatcher.java:62)"Service Thread" #9 daemon prio=9 os_prio=0 tid=0x00007fa290268800 nid=0x2bf692 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007fa290255800 nid=0x2bf691 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007fa290253000 nid=0x2bf690 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007fa290251800 nid=0x2bf68f waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007fa29024e800 nid=0x2bf68e waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007fa290249000 nid=0x2bf68d runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007fa29021a800 nid=0x2bf68c in Object.wait() [0x00007fa2722e1000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000064982b578> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
- locked <0x000000064982b578> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007fa290216000 nid=0x2bf68b in Object.wait() [0x00007fa2723e2000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000649815328> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x0000000649815328> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)"VM Thread" os_prio=0 tid=0x00007fa29020c800 nid=0x2bf68a runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fa29001f800 nid=0x2bf680 runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fa290021800 nid=0x2bf681 runnable "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007fa290023800 nid=0x2bf682 runnable "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007fa290025000 nid=0x2bf683 runnable "GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007fa290027000 nid=0x2bf684 runnable "GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007fa290028800 nid=0x2bf685 runnable "GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007fa29002a800 nid=0x2bf686 runnable "GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007fa29002c000 nid=0x2bf687 runnable "GC task thread#8 (ParallelGC)" os_prio=0 tid=0x00007fa29002e000 nid=0x2bf688 runnable "GC task thread#9 (ParallelGC)" os_prio=0 tid=0x00007fa29002f800 nid=0x2bf689 runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007fa29026b000 nid=0x2bf693 waiting on condition JNI global references: 1652
{code}
Here is the log4j2.xml configuration file being used:
{code:java}
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE Configuration>
<Configuration status="WARN">
<Properties>
<Property name="rootLogger.level">trace</Property>
<Property name="rollingFile.fileName">${sys:mediafeed.logbase}.log</Property>
<Property name="rollingFile.filePattern">${sys:mediafeed.logbase}.%date{yyyy-MM-dd}.log</Property>
<Property name="logExcludedArticles.enabled">false</Property>
<Property name="logExcludedArticles.directory">filtered</Property>
</Properties>
<Appenders>
<ScriptAppenderSelector name="LogExcludedArticlesIfEnabled">
<Script language="JavaScript"><![CDATA[${sys:logExcludedArticles.enabled} ? "LogExcludedArticles" : "DoNotLogExcludedArticles";]]></Script>
<AppenderSet>
<RollingFile name="LogExcludedArticles" fileName="${sys:logExcludedArticles.directory}/excludedarticles.csv" filePattern="${sys:logExcludedArticles.directory}/excludedarticles-%d{yyyy-MM-dd}.csv.gz">
<TimeBasedTriggeringPolicy />
<CsvParameterLayout />
</RollingFile>
<Null name="DoNotLogExcludedArticles" />
</AppenderSet>
</ScriptAppenderSelector>
<RollingFile name="RollingLogFile" fileName="${rollingFile.fileName}" filePattern="${rollingFile.filePattern}">
<PatternLayout pattern="%date [%9replace{%threadName}{ForkJoinPool.commonPool-worker}{FJP.cw}] %-5level %30.30logger{-6} %message%n%throwable" />
<SizeBasedTriggeringPolicy size="20 MB" />
<DefaultRolloverStrategy max="6" />
</RollingFile>
<Async name="AsynAppenders">
<AppenderRef ref="RollingLogFile" />
</Async>
</Appenders>
<Loggers>
<Logger name="ExcludedArticlesLogger" level="trace" additivity="false">
<AppenderRef ref="LogExcludedArticlesIfEnabled" level="trace" />
<AppenderRef ref="AsynAppenders" level="${sys:rootLogger.level}" />
</Logger>
<Root level="${sys:rootLogger.level}">
<AppenderRef ref="AsynAppenders" />
</Root>
</Loggers>
</Configuration>
{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)