Samraj created LOG4J2-2950:
------------------------------
Summary: LOG INFO statement blocking in java program
Key: LOG4J2-2950
URL: https://issues.apache.org/jira/browse/LOG4J2-2950
Project: Log4j 2
Issue Type: Bug
Affects Versions: 2.13.3
Reporter: Samraj
Hi All,
We are facing this issue when we enable INFO logs in the program. Our main
method will trigger a subproccess and communicate via JMX. Whenever we enable
the INFO log, some times after we will see there is a problem with process gets
blocked due to info statement. I have attached the Thread trace log for
reference.
Log 1:
"JMX client heartbeat 3" #41 daemon prio=5 os_prio=0 tid=0x0000000019949000
nid=0x12e0 waiting for monitor entry [0x000000002e33f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.logging.log4j.core.appender.rolling.RollingFileManager.checkRollover(RollingFileManager.java:272)
- waiting to lock <0x00000000800c3b98> (a
org.apache.logging.log4j.core.appender.rolling.RollingFileManager)
at
org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:311)
at
org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at
org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543)
at
org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460)
at
org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
at
org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1994)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1852)
at org.apache.logging.log4j.jcl.Log4jLog.info(Log4jLog.java:91)
at
xxxxxxxxxxxxxxxxxxMBeanManager$NotificationHandler.handleNotification(XXXXMBeanManager.java:634)
at
javax.management.NotificationBroadcasterSupport.handleNotification(NotificationBroadcasterSupport.java:275)
at
javax.management.NotificationBroadcasterSupport$SendNotifJob.run(NotificationBroadcasterSupport.java:352)
at
javax.management.NotificationBroadcasterSupport$1.execute(NotificationBroadcasterSupport.java:337)
at
javax.management.NotificationBroadcasterSupport.sendNotification(NotificationBroadcasterSupport.java:248)
at
javax.management.remote.rmi.RMIConnector.sendNotification(RMIConnector.java:441)
at javax.management.remote.rmi.RMIConnector.access$1200(RMIConnector.java:121)
at
javax.management.remote.rmi.RMIConnector$RMIClientCommunicatorAdmin.gotIOException(RMIConnector.java:1531)
at
com.sun.jmx.remote.internal.ClientCommunicatorAdmin$Checker.run(ClientCommunicatorAdmin.java:199)
at java.lang.Thread.run(Thread.java:748)
Log 2:
"ForkJoinPool-1-worker-4" #36 daemon prio=5 os_prio=0 tid=0x000000001994c000
nid=0x2178 waiting for monitor entry [0x0000000024fee000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.logging.log4j.core.appender.rolling.RollingFileManager.checkRollover(RollingFileManager.java:272)
- waiting to lock <0x00000000800c3b98> (a
org.apache.logging.log4j.core.appender.rolling.RollingFileManager)
at
org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:311)
at
org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
at
org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at
org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543)
at
org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460)
at
org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
at
org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135)
at
org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1994)
at
org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1852)
at org.apache.logging.log4j.jcl.Log4jLog.info(Log4jLog.java:91)
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
