[
https://issues.apache.org/jira/browse/LOG4J2-982?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14381719#comment-14381719
]
Mikhail Mazurskiy commented on LOG4J2-982:
------------------------------------------
It's a classical deadlock. Thread {{main}} got the instance lock of the
{{LoggerContext}} ({{- locked <0x00000007d8c32370> (a
org.apache.logging.log4j.core.LoggerContext) at
org.apache.logging.log4j.flume.appender.FlumePersistentAppenderTest.teardown(FlumePersistentAppenderTest.java:114)}})
and then it waits for another thread - {{Thread-2}} to finish (thread.join()
{{at java.lang.Thread.join(Thread.java:1281)}}) but that thread is waiting for
the above mentioned lock ({{at
org.apache.logging.log4j.core.LoggerContext.getConfigLocation(LoggerContext.java:400)
- waiting to lock <0x00000007d8c32370> (a
org.apache.logging.log4j.core.LoggerContext)}}). IMHO it is an issue unrelated
to my patch.
{noformat}
"main" prio=6 tid=0x00000000023aa000 nid=0x30c8 in Object.wait()
[0x000000000260d000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007d714b358> (a
org.apache.logging.log4j.flume.appender.FlumePersistentManager$WriterThread)
at java.lang.Thread.join(Thread.java:1281)
- locked <0x00000007d714b358> (a
org.apache.logging.log4j.flume.appender.FlumePersistentManager$WriterThread)
at java.lang.Thread.join(Thread.java:1355)
at
org.apache.logging.log4j.flume.appender.FlumePersistentManager.releaseSub(FlumePersistentManager.java:236)
at
org.apache.logging.log4j.core.appender.AbstractManager.release(AbstractManager.java:119)
at
org.apache.logging.log4j.flume.appender.FlumeAppender.stop(FlumeAppender.java:112)
at
org.apache.logging.log4j.core.config.AbstractConfiguration.stop(AbstractConfiguration.java:237)
at
org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:364)
- locked <0x00000007d8c32370> (a
org.apache.logging.log4j.core.LoggerContext)
at
org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:420)
- locked <0x00000007d8c32370> (a
org.apache.logging.log4j.core.LoggerContext)
at
org.apache.logging.log4j.flume.appender.FlumePersistentAppenderTest.teardown(FlumePersistentAppenderTest.java:114)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
at
org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
at
org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:264)
at
org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
at
org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124)
at
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153)
at
org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Locked ownable synchronizers:
- <0x00000007d8c76348> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)
{noformat}
{noformat}
"Thread-2" daemon prio=6 tid=0x000000000da69800 nid=0x3590 waiting for monitor
entry [0x0000000011c5e000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.logging.log4j.core.LoggerContext.getConfigLocation(LoggerContext.java:400)
- waiting to lock <0x00000007d8c32370> (a
org.apache.logging.log4j.core.LoggerContext)
at
org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.locateContext(ClassLoaderContextSelector.java:156)
at
org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:70)
at
org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:57)
at
org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:142)
at
org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:1)
at org.apache.logging.log4j.LogManager.getContext(LogManager.java:175)
at
org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:102)
at
org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
at
org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
at
org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:277)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
at
org.apache.flume.api.NettyAvroRpcClient.<clinit>(NettyAvroRpcClient.java:103)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:191)
at
org.apache.flume.api.RpcClientFactory.getInstance(RpcClientFactory.java:73)
at
org.apache.flume.api.FailoverRpcClient.getNextClient(FailoverRpcClient.java:264)
at
org.apache.flume.api.FailoverRpcClient.getClient(FailoverRpcClient.java:125)
- locked <0x00000007d70ec370> (a org.apache.flume.api.FailoverRpcClient)
at
org.apache.flume.api.FailoverRpcClient.appendBatch(FailoverRpcClient.java:200)
at
org.apache.logging.log4j.flume.appender.FlumeAvroManager.send(FlumeAvroManager.java:146)
- locked <0x00000007d7064178> (a
org.apache.logging.log4j.flume.appender.FlumePersistentManager)
at
org.apache.logging.log4j.flume.appender.FlumePersistentManager$WriterThread.sendBatch(FlumePersistentManager.java:691)
at
org.apache.logging.log4j.flume.appender.FlumePersistentManager$WriterThread.run(FlumePersistentManager.java:651)
Locked ownable synchronizers:
- None
{noformat}
> Use System.nanoTime() to measure time intervals
> -----------------------------------------------
>
> Key: LOG4J2-982
> URL: https://issues.apache.org/jira/browse/LOG4J2-982
> Project: Log4j 2
> Issue Type: Improvement
> Components: Core, Flume Appender
> Reporter: Mikhail Mazurskiy
> Priority: Minor
> Attachments: LOG4J2-982-v2.patch, LOG4J2-982.patch
>
>
> Unlike {{System.currentTimeMillis()}}, which can jump/slew forward and
> backwards, {{System.nanoTime()}} is a monotonic clock (at least it should be)
> and hence it should be used to measure time intervals (timeouts/delays/etc).
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
