Potential Deadlock issues while logging in a high volume multi threaded java application

[rohitnitk2004]

reload4j v1.2.24

Thread-5 is stuck and below is thread dump.

AsyncAppender-Dispatcher-Thread-0" #21 daemon prio=5 os_prio=0 tid=0x00007f13d2338000 nid=0x2454d waiting for monitor entry [0x00007f13a171a000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:192)

• waiting to lock <0x00000006c006e230> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:364) at org.apache.log4j.Category.log(Category.java:771) at org.slf4j.impl.Log4jLoggerAdapter.log(Log4jLoggerAdapter.java:581) at org.apache.commons.logging.impl.SLF4JLocationAwareLog.error(SLF4JLocationAwareLog.java:220)

"Thread-5" #170 prio=5 os_prio=0 tid=0x00007f13b85d1000 nid=0x2680f in Object.wait() [0x00007f1396c20000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at org.apache.log4j.AsyncAppender.append(AsyncAppender.java:190)

• locked <0x00000006c0026878> (a java.util.ArrayList) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:228)
• locked <0x00000006c007e980> (a org.apache.log4j.AsyncAppender) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:56) at org.apache.log4j.Category.callAppenders(Category.java:194)
• locked <0x00000006c006e230> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:364) at org.apache.log4j.Category.log(Category.java:771) at org.slf4j.impl.Log4jLoggerAdapter.log(Log4jLoggerAdapter.java:581) at org.apache.commons.logging.impl.SLF4JLocationAwareLog.info(SLF4JLocationAwareLog.java:164)

[ceki]

Can you please provide your log4j configuration? Which version of the JDK? OS?

[rohitnitk2004]

Linux 3.10.0-1160.105.1.el7.x86_64 x86_64 GNU/Linux

openjdk version "1.8.0_302"

`

public class MyLog4JAppender implements Appender, OptionHandler { private final AppenderSkeleton delegate; public MyLog4JAppender() { delegate = new ConsoleAppender(); delegate.setThreshold(Level.INFO); delegate.setLayout(new PatternLayout("%-5p %d{ISO8601} %c{1} %x - %m%n")); } `

[ceki]

@rohitnitk2004 Writing to the console is known to be very slow and can also be blocked via the key boaard (Ctrl-Q). However, I think relaod4j's AsyncAppender can be simplified and improved.

[rohitnitk2004]

@rohitnitk2004 Writing to the console is known to be very slow and can also be blocked via the key boaard (Ctrl-Q). However, I think relaod4j's AsyncAppender can be simplified and improved.

yes but in this case; we are experiencing deadlocks. looking at stacktrace; looks like buffer is full and appender is waiting on dispatcher notification which is contending for locking root logger held by appender

Thread-5 at org.apache.log4j.Category.callAppenders(Category.java:194)

• locked <0x00000006c006e230> (a org.apache.log4j.spi.RootLogger)

AsyncAppender-Dispatcher at org.apache.log4j.Category.callAppenders(Category.java:192)

• waiting to lock <0x00000006c006e230> (a org.apache.log4j.spi.RootLogger)