Uploaded image for project: 'ActiveMQ'
  1. ActiveMQ
  2. AMQ-1976

Network of brokers gets out of sync for dispatched messages causing a shutdown of the bridge connections and stalling the brokers

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 5.2.0
    • Fix Version/s: 5.2.0
    • Component/s: None
    • Labels:
      None

      Description

      Running 5.2.0 RC2 + patch AMQ-1971

      I have a network of 5 brokers, running around 50,000 messages per minute per broker within each broker and sending across a total of around 20,000 messages per minute to one of the 5 brokers via a bridge connection. The configuration is the 5.2.0 default with broker names changed on each config and with a network connector set for autodiscovery.

      The system runs for a while then eventually on one broker (the receiving broker that is the only one with the consumers for this queue) these errors appear:

      ERROR RecoveryListenerAdapter - Message id ID:ingest1.mag.ss.com-54179-1223898804441-0:6:1:1:6134 could not be recovered from the data store - already dispatched
      ERROR RecoveryListenerAdapter - Message id ID:query1.mag.ss.com-38822-1223898893819-0:58:16388:1:48 could not be recovered from the data store - already dispatched

      They appear in really high counts.

      On the sending side brokers (publishers but no consumers on these brokers for this queue), these errors appear:

      INFO DemandForwardingBridge - query2.mag.ss.com bridge to query1.mag.ss.com stopped
      INFO DiscoveryNetworkConnector - Establishing network connection between from vm://query2.mag.ss.com to tcp://query1.mag.ss.com:61616
      INFO DemandForwardingBridge - Network connection between vm://query2.mag.ss.com#30 and tcp://query1.mag.ss.com/10.100.0.101:61616(query1.mag.ss.com) has been established.
      ERROR Service - Async error occurred: javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (732)
      javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (732)
      at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:445)
      at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:187)
      at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
      at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
      at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:194)
      at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
      at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
      at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:85)
      at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:456)
      at org.apache.activemq.command.MessageAck.visit(MessageAck.java:205)
      at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305)
      at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
      at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
      at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
      at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:113)
      at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:40)
      at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
      at org.apache.activemq.network.DemandForwardingBridgeSupport$8.onCompletion(DemandForwardingBridgeSupport.java:643)
      at org.apache.activemq.transport.FutureResponse.set(FutureResponse.java:61)
      at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:97)
      at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
      at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143)
      at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206)
      at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
      at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:202)
      at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:184)
      at java.lang.Thread.run(Thread.java:619)
      INFO DemandForwardingBridge - Network connection between vm://query2.mag.ss.com#30 and tcp://query1.mag.ss.com/10.100.0.101:61616 shutdown due to a local error: javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (732)
      INFO DemandForwardingBridge - query2.mag.ss.com bridge to query1.mag.ss.com stopped
      INFO DiscoveryNetworkConnector - Establishing network connection between from vm://query2.mag.ss.com to tcp://query1.mag.ss.com:61616
      INFO DemandForwardingBridge - Network connection between vm://query2.mag.ss.com#32 and tcp://query1.mag.ss.com/10.100.0.101:61616(query1.mag.ss.com) has been established.
      ERROR Service - Async error occurred: javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (730)
      javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (730)
      at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:445)
      at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:187)
      at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
      at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
      at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:194)
      at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
      at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
      at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:85)
      at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:456)
      at org.apache.activemq.command.MessageAck.visit(MessageAck.java:205)
      at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305)
      at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
      at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:104)
      at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
      at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:113)
      at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:40)
      at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
      at org.apache.activemq.network.DemandForwardingBridgeSupport$8.onCompletion(DemandForwardingBridgeSupport.java:643)
      at org.apache.activemq.transport.FutureResponse.set(FutureResponse.java:61)
      at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:97)
      at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
      at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143)
      at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206)
      at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
      at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:202)
      at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:184)
      at java.lang.Thread.run(Thread.java:619)
      INFO DemandForwardingBridge - Network connection between vm://query2.mag.ss.com#32 and tcp://query1.mag.ss.com/10.100.0.101:61616 shutdown due to a local error: javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (730)
      ERROR Service - Async error occurred: javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (729)
      javax.jms.JMSException: Unmatched acknowledege: Expected message count (1) differs from count in dispatched-list (729)
      at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:445)
      at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:187)
      at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
      at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
      at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:194)
      ...

        Attachments

          Activity

            People

            • Assignee:
              gtully Gary Tully
              Reporter:
              jayson.minard Jayson Minard
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: