Uploaded image for project: 'JBoss A-MQ'
  1. JBoss A-MQ
  2. ENTMQ-2149

Deadlock Between Scheduler and Transport

XMLWordPrintable

    • Hide

      (Reproducer TBD)

      Show
      (Reproducer TBD)

      When troubleshooting a stuck message issue in a fabric environment we discovered the following deadlock in the broker container:

      Found one Java-level deadlock:
      =============================
      "ActiveMQ Transport: tcp:///X.X.X.X:36258@6146":
        waiting for ownable synchronizer 0x00000000c3002170, (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync),
        which is held by "ActiveMQ Broker[activemq-01] Scheduler"
      "ActiveMQ Broker[activemq-01] Scheduler":
        waiting for ownable synchronizer 0x00000000c3293578, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
        which is held by "ActiveMQ Transport: tcp:///X.X.X.X:36258@6146"
      
      Java stack information for the threads listed above:
      ===================================================
      "ActiveMQ Transport: tcp:///X.X.X.X:36258@6146":
      	at sun.misc.Unsafe.park(Native Method)
      	- parking to wait for  <0x00000000c3002170> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
      	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
      	at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:945)
      	at org.apache.activemq.broker.region.Queue.doPendingCursorAdditions(Queue.java:765)
      	at org.apache.activemq.broker.region.Queue.orderedCursorAdd(Queue.java:866)
      	at org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:845)
      	at org.apache.activemq.broker.region.Queue.send(Queue.java:723)
      	at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:419)
      	at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:468)
      	at org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:296)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:152)
      	at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
      	at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:152)
      	at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:157)
      	at org.apache.activemq.util.BrokerSupport.doResend(BrokerSupport.java:68)
      	at org.apache.activemq.util.BrokerSupport.resendNoCopy(BrokerSupport.java:38)
      	at org.apache.activemq.broker.region.RegionBroker.sendToDeadLetterQueue(RegionBroker.java:805)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.advisory.AdvisoryBroker.sendToDeadLetterQueue(AdvisoryBroker.java:495)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.broker.MutableBrokerFilter.sendToDeadLetterQueue(MutableBrokerFilter.java:330)
      	at org.apache.activemq.broker.region.RegionBroker.messageExpired(RegionBroker.java:766)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.advisory.AdvisoryBroker.messageExpired(AdvisoryBroker.java:348)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.broker.MutableBrokerFilter.messageExpired(MutableBrokerFilter.java:324)
      	at org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1778)
      	at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:294)
      	- locked <0x00000000d4470820> (a java.lang.Object)
      	at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:441)
      	at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:484)
      	at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:87)
      	at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:87)
      	at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276)
      	at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:87)
      	at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:97)
      	at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:555)
      	at org.apache.activemq.command.MessageAck.visit(MessageAck.java:245)
      	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:338)
      	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:188)
      	at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
      	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
      	at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:300)
      	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
      	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
      	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
      	at java.lang.Thread.run(Thread.java:745)
      "ActiveMQ Broker[activemq-01] Scheduler":
      	at sun.misc.Unsafe.park(Native Method)
      	- parking to wait for  <0x00000000c3293578> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
      	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireInterruptibly(AbstractQueuedSynchronizer.java:894)
      	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1221)
      	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340)
      	at org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:823)
      	at org.apache.activemq.broker.region.Queue.send(Queue.java:723)
      	at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:419)
      	at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:468)
      	at org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:296)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:152)
      	at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
      	at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)
      	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:152)
      	at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:157)
      	at org.apache.activemq.util.BrokerSupport.doResend(BrokerSupport.java:68)
      	at org.apache.activemq.util.BrokerSupport.resendNoCopy(BrokerSupport.java:38)
      	at org.apache.activemq.broker.region.RegionBroker.sendToDeadLetterQueue(RegionBroker.java:805)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.advisory.AdvisoryBroker.sendToDeadLetterQueue(AdvisoryBroker.java:495)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.broker.BrokerFilter.sendToDeadLetterQueue(BrokerFilter.java:318)
      	at org.apache.activemq.broker.MutableBrokerFilter.sendToDeadLetterQueue(MutableBrokerFilter.java:330)
      	at org.apache.activemq.broker.region.RegionBroker.messageExpired(RegionBroker.java:766)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.advisory.AdvisoryBroker.messageExpired(AdvisoryBroker.java:348)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.broker.BrokerFilter.messageExpired(BrokerFilter.java:312)
      	at org.apache.activemq.broker.MutableBrokerFilter.messageExpired(MutableBrokerFilter.java:324)
      	at org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1778)
      	at org.apache.activemq.broker.region.Queue.messageExpired(Queue.java:1772)
      	at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1905)
      	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:2108)
      	at org.apache.activemq.broker.region.Queue.doBrowse(Queue.java:1107)
      	at org.apache.activemq.broker.region.Queue.expireMessages(Queue.java:900)
      	at org.apache.activemq.broker.region.Queue.access$100(Queue.java:96)
      	at org.apache.activemq.broker.region.Queue$2.run(Queue.java:139)
      	at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
      	at java.util.TimerThread.mainLoop(Timer.java:555)
      	at java.util.TimerThread.run(Timer.java:505)
      

      We tried restarting the container and hit the deadlock again within a minute or two of restart. We tried explicitly disabling schedulerSupport in the broker, but still hit the same deadlock again after a restart. After moving the store (leveDB) to the side and restarting, the broker resumed processing.

      Configuration is fairly "vanilla":

      <beans
        xmlns="http://www.springframework.org/schema/beans"
        xmlns:amq="http://activemq.apache.org/schema/core"
        xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
        xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd
        http://activemq.apache.org/schema/core http://activemq.apache.org/schema/core/activemq-core.xsd">
      
          <!-- Allows us to use system properties and fabric as variables in this configuration file -->
          <bean class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
              <property name="properties">
                  <bean class="io.fabric8.mq.fabric.ConfigurationProperties"/>
              </property>
          </bean>
      
      
          <broker xmlns="http://activemq.apache.org/schema/core" brokerName="${broker-name}" dataDirectory="${data}" start="false" restartAllowed="false">
              <destinationInterceptors>
                  <virtualDestinationInterceptor>
                      <virtualDestinations>
      					<virtualTopic name="VirtualTopic.>" />				  
                      </virtualDestinations>
                  </virtualDestinationInterceptor>
              </destinationInterceptors>
      
      	  	<destinationPolicy>
                  <policyMap>
      			    <policyEntries> 
                          <policyEntry topic="t.>" sendAdvisoryIfNoConsumers="true" advisoryForSlowConsumers="true" advisoryForDelivery="true" advisoryForConsumed="true" advisoryForDiscardingMessages="true" advisoryWhenFull="true" />
                          <policyEntry queue="q.>" sendAdvisoryIfNoConsumers="true" advisoryForSlowConsumers="true" advisoryForDelivery="true" advisoryForConsumed="true" advisoryForDiscardingMessages="true" advisoryWhenFull="true" />
      			    </policyEntries>
      		    </policyMap>
              </destinationPolicy>
      	  
              <managementContext>
                  <managementContext createConnector="false"/>
              </managementContext>
      
              <persistenceAdapter>
      		    <levelDB directory="${data}/levelDB/${karaf.name}"/>
              </persistenceAdapter>
      
              <plugins>
                  <jaasAuthenticationPlugin configuration="karaf" />
              </plugins>
      
              <systemUsage>
                  <systemUsage sendFailIfNoSpaceAfterTimeout="30000">
                      <memoryUsage>
                          <memoryUsage limit="512 mb"/>
                      </memoryUsage>
                      <storeUsage>
                          <storeUsage limit="100 gb"/>
                      </storeUsage>
                      <tempUsage>
                          <tempUsage limit="50 gb"/>
                      </tempUsage>
                  </systemUsage>
              </systemUsage>
      	  
              <transportConnectors>
                  <transportConnector name="openwire" uri="tcp://0.0.0.0:${openwire-port}"/>		    
              </transportConnectors>
          </broker>
      
      </beans>
      

      Note: We didn't clear the scheduler store; we can try that if the issue reoccurs.

              gtully@redhat.com Gary Tully
              rhn-support-dhawkins Duane Hawkins
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: