activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Gary Tully (JIRA)" <j...@apache.org>
Subject [jira] Commented: (AMQ-2693) potential hang with failover, transactions and slow thread creation with outstanding commit - close blocks pending dispatch FailoverConsumerOutstandingCommitTest intermittent failure
Date Tue, 13 Jul 2010 09:34:51 GMT

    [ https://issues.apache.org/activemq/browse/AMQ-2693?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=60617#action_60617
] 

Gary Tully commented on AMQ-2693:
---------------------------------

Are you seeing this failure on trunk or on the 5.3.2 branch? do you need to reopen this issue?

TRACE level debug will also help a little here. Any outstanding connection/consumer/producer
is replayed by the ConnectionStateTracker and this is visible with TRACE.

> potential hang with failover, transactions and slow thread creation with outstanding
commit - close blocks pending dispatch  FailoverConsumerOutstandingCommitTest intermittent
failure
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: AMQ-2693
>                 URL: https://issues.apache.org/activemq/browse/AMQ-2693
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.3.0, 5.3.1
>         Environment: loaded machine where thread creation is slow
>            Reporter: Gary Tully
>            Assignee: Gary Tully
>             Fix For: 5.4.0
>
>
> potential dead lock pending dispatch that is blocked by an outstanding commit after failover.
> Log indicates:{code}
> WARN  ActiveMQConnection             - dispatch paused, waiting for outstanding dispatch
interruption processing (x) to complete..
> {code}
> Thread Dump:{code}
> Full thread dump Java HotSpot(TM) Server VM (14.0-b16 mixed mode):
> ...
> "ActiveMQ Transport: tcp:///127.0.0.1:49284" daemon prio=3 tid=0x0068f800 nid=0x32 runnable
[0x56ffe000]
>    java.lang.Thread.State: RUNNABLE
> 	at java.net.SocketOutputStream.socketWrite0(Native Method)
> 	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
> 	at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
> 	at org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:115)
> 	at java.io.DataOutputStream.flush(DataOutputStream.java:106)
> 	at org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:168)
> 	at org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:243)
> 	- locked <0x5c2daab0> (a java.util.concurrent.atomic.AtomicBoolean)
> 	at org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:83)
> 	at org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:104)
> 	at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:40)
> 	- locked <0x5c2da520> (a java.lang.Object)
> 	at org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1205)
> 	at org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:790)
> 	at org.apache.activemq.broker.TransportConnection.dispatchSync(TransportConnection.java:750)
> 	at org.apache.activemq.broker.region.PrefetchSubscription.dispatch(PrefetchSubscription.java:647)
> 	at org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:592)
> 	- locked <0x5c2db3a0> (a java.lang.Object)
> 	- locked <0x5c2db3a8> (a java.lang.Object)
> 	at org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:158)
> 	at org.apache.activemq.broker.region.Queue.doActualDispatch(Queue.java:1548)
> 	at org.apache.activemq.broker.region.Queue.doDispatch(Queue.java:1500)
> 	- locked <0x5c2db500> (a java.util.ArrayList)
> 	- locked <0x5c2db518> (a java.lang.Object)
> 	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1585)
> 	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1219)
> 	- locked <0x5c2db520> (a org.apache.activemq.broker.region.Queue$3)
> 	at org.apache.activemq.broker.region.Queue.wakeup(Queue.java:1406)
> 	at org.apache.activemq.broker.region.Queue.addSubscription(Queue.java:377)
> 	at org.apache.activemq.broker.region.AbstractRegion.addConsumer(AbstractRegion.java:279)
> 	- locked <0x5c2db590> (a java.lang.Object)
> 	at org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:380)
> 	at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> 	at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> 	at org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:89)
> 	at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> 	at org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:93)
> 	at org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:533)
> 	at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:349)
> 	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:300)
> 	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:178)
> 	at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
> 	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
> 	at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:216)
> 	- locked <0x5c2dab30> (a org.apache.activemq.transport.InactivityMonitor$1)
> 	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
> 	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:204)
> 	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:186)
> 	at java.lang.Thread.run(Thread.java:619)
> "ActiveMQ Transport: tcp://localhost/127.0.0.1:61616" prio=3 tid=0x007c9000 nid=0x2e
waiting on condition [0x569fe000]
>    java.lang.Thread.State: TIMED_WAITING (parking)
> 	at sun.misc.Unsafe.park(Native Method)
> 	- parking to wait for  <0x5c2b1950> (a java.util.concurrent.CountDownLatch$Sync)
> 	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:947)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1239)
> 	at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:253)
> 	at org.apache.activemq.ActiveMQConnection.waitForTransportInterruptionProcessing(ActiveMQConnection.java:2248)
> 	at org.apache.activemq.ActiveMQConnection$2.processMessageDispatch(ActiveMQConnection.java:1679)
> 	at org.apache.activemq.command.MessageDispatch.visit(MessageDispatch.java:108)
> 	at org.apache.activemq.ActiveMQConnection.onCommand(ActiveMQConnection.java:1676)
> 	at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
> 	at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
> 	at org.apache.activemq.transport.failover.FailoverTransport$3.onCommand(FailoverTransport.java:168)
> 	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
> 	at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:216)
> 	- locked <0x5c2db138> (a org.apache.activemq.transport.InactivityMonitor$1)
> 	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
> 	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:204)
> 	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:186)
> 	at java.lang.Thread.run(Thread.java:619)
> "ActiveMQ Session Task" prio=3 tid=0x0076f000 nid=0x25 waiting on condition [0x55ffe000]
>    java.lang.Thread.State: WAITING (parking)
> 	at sun.misc.Unsafe.park(Native Method)
> 	- parking to wait for  <0x5c2e3cd0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> 	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> 	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> 	at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> 	at org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:40)
> 	at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:87)
> 	at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1262)
> 	at org.apache.activemq.TransactionContext.syncSendPacketWithInterruptionHandling(TransactionContext.java:666)
> 	at org.apache.activemq.TransactionContext.commit(TransactionContext.java:299)
> 	at org.apache.activemq.ActiveMQSession.commit(ActiveMQSession.java:558)
> 	at org.apache.activemq.transport.failover.FailoverConsumerOutstandingCommitTest$2.onMessage(FailoverConsumerOutstandingCommitTest.java:155)
> 	at org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:1204)
> 	- locked <0x5c2c6088> (a java.lang.Object)
> 	at org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:131)
> 	at org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:202)
> 	at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> 	at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:619)
> "ActiveMQ Scheduler" daemon prio=3 tid=0x006e4c00 nid=0xf waiting for monitor entry [0x573ff000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at org.apache.activemq.ActiveMQMessageConsumer.clearMessagesInProgress(ActiveMQMessageConsumer.java:661)
> 	- waiting to lock <0x5c2c6088> (a java.lang.Object)
> 	at org.apache.activemq.ActiveMQSession$2.run(ActiveMQSession.java:654)
> 	at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
> 	at java.util.TimerThread.mainLoop(Timer.java:512)
> 	at java.util.TimerThread.run(Timer.java:462)
> "main" prio=3 tid=0x00030800 nid=0x2 waiting for monitor entry [0x7eb7d000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at org.apache.activemq.MessageDispatchChannel.stop(MessageDispatchChannel.java:115)
> 	- waiting to lock <0x5c2c6088> (a java.lang.Object)
> 	at org.apache.activemq.ActiveMQMessageConsumer.stop(ActiveMQMessageConsumer.java:1312)
> 	at org.apache.activemq.ActiveMQSession.stop(ActiveMQSession.java:1643)
> 	at org.apache.activemq.ActiveMQConnection.stop(ActiveMQConnection.java:544)
> 	- locked <0x5c2ae5d8> (a java.util.concurrent.CopyOnWriteArrayList)
> 	at org.apache.activemq.ActiveMQConnection.close(ActiveMQConnection.java:597)
> 	at org.apache.activemq.transport.failover.FailoverConsumerOutstandingCommitTest.doTestFailoverConsumerDups(FailoverConsumerOutstandingCommitTest.java:185)
> 	at org.apache.activemq.transport.failover.FailoverConsumerOutstandingCommitTest.testFailoverConsumerDups(FailoverConsumerOutstandingCommitTest.java:104)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> 	at java.lang.reflect.Method.invoke(Method.java:597)
> 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
> 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
> 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
> 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
> 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
> 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
> 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:73)
> 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:46)
> 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:180)
> 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:41)
> 	at org.junit.runners.ParentRunner$1.evaluate(ParentRunner.java:173)
> 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
> 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
> 	at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
> 	at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:62)
> 	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.executeTestSet(AbstractDirectoryTestSuite.java:140)
> 	at org.apache.maven.surefire.suite.AbstractDirectoryTestSuite.execute(AbstractDirectoryTestSuite.java:165)
> 	at org.apache.maven.surefire.Surefire.run(Surefire.java:107)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> 	at java.lang.reflect.Method.invoke(Method.java:597)
> 	at org.apache.maven.surefire.booter.SurefireBooter.runSuitesInProcess(SurefireBooter.java:289)
> 	at org.apache.maven.surefire.booter.SurefireBooter.main(SurefireBooter.java:1005)
> {code}

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


Mime
View raw message