Raúl Kripalani created AMQ-5219:
-----------------------------------
Summary: Deadlock between JMS Job Scheduler and broker
initialization
Key: AMQ-5219
URL: https://issues.apache.org/jira/browse/AMQ-5219
Project: ActiveMQ
Issue Type: Bug
Components: Broker
Affects Versions: 5.7.0
Environment: Apache SMX 4.5.0, JDK 1.6, RHEL.
Reporter: Raúl Kripalani
Priority: Critical
Thread dump exhibiting a deadlock shows that JMS scheduler is started too early
in the broker boot procedure. If scheduled jobs are pending and fired
straightaway after scheduler initialisation – while other broker elements are
still being initialised – this can incur in a deadlock which stalls the broker
completely.
{code}
Java stack information for the threads listed above:
===================================================
"JobScheduler:JMS":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006bca4ecb0> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:941)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1261)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:594)
at
org.apache.activemq.broker.region.AbstractRegion.getDestinations(AbstractRegion.java:240)
at
org.apache.activemq.broker.region.RegionBroker.getDestinations(RegionBroker.java:130)
at
org.apache.activemq.store.kahadb.KahaDBStore.rollbackStatsOnDuplicate(KahaDBStore.java:295)
at
org.apache.activemq.store.kahadb.MessageDatabase.upadateIndex(MessageDatabase.java:1165)
at
org.apache.activemq.store.kahadb.MessageDatabase$14.execute(MessageDatabase.java:982)
at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:980)
at
org.apache.activemq.store.kahadb.MessageDatabase$13.visit(MessageDatabase.java:927)
at
org.apache.activemq.store.kahadb.data.KahaAddMessageCommand.visit(KahaAddMessageCommand.java:241)
at
org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:924)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:836)
at
org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:818)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.addMessage(KahaDBStore.java:433)
at
org.apache.activemq.store.kahadb.KahaDBTransactionStore.addMessage(KahaDBTransactionStore.java:385)
at
org.apache.activemq.store.kahadb.KahaDBTransactionStore$1.addMessage(KahaDBTransactionStore.java:157)
at org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:746)
at org.apache.activemq.broker.region.Queue.send(Queue.java:717)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:407)
at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:503)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:311)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
at
org.apache.activemq.broker.scheduler.SchedulerBroker.scheduledJob(SchedulerBroker.java:251)
at
org.apache.activemq.broker.scheduler.JobSchedulerImpl.fireJob(JobSchedulerImpl.java:423)
at
org.apache.activemq.broker.scheduler.JobSchedulerImpl.mainLoop(JobSchedulerImpl.java:473)
- locked <0x00000006bca05f50> (a
org.apache.activemq.broker.scheduler.JobSchedulerImpl)
at
org.apache.activemq.broker.scheduler.JobSchedulerImpl.run(JobSchedulerImpl.java:429)
at java.lang.Thread.run(Thread.java:662)
"Start Level Event Dispatcher":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006bc5cd318> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
at
java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.getMessageCount(KahaDBStore.java:477)
at
org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:101)
at org.apache.activemq.broker.region.Queue.initialize(Queue.java:376)
at
org.apache.activemq.broker.region.DestinationFactoryImpl.createDestination(DestinationFactoryImpl.java:86)
at
org.apache.activemq.broker.region.AbstractRegion.createDestination(AbstractRegion.java:532)
at
org.apache.activemq.broker.jmx.ManagedQueueRegion.createDestination(ManagedQueueRegion.java:56)
at
org.apache.activemq.broker.region.AbstractRegion.addDestination(AbstractRegion.java:137)
at
org.apache.activemq.broker.region.RegionBroker.addDestination(RegionBroker.java:283)
- locked <0x00000006bca82920> (a java.util.concurrent.ConcurrentHashMap)
at
org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
at
org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
at
org.apache.activemq.advisory.AdvisoryBroker.addDestination(AdvisoryBroker.java:175)
at
org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
at
org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
at
org.apache.activemq.broker.MutableBrokerFilter.addDestination(MutableBrokerFilter.java:151)
at
org.apache.activemq.broker.MutableBrokerFilter.addDestination(MutableBrokerFilter.java:151)
at
org.apache.activemq.broker.region.AbstractRegion.start(AbstractRegion.java:99)
at
org.apache.activemq.broker.region.RegionBroker.start(RegionBroker.java:186)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.start(ManagedRegionBroker.java:121)
at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:157)
at
org.apache.activemq.broker.scheduler.SchedulerBroker.start(SchedulerBroker.java:89)
at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:157)
at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:157)
at
org.apache.activemq.broker.TransactionBroker.start(TransactionBroker.java:122)
at
org.apache.activemq.broker.MutableBrokerFilter.start(MutableBrokerFilter.java:163)
at
org.apache.activemq.broker.BrokerPluginSupport.start(BrokerPluginSupport.java:40)
at
org.apache.activemq.broker.BrokerService$5.start(BrokerService.java:2110)
at
org.apache.activemq.broker.BrokerService.doStartBroker(BrokerService.java:662)
at
org.apache.activemq.broker.BrokerService.startBroker(BrokerService.java:642)
at
org.apache.activemq.broker.BrokerService.start(BrokerService.java:578)
at
org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:58)
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.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1546)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1487)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1419)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:518)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:455)
at
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:293)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
- locked <0x00000006bc3cb720> (a java.util.concurrent.ConcurrentHashMap)
at
org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:290)
at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:192)
at
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:585)
- locked <0x00000006bc3cb510> (a java.util.concurrent.ConcurrentHashMap)
at
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895)
at
org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.access$1600(AbstractDelegatedExecutionApplicationContext.java:69)
at
org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext$4.run(AbstractDelegatedExecutionApplicationContext.java:355)
- locked <0x00000006bc3bccc0> (a java.lang.Object)
at
org.springframework.osgi.util.internal.PrivilegedUtils.executeWithCustomTCCL(PrivilegedUtils.java:85)
at
org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.completeRefresh(AbstractDelegatedExecutionApplicationContext.java:320)
at
org.springframework.osgi.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$CompleteRefreshTask.run(DependencyWaiterApplicationContextExecutor.java:132)
at
org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
at
org.springframework.osgi.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.stageTwo(DependencyWaiterApplicationContextExecutor.java:299)
at
org.springframework.osgi.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.stageOne(DependencyWaiterApplicationContextExecutor.java:244)
at
org.springframework.osgi.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.refresh(DependencyWaiterApplicationContextExecutor.java:169)
at
org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.refresh(AbstractDelegatedExecutionApplicationContext.java:175)
at
org.springframework.osgi.extender.internal.activator.ContextLoaderListener$2.run(ContextLoaderListener.java:716)
at
org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
at
org.springframework.osgi.extender.internal.activator.ContextLoaderListener.maybeCreateApplicationContextFor(ContextLoaderListener.java:781)
at
org.springframework.osgi.extender.internal.activator.ContextLoaderListener$ContextBundleListener.handleEvent(ContextLoaderListener.java:229)
at
org.springframework.osgi.extender.internal.activator.ContextLoaderListener$BaseListener.bundleChanged(ContextLoaderListener.java:172)
at
org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:919)
at
org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:227)
at
org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:149)
at
org.eclipse.osgi.framework.internal.core.Framework.publishBundleEventPrivileged(Framework.java:1349)
at
org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1300)
at
org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:380)
at
org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:374)
at
org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1067)
at
org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:561)
at
org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:546)
at
org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:459)
at
org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:243)
- locked <0x00000006ba9f9338> (a java.lang.Object)
at
org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:440)
at
org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:227)
at
org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:337)
Found 1 deadlock.
{code}
Useful info:
* This was seen in an OSGi environment, Apache SMX 4.5.0.
* Broker is being initialised through Spring configuration. Original OOTB
Blueprint activemq-broker.xml was replaced with Spring equivalent, with the
following manifest option:
{code}
<manifest>
Spring-Context: *;publish-context:=false;create-asynchronously:=false
</manifest>
{code}
** This ensures that the broker is started before all other business bundles
(by starting this Spring context synchronously, the OSGi framework waits until
the bundle is started before continuing with starting the rest).
* No other broker plugins apart from the redeliveryPlugin are configured.
Config of this one is as follows:
{code}
<redeliveryPlugin fallbackToDeadLetter="true"
sendToDlqIfMaxRetriesExceeded="true">
<redeliveryPolicyMap>
<redeliveryPolicyMap>
<redeliveryPolicyEntries>
...
</redeliveryPolicyEntries>
</redeliveryPolicyMap>
</redeliveryPolicyMap>
</redeliveryPlugin>
{code}
--
This message was sent by Atlassian JIRA
(v6.2#6252)