logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Created] (LOG4J2-1422) AsyncAppenderQueueFullPolicyTest sometimes hangs
Date Fri, 10 Jun 2016 17:09:21 GMT
Remko Popma created LOG4J2-1422:
-----------------------------------

             Summary: AsyncAppenderQueueFullPolicyTest sometimes hangs
                 Key: LOG4J2-1422
                 URL: https://issues.apache.org/jira/browse/LOG4J2-1422
             Project: Log4j 2
          Issue Type: Bug
          Components: Appenders
    Affects Versions: 2.6
            Reporter: Remko Popma


>From the log4j-dev mailing list:
{quote}
I just tried to do a full build and got this test to hang. Gary reported the same thing last
week on Windows.  The stack trace indicates that it isn’t properly shutting down. Somehow
it seems the BlockingAppender must not be having its shutdown flag set. This test was only
added a month ago. I’m not really sure what this test is trying to do but it appears to
have some flawed logic somewhere.
{quote}


{noformat}
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode):

"Attach Listener" daemon prio=5 tid=0x00007fc93b81b000 nid=0x3d0b waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"AsyncAppender-Async" daemon prio=5 tid=0x00007fc93c16c000 nid=0x5603 sleeping[0x00007000015d5000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at org.apache.logging.log4j.test.appender.BlockingAppender.append(BlockingAppender.java:44)
	at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:155)
	at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:128)
	at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:119)
	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
	at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.callAppenders(AsyncAppender.java:338)
	at org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:291)

"surefire-forkedjvm-command-thread" daemon prio=5 tid=0x00007fc93c845800 nid=0x5403 runnable
[0x00007000014d2000]
   java.lang.Thread.State: RUNNABLE
	at java.io.FileInputStream.readBytes(Native Method)
	at java.io.FileInputStream.read(FileInputStream.java:272)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
	- locked <0x00000007aaa9ab70> (a java.io.BufferedInputStream)
	at java.io.DataInputStream.readInt(DataInputStream.java:387)
	at org.apache.maven.surefire.booter.MasterProcessCommand.decode(MasterProcessCommand.java:117)
	at org.apache.maven.surefire.booter.CommandReader$CommandRunnable.run(CommandReader.java:360)
	at java.lang.Thread.run(Thread.java:745)

"last-ditch-daemon-shutdown-thread-30sec" daemon prio=5 tid=0x00007fc93c873800 nid=0x5203
waiting on condition [0x00007000013cf000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007aad7d750> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

"Service Thread" daemon prio=5 tid=0x00007fc93c014800 nid=0x4e03 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=5 tid=0x00007fc93c82d800 nid=0x4c03 waiting on condition
[0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=5 tid=0x00007fc93b051800 nid=0x4a03 waiting on condition
[0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=5 tid=0x00007fc93b04c000 nid=0x3e0f runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=5 tid=0x00007fc93c800000 nid=0x3803 in Object.wait() [0x0000700000d3a000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000007aaa84858> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
	- locked <0x00000007aaa84858> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" daemon prio=5 tid=0x00007fc93c00e000 nid=0x3603 in Object.wait() [0x0000700000c37000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000007aaa84470> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:503)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
	- locked <0x00000007aaa84470> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=0x00007fc93c002800 nid=0x1703 in Object.wait() [0x0000700000218000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000007aca98af0> (a org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread)
	at java.lang.Thread.join(Thread.java:1281)
	- locked <0x00000007aca98af0> (a org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread)
	at org.apache.logging.log4j.core.appender.AsyncAppender.stop(AsyncAppender.java:126)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.stop(AbstractConfiguration.java:321)
	at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:306)
	at org.apache.logging.log4j.core.config.Configurator.shutdown(Configurator.java:337)
	at org.apache.logging.log4j.junit.LoggerContextRule$1.evaluate(LoggerContextRule.java:97)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.junit.runners.Suite.runChild(Suite.java:128)
	at org.junit.runners.Suite.runChild(Suite.java:27)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:161)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:290)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:242)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:121)

"VM Thread" prio=5 tid=0x00007fc93c00b800 nid=0x3403 runnable 

"GC task thread#0 (ParallelGC)" prio=5 tid=0x00007fc93b809800 nid=0x2403 runnable 

"GC task thread#1 (ParallelGC)" prio=5 tid=0x00007fc93b80a000 nid=0x2603 runnable 

"GC task thread#2 (ParallelGC)" prio=5 tid=0x00007fc93b80a800 nid=0x2803 runnable 

"GC task thread#3 (ParallelGC)" prio=5 tid=0x00007fc93b80b000 nid=0x2a03 runnable 

"GC task thread#4 (ParallelGC)" prio=5 tid=0x00007fc93b80c000 nid=0x2c03 runnable 

"GC task thread#5 (ParallelGC)" prio=5 tid=0x00007fc93b80c800 nid=0x2e03 runnable 

"GC task thread#6 (ParallelGC)" prio=5 tid=0x00007fc93b80d000 nid=0x3003 runnable 

"GC task thread#7 (ParallelGC)" prio=5 tid=0x00007fc93b00b800 nid=0x3203 runnable 

"VM Periodic Task Thread" prio=5 tid=0x00007fc93c01d000 nid=0x5003 waiting on condition 

JNI global references: 170
{noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message