You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Hans Bausewein (JIRA)" <ji...@apache.org> on 2008/10/08 18:46:52 UTC

[jira] Updated: (AMQ-1970) Slave in Pure Master/Slave setup not updated when more than 200 messages on a queue

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

Hans Bausewein updated AMQ-1970:
--------------------------------

    Description: 
See the attached application. 

If I run

   org.activemq.jms.StandaloneApp 200 1

it works fine. Tried it 5 times, so sent 1000 messages altogether

If I run

  org.activemq.jms.StandaloneApp 250 1

it fails. The master is fine, but the slave still has pending messages on "queue.A". (43 in my last run)
It reported 407 received messages. (the first 200 + 207 of the last run)

Master logs:
2008-10-08 18:31:04,509 [queue://queue.A] DEBUG AMQMessageStore                - flush starting ...
2008-10-08 18:31:04,513 [0.1.1.155:56003] DEBUG AMQMessageStore                - Journalled message add for: ID:hans-44777-1223483462760-0:1:1:1:208, at: offset = 168628, file = 1, size = 279, type = 1
2008-10-08 18:31:04,513 [queue://queue.A] DEBUG AMQMessageStore                - Doing batch update... adding: 1 removing: 0 
2008-10-08 18:31:04,513 [queue://queue.A] DEBUG AMQMessageStore                - Batch update done.
.................
2008-10-08 18:31:33,313 [0.1.1.155:56846] DEBUG TransportConnection            - Stopping connection: /10.1.1.155:56846
2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TcpTransport                   - Stopping transport tcp:///10.1.1.155:56846
2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TransportConnection            - Stopped transport: /10.1.1.155:56846
2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TransportConnection            - Connection Stopped: /10.1.1.155:56846
2008-10-08 18:31:33,317 [0.1.1.155:56001] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: Could not find Message-ID null in dispatched-list (end of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:443)
        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.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
2008-10-08 18:31:33,319 [0.1.1.155:56001] DEBUG AMQMessageStore                - Journalled message remove for: ID:hans-44777-1223483462760-0:1:1:1:208, at: offset = 233965, file = 1, size = 266, type = 1
2008-10-08 18:31:33,319 [queue://queue.A] DEBUG AMQMessageStore                - Doing batch update... adding: 0 removing: 1 
2008-10-08 18:31:33,320 [queue://queue.A] DEBUG AMQMessageStore                - Batch update done.


Slave logs:
2008-10-08 18:31:04,515 [.serverhost#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:hans-44777-1223483462760-0:1:1:1:208) was not in the pending list
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:hans-44777-1223483462760-0:1:1:1:208) was not in the pending list
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:174)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)


  was:
See the attached application. 

If I run

   org.activemq.jms.StandaloneApp 200 1

it works fine. Tried it 5 times, so sent 1000 messages altogether

If I run

  org.activemq.jms.StandaloneApp 250 1

it fails. The master is fine, but the slave still has pending messages on "queue.A". (43 in my last run)
It reported 407 received messages. (the first 200 + 207 of the last run)

Master logs:
2008-10-08 18:31:04,509 [queue://queue.A] DEBUG AMQMessageStore                - flush starting ...
2008-10-08 18:31:04,513 [0.1.1.155:56003] DEBUG AMQMessageStore                - Journalled message add for: ID:hans-44777-1223483462760-0:1:1:1:208, at: offset = 168628, file = 1, size = 279, type = 1
2008-10-08 18:31:04,513 [queue://queue.A] DEBUG AMQMessageStore                - Doing batch update... adding: 1 removing: 0 
2008-10-08 18:31:04,513 [queue://queue.A] DEBUG AMQMessageStore                - Batch update done.
.................
2008-10-08 18:31:33,313 [0.1.1.155:56846] DEBUG TransportConnection            - Stopping connection: /10.1.1.155:56846
2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TcpTransport                   - Stopping transport tcp:///10.1.1.155:56846
2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TransportConnection            - Stopped transport: /10.1.1.155:56846
2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TransportConnection            - Connection Stopped: /10.1.1.155:56846
2008-10-08 18:31:33,317 [0.1.1.155:56001] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: Could not find Message-ID null in dispatched-list (end of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:443)
        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.iterate(VMTransport.java:205)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
2008-10-08 18:31:33,319 [0.1.1.155:56001] DEBUG AMQMessageStore                - Journalled message remove for: ID:hans-44777-1223483462760-0:1:1:1:208, at: offset = 233965, file = 1, size = 266, type = 1
2008-10-08 18:31:33,319 [queue://queue.A] DEBUG AMQMessageStore                - Doing batch update... adding: 0 removing: 1 
2008-10-08 18:31:33,320 [queue://queue.A] DEBUG AMQMessageStore                - Batch update done.


Slave logs:
2008-10-08 18:31:04,515 [.marketxs.com#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:hans-44777-1223483462760-0:1:1:1:208) was not in the pending list
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:hans-44777-1223483462760-0:1:1:1:208) was not in the pending list
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:174)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)



> Slave in Pure Master/Slave setup not updated when more than 200 messages on a queue
> -----------------------------------------------------------------------------------
>
>                 Key: AMQ-1970
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1970
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: 5.2.0 RC2 in Pure Master/Slave setup with a single client
> java version "1.6.0_07"
> Java(TM) SE Runtime Environment (build 1.6.0_07-b06)
>            Reporter: Hans Bausewein
>         Attachments: activemqjee-0.0.5-src.tar.gz
>
>
> See the attached application. 
> If I run
>    org.activemq.jms.StandaloneApp 200 1
> it works fine. Tried it 5 times, so sent 1000 messages altogether
> If I run
>   org.activemq.jms.StandaloneApp 250 1
> it fails. The master is fine, but the slave still has pending messages on "queue.A". (43 in my last run)
> It reported 407 received messages. (the first 200 + 207 of the last run)
> Master logs:
> 2008-10-08 18:31:04,509 [queue://queue.A] DEBUG AMQMessageStore                - flush starting ...
> 2008-10-08 18:31:04,513 [0.1.1.155:56003] DEBUG AMQMessageStore                - Journalled message add for: ID:hans-44777-1223483462760-0:1:1:1:208, at: offset = 168628, file = 1, size = 279, type = 1
> 2008-10-08 18:31:04,513 [queue://queue.A] DEBUG AMQMessageStore                - Doing batch update... adding: 1 removing: 0 
> 2008-10-08 18:31:04,513 [queue://queue.A] DEBUG AMQMessageStore                - Batch update done.
> .................
> 2008-10-08 18:31:33,313 [0.1.1.155:56846] DEBUG TransportConnection            - Stopping connection: /10.1.1.155:56846
> 2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TcpTransport                   - Stopping transport tcp:///10.1.1.155:56846
> 2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TransportConnection            - Stopped transport: /10.1.1.155:56846
> 2008-10-08 18:31:33,314 [0.1.1.155:56846] DEBUG TransportConnection            - Connection Stopped: /10.1.1.155:56846
> 2008-10-08 18:31:33,317 [0.1.1.155:56001] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: Could not find Message-ID null in dispatched-list (end of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:443)
>         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.iterate(VMTransport.java:205)
>         at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
>         at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
> 2008-10-08 18:31:33,319 [0.1.1.155:56001] DEBUG AMQMessageStore                - Journalled message remove for: ID:hans-44777-1223483462760-0:1:1:1:208, at: offset = 233965, file = 1, size = 266, type = 1
> 2008-10-08 18:31:33,319 [queue://queue.A] DEBUG AMQMessageStore                - Doing batch update... adding: 0 removing: 1 
> 2008-10-08 18:31:33,320 [queue://queue.A] DEBUG AMQMessageStore                - Batch update done.
> Slave logs:
> 2008-10-08 18:31:04,515 [.serverhost#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:hans-44777-1223483462760-0:1:1:1:208) was not in the pending list
> javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:hans-44777-1223483462760-0:1:1:1:208) was not in the pending list
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:174)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.