You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Sergiy Barlabanov (JIRA)" <ji...@apache.org> on 2012/11/09 12:04:11 UTC

[jira] [Updated] (AMQ-4166) RedeliveryPlugin causes a deadlock with JobSchedulerImpl

     [ https://issues.apache.org/jira/browse/AMQ-4166?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sergiy Barlabanov updated AMQ-4166:
-----------------------------------

    Attachment: stack-trace-2.txt
                stack-trace-1.txt
                broker-config.xml

Broker config and the stack traces of the participating threads.
                
> RedeliveryPlugin causes a deadlock with JobSchedulerImpl
> --------------------------------------------------------
>
>                 Key: AMQ-4166
>                 URL: https://issues.apache.org/jira/browse/AMQ-4166
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.7.0
>         Environment: Reproduced on Windows 8, Windows Vista, MacOS X
> with Oracle jdk 1.7.0_07. ActiveMQ is started embedded using RAR inside Glassfish 3.1.2.2.
>            Reporter: Sergiy Barlabanov
>         Attachments: broker-config.xml, stack-trace-1.txt, stack-trace-2.txt
>
>
> Originates from the forum discussion http://activemq.2283324.n4.nabble.com/RedeliveryPlugin-causes-a-deadlock-with-JobSchedulerImpl-in-ActiveMQ-5-7-0-tt4659019.html
> we have RedeliveryPlugin causing thread deadlock together with JobSchedulerImpl. ActiveMQ version is 5.7.0. We activated RedeliveryPlugin in our broker config xml (see below). There two stacktraces below as well. One is from ActiveMQ VMTransport thread, which tries to send a message to a dead letter queue using RedeliveryPlugin. RedeliveryPlugin just tries to reschedule the message for redelivery and for that it calls JobSchedulerImpl and blocks on its synchronized method "schedule". On the way "consumersLock" is locked. 
> Another stack trace is from JobScheduler:JMS thread, which fires a job to redeliver some message and tries to send it using the same queue used by the VMTransport thread. And it blocks on that consumersLock locked by the VMTransport thread. And this occurs in JobSchedulerImpl#mainLoop method inside synchronized {} block causing a deadlock, since the VMTransport thread tries to call another synchronized method of JobSchedulerImpl. The art how RedeliveryPlugin and JobSchedulerImpl are programmed seems to be quite dangerous, since they both access the queues and try to acquire queue locks. And additionally synchronized methods of JobSchedulerImpl are called directly from RedeliveryPlugin making that to a nice source of thread deadlocks. And I see no measures taken in the code to avoid these deadlocks.
> We can reproduce it quite often if we start ActiveMQ with empty stores (kahadb and scheduler stores are deleted manually from the file system before startup). But looking at the code, I would say that the problem may occur in any situation in any deployment scenario (standalone or embedded in a JEE container). It is just enough to have some Transport thread redelivering a message and the JobScheduler thread trying to fire a job at the same moment on the same queue.
> And another strange thing, which is may be has nothing to do with the deadlock but is still strange, is that according to the stack trace RedeliveryPlugin tries to redeliver an expired message.
> Our broker configuration:
>     <broker xmlns="http://activemq.apache.org/schema/core" brokerName="dcdng" useJmx="true" useShutdownHook="false" schedulerSupport="false">
>         <managementContext>
>             
>             <managementContext createConnector="false"/>
>         </managementContext>
>         <persistenceAdapter>
>             <kahaDB directory="${activemq.message.storage}" journalMaxFileLength="10mb"/>
>         </persistenceAdapter>
>         <transportConnectors>
>             <transportConnector uri="${activemq.connector.address}"/>
>         </transportConnectors>
>         <destinationPolicy>
>             <policyMap>
>                 <policyEntries>
>                     
>                     <policyEntry queue=">" producerFlowControl="true"> 
>                         <deadLetterStrategy>
>                             
>                             <individualDeadLetterStrategy queuePrefix="DLQ." useQueueForQueueMessages="true" processExpired="false" enableAudit="false"/>
>                         </deadLetterStrategy>
>                     </policyEntry>
>                 </policyEntries>
>             </policyMap>
>         </destinationPolicy>
>         <plugins>
>             <redeliveryPlugin fallbackToDeadLetter="true" sendToDlqIfMaxRetriesExceeded="true">
>                 <redeliveryPolicyMap>
>                     <redeliveryPolicyMap>
>                         <redeliveryPolicyEntries>
>                             <redeliveryPolicy queue="EventQueue" maximumRedeliveries="10" 
>                                               redeliveryDelay="1000"/>
>                         </redeliveryPolicyEntries>
>                         <defaultEntry>
>                             <redeliveryPolicy maximumRedeliveries="3" 
>                                               redeliveryDelay="1000"/>
>                         </defaultEntry>
>                     </redeliveryPolicyMap>
>                 </redeliveryPolicyMap>
>             </redeliveryPlugin>
>         </plugins>
>         <systemUsage>
>             <systemUsage sendFailIfNoSpace="true">
>                 <memoryUsage>
>                     <memoryUsage limit="200 mb"/>
>                 </memoryUsage>
>                 <storeUsage>
>                     <storeUsage limit="1000 mb"/>
>                 </storeUsage>
>                 <tempUsage>
>                     <tempUsage limit="200 mb"/>
>                 </tempUsage>
>             </systemUsage>
>         </systemUsage>
>     </broker>
> Stack trace #1:
> Name: ActiveMQ VMTransport: vm://dcdng#101-1 
> State: BLOCKED on org.apache.activemq.broker.scheduler.JobSchedulerImpl@6a135124 owned by: JobScheduler:JMS 
> Total blocked: 22  Total waited: 13 
> org.apache.activemq.broker.scheduler.JobSchedulerImpl.schedule(JobSchedulerImpl.java:110) 
> org.apache.activemq.broker.scheduler.SchedulerBroker.send(SchedulerBroker.java:185) 
> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129) 
> org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96) 
> org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317) 
> org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135) 
> org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135) 
> org.apache.activemq.broker.util.RedeliveryPlugin.scheduleRedelivery(RedeliveryPlugin.java:190) 
> org.apache.activemq.broker.util.RedeliveryPlugin.sendToDeadLetterQueue(RedeliveryPlugin.java:144) 
> org.apache.activemq.broker.MutableBrokerFilter.sendToDeadLetterQueue(MutableBrokerFilter.java:274) 
> org.apache.activemq.broker.region.RegionBroker.messageExpired(RegionBroker.java:798) 
> org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:257) 
> org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:257) 
> org.apache.activemq.advisory.AdvisoryBroker.messageExpired(AdvisoryBroker.java:284) 
> org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:257) 
> org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:257) 
> org.apache.activemq.broker.MutableBrokerFilter.messageExpired(MutableBrokerFilter.java:269) 
> org.apache.activemq.broker.MutableBrokerFilter.messageExpired(MutableBrokerFilter.java:269) 
> org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1657) 
> org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:640) 
>    - locked java.lang.Object@7b97909e 
>    - locked java.lang.Object@1b97b476 
> org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:155) 
> org.apache.activemq.broker.region.Queue.doActualDispatch(Queue.java:1897) 
> org.apache.activemq.broker.region.Queue.doDispatch(Queue.java:1824) 
> org.apache.activemq.broker.region.Queue.removeSubscription(Queue.java:572) 
> org.apache.activemq.broker.region.AbstractRegion.removeConsumer(AbstractRegion.java:381) 
> org.apache.activemq.broker.region.RegionBroker.removeConsumer(RegionBroker.java:445) 
> org.apache.activemq.broker.jmx.ManagedRegionBroker.removeConsumer(ManagedRegionBroker.java:275) 
> org.apache.activemq.broker.BrokerFilter.removeConsumer(BrokerFilter.java:117) 
> org.apache.activemq.broker.BrokerFilter.removeConsumer(BrokerFilter.java:117) 
> org.apache.activemq.advisory.AdvisoryBroker.removeConsumer(AdvisoryBroker.java:254) 
> org.apache.activemq.broker.BrokerFilter.removeConsumer(BrokerFilter.java:117) 
> org.apache.activemq.broker.BrokerFilter.removeConsumer(BrokerFilter.java:117) 
> org.apache.activemq.broker.MutableBrokerFilter.removeConsumer(MutableBrokerFilter.java:123) 
> org.apache.activemq.broker.MutableBrokerFilter.removeConsumer(MutableBrokerFilter.java:123) 
> org.apache.activemq.broker.TransportConnection.processRemoveConsumer(TransportConnection.java:593) 
> org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:76) 
> org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:294) 
> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:152) 
> org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) 
> org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) 
> org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:241) 
> org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:129) 
> org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:47) 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) 
> java.lang.Thread.run(Thread.java:722) 
> Stack trace #2:
> Name: JobScheduler:JMS 
> State: WAITING on java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync@30001430 owned by: ActiveMQ VMTransport: vm://dcdng#101-1 
> Total blocked: 15  Total waited: 480 
>   
> Stack trace: 
> sun.misc.Unsafe.park(Native Method) 
> java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) 
> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834) 
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964) 
> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282) 
> java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731) 
> org.apache.activemq.broker.region.Queue.messageSent(Queue.java:1679) 
> org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:791) 
> org.apache.activemq.broker.region.Queue.send(Queue.java:717) 
> org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:407) 
> org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:503) 
> org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:311) 
> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129) 
> org.apache.activemq.broker.scheduler.SchedulerBroker.scheduledJob(SchedulerBroker.java:251) 
> org.apache.activemq.broker.scheduler.JobSchedulerImpl.fireJob(JobSchedulerImpl.java:423) 
> org.apache.activemq.broker.scheduler.JobSchedulerImpl.mainLoop(JobSchedulerImpl.java:473) 
>    - locked org.apache.activemq.broker.scheduler.JobSchedulerImpl@6a135124 
> org.apache.activemq.broker.scheduler.JobSchedulerImpl.run(JobSchedulerImpl.java:429) 
> java.lang.Thread.run(Thread.java:722) 

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira