[LOG4J2-1012] AsyncAppender hang on shutdown if delegate Appender hangs

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.2
• Fix Version/s: 2.4.1
• Component/s: Appenders
• Assignee: Unassigned
• Reporter: Mikael Ståldal
• Created: 11/May/15 15:44
• Updated: 15/Sep/16 11:57
• Resolved: 29/Sep/15 11:41

Description

I have a custom appender which sometimes hangs forever on Appender.append(LogEvent). To make sure that this does not affect my application, I have wrapped it with a non-blocking AsyncAppender like this. (I rather lose some log events than lock-up my application).

<Configuration status="WARN">
    <Appenders>
        <Custom name="Custom">
        </Custom>
        <Async name="AsyncCustom" blocking="false">
            <AppenderRef ref="Custom"/>
        </Async>
    </Appenders>
    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="AsyncCustom"/>
        </Root>
    </Loggers>
</Configuration>

This works fine as long as the application runs, but when I shut down, it can hang forever, from jstack:

"pool-1-thread-1" prio=10 tid=0x00007f3e840cd800 nid=0x3945 in Object.wait() [0x00007f3e765de000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000007490d2b88> (a org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread)
	at java.lang.Thread.join(Thread.java:1281)
	- locked <0x00000007490d2b88> (a org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread)
	at java.lang.Thread.join(Thread.java:1355)
	at org.apache.logging.log4j.core.appender.AsyncAppender.stop(AsyncAppender.java:119)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.stop(AbstractConfiguration.java:228)
	at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:224)
	at org.apache.logging.log4j.core.LoggerContext$1.run(LoggerContext.java:185)
	at org.apache.logging.log4j.core.util.DefaultShutdownCallbackRegistry$1.run(DefaultShutdownCallbackRegistry.java:101)
	at org.apache.logging.log4j.core.util.DefaultShutdownCallbackRegistry.run(DefaultShutdownCallbackRegistry.java:75)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x00000007490e9360> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"AsyncAppender-AsyncCustom" daemon prio=10 tid=0x00007f3e84676000 nid=0x386b waiting on condition [0x00007f3e77df6000]
[...hang in CustomAppender...]
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:99)
	at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:290)
	at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:241)

   Locked ownable synchronizers:
	- None

It would be nice if AsyncAppender could fully protect you from faulty appenders and have some timeout on shutdown (at least when you specify blocking=false). Proper shutdown of the application is important for me.

(I know that I should fix my faulty custom appender, but I want an extra safety net to make my application reliable and robust.)

Issue Links

• relates to: LOG4J2-1043 Run initialization of AsyncAppender delegates asynchronously