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/19 20:05:52 UTC

[jira] Created: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Async error occurred - Slave broker out of sync with master
-----------------------------------------------------------

                 Key: AMQ-1983
                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
             Project: ActiveMQ
          Issue Type: Bug
          Components: Broker
    Affects Versions: 5.2.0
         Environment: java version "1.6.0_07"
Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
            Reporter: Hans Bausewein
         Attachments: activemqjee-0.0.8-src.tar.gz

I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)


Logged on the slave:
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)


I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.




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


[jira] Commented: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46638#action_46638 ] 

Hans Bausewein commented on AMQ-1983:
-------------------------------------

I've run another test with our real application with a single JBoss host and a pure master/slave ActiveMQ setup.

See the ERRORs in "activemq-master.log.gz" and "activemq-slave.log.gz"

Logged at DEBUG level, so I hope it's clear enough.

I think the case matches quite closely to the test code in this issue, though the real application does a lot more.

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Commented: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46650#action_46650 ] 

Hans Bausewein commented on AMQ-1983:
-------------------------------------

This was the message from the JBoss server log that produced the issue:

2008-10-21 18:27:06,677 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:339 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:339:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:339:1, destination = queue://queue.CLIENT_OUT_TOKEN, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530323500000000000000000000000000000000000000000000000000000000000000000000000000:31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606426677, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = ..........(removed the message)............}


It was one of 686 messages sent by the same EJB to the same queue within about 15 minutes during my tests.

The transaction commit happened at the time of the ERROR Service                        - Async error occurred: 
  JMSException: Slave broker out of sync with master: Dispatched message (ID:master.cluster-49988-1224605035095-0:42:339:1:1) was not in the pending list

in the slave log.





> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Issue Comment Edited: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46650#action_46650 ] 

hansb edited comment on AMQ-1983 at 10/21/08 2:47 PM:
---------------------------------------------------------------

This was the message from the JBoss server log that produced the issue:

2008-10-21 18:27:06,677 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:339 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:339:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:339:1, destination = queue://queue.CLIENT_OUT_TOKEN, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530323500000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606426677, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = ..........(removed the message)............}


It was one of 686 messages sent by the same EJB to the same queue within about 15 minutes during my tests.

The transaction commit happened at the time of the ERROR Service                        - Async error occurred: 
  JMSException: Slave broker out of sync with master: Dispatched message (ID:master.cluster-49988-1224605035095-0:42:339:1:1) was not in the pending list

in the slave log.





      was (Author: hansb):
    This was the message from the JBoss server log that produced the issue:

{code}
2008-10-21 18:27:06,677 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:339 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:339:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:339:1, destination = queue://queue.CLIENT_OUT_TOKEN, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530323500000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606426677, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = ..........(removed the message)............}
{code}

It was one of 686 messages sent by the same EJB to the same queue within about 15 minutes during my tests.

The transaction commit happened at the time of the ERROR Service                        - Async error occurred: 
  JMSException: Slave broker out of sync with master: Dispatched message (ID:master.cluster-49988-1224605035095-0:42:339:1:1) was not in the pending list

in the slave log.




  
> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Environment: 
java version "1.6.0_07"
Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
ActiveMQ 5.3.0  rev 706043 in pure master/slave setup

  was:
java version "1.6.0_07"
Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)


> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Issue Comment Edited: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46638#action_46638 ] 

hansb edited comment on AMQ-1983 at 10/21/08 10:00 AM:
----------------------------------------------------------------

I've run another test with our real application with a single JBoss host and a pure master/slave ActiveMQ setup (5.2.0 RC2).

See the ERRORs in "activemq-master.log.gz" and "activemq-slave.log.gz"

Logged at DEBUG level, so I hope it's clear enough.

I think the case matches quite closely to the test code in this issue, though the real application does a lot more.



      was (Author: hansb):
    I've run another test with our real application with a single JBoss host and a pure master/slave ActiveMQ setup.

See the ERRORs in "activemq-master.log.gz" and "activemq-slave.log.gz"

Logged at DEBUG level, so I hope it's clear enough.

I think the case matches quite closely to the test code in this issue, though the real application does a lot more.
  
> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Attachment: activemq-slave.log.gz

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Attachment: activemq-master.log.gz
                activemq-slave.log.gz

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Attachment:     (was: activemq-slave.log.gz)

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Commented: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46665#action_46665 ] 

Hans Bausewein commented on AMQ-1983:
-------------------------------------

This is the start and end of the XA transactions with that XID in the JBoss server log:

2008-10-21 18:27:09,412 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
...........
2008-10-21 18:27:09,457 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

.................
2008-10-21 18:27:09,459 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:346 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:346:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:346:1, destination = topic://topic.PRE_CLIENT_OUT, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606429459, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text =
 
2008-10-21 18:27:09,478 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:346 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:346:2:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:346:2, destination = queue://queue.CLIENT_OUT, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606429478, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {tnx435=true}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text =
.............

2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f3135303834000000000000000000000000000000000000000000000000000000000
00000000000000000:31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] End: XidImpl[FormatId=257, GlobalId=mcfadden.marketxs.com/15084, BranchQual=1, localId=15084]
2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

Apparently there are 2 transactions with the same transaction id!

For different queues, though.

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Commented: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46671#action_46671 ] 

Hans Bausewein commented on AMQ-1983:
-------------------------------------

Nothing special: it's just a single MDB running in the same XA transaction and sending messages to different queues or topics.

I think I must create a better test application.

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Attachment:     (was: activemq-slave.log.gz)

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Resolved: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Gary Tully (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Gary Tully resolved AMQ-1983.
-----------------------------

         Assignee: Gary Tully
    Fix Version/s: 5.3.0
       Resolution: Fixed

resolved in r708548

thanks for validating the patch.

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>            Assignee: Gary Tully
>             Fix For: 5.3.0
>
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz, activemqjee-0.0.9-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Attachment: activemq-slave.log.gz

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Issue Comment Edited: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46650#action_46650 ] 

hansb edited comment on AMQ-1983 at 10/21/08 2:46 PM:
---------------------------------------------------------------

This was the message from the JBoss server log that produced the issue:

{code}
2008-10-21 18:27:06,677 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:339 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:339:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:339:1, destination = queue://queue.CLIENT_OUT_TOKEN, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530323500000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606426677, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = ..........(removed the message)............}
{code}

It was one of 686 messages sent by the same EJB to the same queue within about 15 minutes during my tests.

The transaction commit happened at the time of the ERROR Service                        - Async error occurred: 
  JMSException: Slave broker out of sync with master: Dispatched message (ID:master.cluster-49988-1224605035095-0:42:339:1:1) was not in the pending list

in the slave log.





      was (Author: hansb):
    This was the message from the JBoss server log that produced the issue:

2008-10-21 18:27:06,677 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:339 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:339:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:339:1, destination = queue://queue.CLIENT_OUT_TOKEN, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530323500000000000000000000000000000000000000000000000000000000000000000000000000:31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606426677, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text = ..........(removed the message)............}


It was one of 686 messages sent by the same EJB to the same queue within about 15 minutes during my tests.

The transaction commit happened at the time of the ERROR Service                        - Async error occurred: 
  JMSException: Slave broker out of sync with master: Dispatched message (ID:master.cluster-49988-1224605035095-0:42:339:1:1) was not in the pending list

in the slave log.




  
> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Issue Comment Edited: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46638#action_46638 ] 

hansb edited comment on AMQ-1983 at 10/21/08 10:01 AM:
----------------------------------------------------------------

I've run another test with our real application with a single JBoss 4.0.5 host and a pure master/slave ActiveMQ setup (5.2.0 RC2).

See the ERRORs in "activemq-master.log.gz" and "activemq-slave.log.gz"

Logged at DEBUG level, so I hope it's clear enough.

I think the case matches quite closely to the test code in this issue, though the real application does a lot more.



      was (Author: hansb):
    I've run another test with our real application with a single JBoss host and a pure master/slave ActiveMQ setup (5.2.0 RC2).

See the ERRORs in "activemq-master.log.gz" and "activemq-slave.log.gz"

Logged at DEBUG level, so I hope it's clear enough.

I think the case matches quite closely to the test code in this issue, though the real application does a lot more.


  
> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Commented: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Gary Tully (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46831#action_46831 ] 

Gary Tully commented on AMQ-1983:
---------------------------------

I think the following patch will fix your issue. There is not much in the line of XA tests in core that can help me verify at the moment. If you get a chance, can you build trunk with this patch and validate.
{code}
Index: activemq-core/src/main/java/org/apache/activemq/broker/ft/MasterBroker.java
===================================================================
--- activemq-core/src/main/java/org/apache/activemq/broker/ft/MasterBroker.java	(revision 707659)
+++ activemq-core/src/main/java/org/apache/activemq/broker/ft/MasterBroker.java	(working copy)
@@ -253,7 +253,7 @@
      */
     public int prepareTransaction(ConnectionContext context, TransactionId xid) throws Exception {
         TransactionInfo info = new TransactionInfo(context.getConnectionId(), xid, TransactionInfo.PREPARE);
-        sendAsyncToSlave(info);
+        sendSyncToSlave(info);
         int result = super.prepareTransaction(context, xid);
         return result;
     }
{code}

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Issue Comment Edited: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46665#action_46665 ] 

hansb edited comment on AMQ-1983 at 10/22/08 1:39 AM:
---------------------------------------------------------------

This is the start and end of the XA transactions with that XID in the JBoss server log:

2008-10-21 18:27:09,412 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
...........
2008-10-21 18:27:09,457 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

.................
2008-10-21 18:27:09,459 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:346 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:346:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:346:1, destination = topic://topic.PRE_CLIENT_OUT, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606429459, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text =
 
2008-10-21 18:27:09,478 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:346 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:346:2:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:346:2, destination = queue://queue.CLIENT_OUT, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606429478, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {tnx435=true}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text =
.............

2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] End: XidImpl[FormatId=257, GlobalId=mcfadden.marketxs.com/15084, BranchQual=1, localId=15084]
2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

Apparently there are 2 transactions with the same transaction id!

For different queues, though.

      was (Author: hansb):
    This is the start and end of the XA transactions with that XID in the JBoss server log:

2008-10-21 18:27:09,412 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
...........
2008-10-21 18:27:09,457 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

.................
2008-10-21 18:27:09,459 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:346 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:346:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:346:1, destination = topic://topic.PRE_CLIENT_OUT, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606429459, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, text =
 
2008-10-21 18:27:09,478 DEBUG [org.apache.activemq.ActiveMQSession] ID:master.cluster-49988-1224605035095-0:42:346 sending message: ActiveMQTextMessage {commandId = 0, responseRequired = false, messageId = ID:master.cluster-49988-1224605035095-0:42:346:2:1, originalDestination = null, originalTransactionId = null, producerId = ID:master.cluster-49988-1224605035095-0:42:346:2, destination = queue://queue.CLIENT_OUT, transactionId = XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000, expiration = 0, timestamp = 1224606429478, arrival = 0, brokerInTime = 0, brokerOutTime = 0, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {tnx435=true}, readOnlyProperties = true, readOnlyBody = true, droppable = false, text =
.............

2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f3135303834000000000000000000000000000000000000000000000000000000000
00000000000000000:31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] End: XidImpl[FormatId=257, GlobalId=mcfadden.marketxs.com/15084, BranchQual=1, localId=15084]
2008-10-21 18:27:09,730 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6d6366616464656e2e6d61726b657478732e636f6d2f313530383400000000000000000000000000000000000000000000000000000000000000000000000000:
31000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

Apparently there are 2 transactions with the same transaction id!

For different queues, though.
  
> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Description: 
I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
{code}
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
   ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
   ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
  consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
  destination = queue://queue.B, 
transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
 messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
{code}

Logged on the slave:
{code}
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
  Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
  javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
(ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
{code}

I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.

I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).



  was:
I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
{code}
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
{code}

Logged on the slave:
{code}
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
{code}

I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.

I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).




> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
>            Reporter: Hans Bausewein
>         Attachments: activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Attachment: activemqjee-0.0.9-src.tar.gz

> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz, activemqjee-0.0.9-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Description: 
I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)


Logged on the slave:
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)


I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.

I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).







  was:
I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)


Logged on the slave:
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)


I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.





> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
>            Reporter: Hans Bausewein
>         Attachments: activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> Logged on the slave:
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
> javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Updated: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Hans Bausewein updated AMQ-1983:
--------------------------------

    Description: 
I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
{code}
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
{code}

Logged on the slave:
{code}
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
{code}

I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.

I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).



  was:
I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz

It's a MDB that forwards a message to another queue. 

What I did:
- send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
- the MDB sends each message to queue.B
- if a reply queue was set in the message, the MDB sends a reply

On queue.B is an MDB that just received and logs the message.


Logged on the master:
2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
        at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)


Logged on the slave:
2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
......
2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
        at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
        at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
        at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)


I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.

I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).








> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
>            Reporter: Hans Bausewein
>         Attachments: activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, destination = queue://queue.B, transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136, messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
> javax.jms.JMSException: Slave broker out of sync with master: Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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


[jira] Commented: (AMQ-1983) Async error occurred - Slave broker out of sync with master

Posted by "Hans Bausewein (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/activemq/browse/AMQ-1983?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=46841#action_46841 ] 

Hans Bausewein commented on AMQ-1983:
-------------------------------------

It seems this fixes it. I've sent more than 1600 messages without this happening again.
It's a bit modified MDB that forwards the message to 2 queues and a topic and sends a reply to the replyTo queue. (closer to what our real application does)
See activemqjee-0.0.9-src.tar.gz

I've not tested the stand-alone version and that one is not transacted anyway.
Only tested the EJB version on JBoss 4.2.3.




> Async error occurred - Slave broker out of sync with master
> -----------------------------------------------------------
>
>                 Key: AMQ-1983
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1983
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.2.0
>         Environment: java version "1.6.0_07"
> Client is a JBoss 4.2.3.GA cluster using the ActiveMQ resource adapter (from RC2)
> ActiveMQ 5.3.0  rev 706043 in pure master/slave setup
>            Reporter: Hans Bausewein
>         Attachments: activemq-master.log.gz, activemq-slave.log.gz, activemqjee-0.0.8-src.tar.gz
>
>
> I have tried to reduce the real-life problem to something smaller. See activemqjee-0.0.8.tar.gz
> It's a MDB that forwards a message to another queue. 
> What I did:
> - send some messages to queue.A (I did 10 at a time, using the webconsole setting Persistent Delivery)
> - the MDB sends each message to queue.B
> - if a reply queue was set in the message, the MDB sends a reply
> On queue.B is an MDB that just received and logs the message.
> Logged on the master:
> {code}
> 2008-10-19 18:39:54,114 [127.0.0.1:43972] DEBUG AMQMessageStore                - Journalled transacted message add for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,278 [127.0.0.1:43972] DEBUG AMQMessageStore                - Transacted message add commit for:
>    ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,305 [127.0.0.1:43962] ERROR MasterBroker                   - Slave Failed
> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId = 1031, responseRequired = true, ackType = 2, 
>   consumerId = ID:selten.cluster-40744-1224434310420-0:0:-1:2, firstMessageId = 
> ID:selten.cluster-40744-1224434310420-0:2:4:1:1, lastMessageId = ID:selten.cluster-40744-1224434310420-0:2:4:1:1, 
>   destination = queue://queue.B, 
> transactionId = XID:131075:312d2d32613062356562303a613535653a34386662363236643a313135:2d32613062356562303a613535653a34386662363236643a313136,
>  messageCount = 1}; Could not find Message-ID ID:selten.cluster-40744-1224434310420-0:2:4:1:1 in dispatched-list (start of ack)
>         at org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:438)
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188)
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:373)
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:462)
> {code}
> Logged on the slave:
> {code}
> 2008-10-19 18:39:54,112 [.cluster#1] DEBUG AMQMessageStore                - Journalled transacted message add for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,241 [.cluster#1] DEBUG AMQMessageStore                - Transacted message add commit for: ID:selten.cluster-40744-1224434310420-0:2:4:1:1, at: offset = 90045, file = 1, size = 429, type = 1
> ......
> 2008-10-19 18:39:54,288 [.cluster#1] ERROR Service                        - Async error occurred: javax.jms.JMSException: Slave broker out of sync with master: 
>   Dispatched message (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>   javax.jms.JMSException: Slave broker out of sync with master: Dispatched message 
> (ID:selten.cluster-40744-1224434310420-0:2:4:1:1) was not in the pending list for queue.B
>         at org.apache.activemq.broker.region.PrefetchSubscription.processMessageDispatchNotification(PrefetchSubscription.java:175)
>         at org.apache.activemq.broker.region.AbstractRegion.processDispatchNotification(AbstractRegion.java:414)
>         at org.apache.activemq.broker.region.RegionBroker.processDispatchNotification(RegionBroker.java:585)
> {code}
> I could not consistently reproduce it with a single JBoss server running. I've sent a few 100 messages without any problem.
> I've tested both 5.2.0-RC2 and 5.3.0-SNAPSHOT (rev 706043).

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