ActiveMQ
  1. ActiveMQ
  2. AMQ-3373

Pure master/slave connection state error on the master machine.

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Won't Fix
    • Affects Version/s: 5.5.0
    • Fix Version/s: None
    • Component/s: Broker
    • Labels:
      None
    • Environment:

      CentOS 5.6 - x86_64 - 2GB RAM

      Description

      I added this annoying exception thrown by the master ActiveMQ 5.5 when it's connected as pure master/slave. The slave doesn't complain at all and the failover is performed correctly.

      Thanks

      2011-06-15 23:18:47,368 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://localhost#1
      java.lang.IllegalStateException: Cannot lookup a consumer from a connection that had not been registered: ID:ntcs-amq1-53476-1308056848065-2:1
      at org.apache.activemq.broker.MapTransportConnectionStateRegister.lookupConnectionState(MapTransportConnectionStateRegister.java:67)
      at org.apache.activemq.broker.TransportConnection.lookupConnectionState(TransportConnection.java:1423)
      at org.apache.activemq.broker.TransportConnection.getConsumerBrokerExchange(TransportConnection.java:1337)
      at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:464)
      at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229)
      at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306)
      at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
      at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
      at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
      at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218)
      at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
      at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
      2011-06-15 23:18:47,392 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://localhost#3
      java.lang.IllegalStateException: Cannot lookup a consumer from a connection that had not been registered: ID:ntcs-amq1-53476-1308056848065-2:2
      at org.apache.activemq.broker.MapTransportConnectionStateRegister.lookupConnectionState(MapTransportConnectionStateRegister.java:67)
      at org.apache.activemq.broker.TransportConnection.lookupConnectionState(TransportConnection.java:1423)
      at org.apache.activemq.broker.TransportConnection.getConsumerBrokerExchange(TransportConnection.java:1337)
      at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:464)
      at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229)
      at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306)
      at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
      at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
      at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
      at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218)
      at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
      at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)

        Activity

        Hide
        Adam Hoskins added a comment - - edited

        Same issue here on 5.4.2 with Centos 5.5. Master log shows:

        2011-06-28 07:15:00,870 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | ActiveMQ Transport: tcp:///10.0.200.100:58522
        java.lang.IllegalStateException: Cannot lookup a consumer from a connection that had not been registered: ID:BLAH-01-53227-1308650729422-0:5
        at org.apache.activemq.broker.MapTransportConnectionStateRegister.lookupConnectionState(MapTransportConnectionStateRegister.java:63)
        at org.apache.activemq.broker.TransportConnection.lookupConnectionState(TransportConnection.java:1402)
        at org.apache.activemq.broker.TransportConnection.getConsumerBrokerExchange(TransportConnection.java:1316)
        at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:468)
        at org.apache.activemq.command.MessageAck.visit(MessageAck.java:214)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:311)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:185)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:219)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)

        No corresponding events in the slave log and deferred messages are being received to the master and propagating across to the slave. Failing over to slave works fine too.

        Show
        Adam Hoskins added a comment - - edited Same issue here on 5.4.2 with Centos 5.5. Master log shows: 2011-06-28 07:15:00,870 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | ActiveMQ Transport: tcp:///10.0.200.100:58522 java.lang.IllegalStateException: Cannot lookup a consumer from a connection that had not been registered: ID:BLAH-01-53227-1308650729422-0:5 at org.apache.activemq.broker.MapTransportConnectionStateRegister.lookupConnectionState(MapTransportConnectionStateRegister.java:63) at org.apache.activemq.broker.TransportConnection.lookupConnectionState(TransportConnection.java:1402) at org.apache.activemq.broker.TransportConnection.getConsumerBrokerExchange(TransportConnection.java:1316) at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:468) at org.apache.activemq.command.MessageAck.visit(MessageAck.java:214) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:311) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:185) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:219) at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98) at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36) No corresponding events in the slave log and deferred messages are being received to the master and propagating across to the slave. Failing over to slave works fine too.
        Hide
        Jose Guerra added a comment - - edited

        Hi,
        It was just to add the master log since the instant in what the slave is attached to the master. I didn't realize of these exceptions previous ones to that I originally posted.

        2011-06-29 11:07:38,077 | INFO | Active Slave Broker telemetry-slave is attached | org.apache.activemq.broker.TransportConnection | ActiveMQ Transport: t
        cp:///161.72.44.61:52367
        2011-06-29 11:07:38,137 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | ActiveMQ Transport: tcp:///161.72.44.62:47912
        java.lang.NullPointerException
        at org.apache.activemq.broker.region.Queue.send(Queue.java:537)
        at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:365)
        at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:523)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
        at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:227)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
        at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:458)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
        2011-06-29 11:07:38,151 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://telemetry#5
        java.lang.IllegalArgumentException: The subscription does not exist: ID:ntcs-amq1-50722-1309345322394-2:3:1:1
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:375)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:549)
        at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
        at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
        at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:197)
        at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87)
        at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:465)
        at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
        2011-06-29 11:07:38,221 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | ActiveMQ Transport: tcp:///161.72.44.62:47912
        java.lang.NullPointerException
        at org.apache.activemq.broker.region.Queue.send(Queue.java:537)
        at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:365)
        at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:523)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
        at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:227)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
        at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:458)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
        2011-06-29 11:07:38,234 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://telemetry#11
        java.lang.IllegalStateException: Cannot lookup a consumer from a connection that had not been registered: ID:ntcs-amq1-50722-1309345322394-2:6
        at org.apache.activemq.broker.MapTransportConnectionStateRegister.lookupConnectionState(MapTransportConnectionStateRegister.java:67)
        at org.apache.activemq.broker.TransportConnection.lookupConnectionState(TransportConnection.java:1423)
        at org.apache.activemq.broker.TransportConnection.getConsumerBrokerExchange(TransportConnection.java:1337)
        at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:464)
        at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
        at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
        2011-06-29 11:07:38,263 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://telemetry#1

        Show
        Jose Guerra added a comment - - edited Hi, It was just to add the master log since the instant in what the slave is attached to the master. I didn't realize of these exceptions previous ones to that I originally posted. 2011-06-29 11:07:38,077 | INFO | Active Slave Broker telemetry-slave is attached | org.apache.activemq.broker.TransportConnection | ActiveMQ Transport: t cp:///161.72.44.61:52367 2011-06-29 11:07:38,137 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | ActiveMQ Transport: tcp:///161.72.44.62:47912 java.lang.NullPointerException at org.apache.activemq.broker.region.Queue.send(Queue.java:537) at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:365) at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:523) at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129) at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96) at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:227) at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135) at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:458) at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218) at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104) at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42) 2011-06-29 11:07:38,151 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://telemetry#5 java.lang.IllegalArgumentException: The subscription does not exist: ID:ntcs-amq1-50722-1309345322394-2:3:1:1 at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:375) at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:549) at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77) at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77) at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:197) at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87) at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:465) at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218) at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104) at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42) 2011-06-29 11:07:38,221 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | ActiveMQ Transport: tcp:///161.72.44.62:47912 java.lang.NullPointerException at org.apache.activemq.broker.region.Queue.send(Queue.java:537) at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:365) at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:523) at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129) at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96) at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:227) at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135) at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:458) at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218) at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104) at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42) 2011-06-29 11:07:38,234 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://telemetry#11 java.lang.IllegalStateException: Cannot lookup a consumer from a connection that had not been registered: ID:ntcs-amq1-50722-1309345322394-2:6 at org.apache.activemq.broker.MapTransportConnectionStateRegister.lookupConnectionState(MapTransportConnectionStateRegister.java:67) at org.apache.activemq.broker.TransportConnection.lookupConnectionState(TransportConnection.java:1423) at org.apache.activemq.broker.TransportConnection.getConsumerBrokerExchange(TransportConnection.java:1337) at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:464) at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:306) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179) at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69) at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:218) at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104) at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42) 2011-06-29 11:07:38,263 | ERROR | Slave Failed | org.apache.activemq.broker.ft.MasterBroker | VMTransport: vm://telemetry#1
        Hide
        Vitali Kviatkouski added a comment - - edited

        Reproduced on ActiveMQ 5.6.0
        Seems this happens because it is expected that there is consumer connection on slave. And when we follow this flow:
        1. Start master
        2. Start slave
        3. Start consumers (consuming app)
        everything works fine as consumer connections are replicated to slave only when they are created.
        But when we restart slave, consumer connections on master are untouched, so they are not replicated to slave.
        My proposal is to replicate active consumer connections on slave when slave connects to master.

        Show
        Vitali Kviatkouski added a comment - - edited Reproduced on ActiveMQ 5.6.0 Seems this happens because it is expected that there is consumer connection on slave. And when we follow this flow: 1. Start master 2. Start slave 3. Start consumers (consuming app) everything works fine as consumer connections are replicated to slave only when they are created. But when we restart slave, consumer connections on master are untouched, so they are not replicated to slave. My proposal is to replicate active consumer connections on slave when slave connects to master.
        Hide
        Timothy Bish added a comment -

        Pure master/slave removed in upcoming v5.8.0

        Show
        Timothy Bish added a comment - Pure master/slave removed in upcoming v5.8.0

          People

          • Assignee:
            Unassigned
            Reporter:
            Jose Guerra
          • Votes:
            5 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development