Return-Path: Delivered-To: apmail-activemq-dev-archive@www.apache.org Received: (qmail 14270 invoked from network); 7 Oct 2009 19:36:24 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 7 Oct 2009 19:36:24 -0000 Received: (qmail 3231 invoked by uid 500); 7 Oct 2009 19:36:23 -0000 Delivered-To: apmail-activemq-dev-archive@activemq.apache.org Received: (qmail 3201 invoked by uid 500); 7 Oct 2009 19:36:23 -0000 Mailing-List: contact dev-help@activemq.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@activemq.apache.org Delivered-To: mailing list dev@activemq.apache.org Received: (qmail 3191 invoked by uid 99); 7 Oct 2009 19:36:23 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 07 Oct 2009 19:36:23 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=10.0 tests=ALL_TRUSTED X-Spam-Check-By: apache.org Received: from [140.211.11.140] (HELO brutus.apache.org) (140.211.11.140) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 07 Oct 2009 19:36:14 +0000 Received: from brutus (localhost [127.0.0.1]) by brutus.apache.org (Postfix) with ESMTP id 0B878234C1EF for ; Wed, 7 Oct 2009 12:35:53 -0700 (PDT) Message-ID: <459272757.1254944153041.JavaMail.jira@brutus> Date: Wed, 7 Oct 2009 12:35:53 -0700 (PDT) From: "Mark Gellings (JIRA)" To: dev@activemq.apache.org Subject: [jira] Created: (AMQNET-194) Async error occurred: javax.jms.JMSException: Unmatched acknowledege when Acknowledgemode of Transactional used MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: ae95407df07c98740808b2ef9da0087c X-Virus-Checked: Checked by ClamAV on apache.org Async error occurred: javax.jms.JMSException: Unmatched acknowledege when Acknowledgemode of Transactional used --------------------------------------------------------------------------------------------------------------- Key: AMQNET-194 URL: https://issues.apache.org/activemq/browse/AMQNET-194 Project: ActiveMQ .Net Issue Type: Bug Components: ActiveMQ, NMS Affects Versions: 1.0.0, 1.1.0 Environment: ActiveMQ 5.2 as Windows Service on Windows Server 2008 64-bit. Client producer and consumer on Windows XP Reporter: Mark Gellings Assignee: Jim Gomes See http://www.nabble.com/Async-error-occurred--%3E-ActiveMQ-5.2-and-NMS-td25474605.html for a primer to this issue. After troubleshooting this, it appears that if a producer sends 65535+ messages to the broker that the consumer gets into an infinite loop after consuming 65535 messages. I will be attaching a test case for this. Run a producer and a consumer, send 100,000 messages and the test case fails at 65535 messages consumed exactly. What appears to be happening is that the NMS provider (or ActiveMQ 5.2) is hitting the upper bound of a ushort and then starting all back over again sending message acknowledgements from message #1. This message was already dispatched though and the broker lot shows an error that the message is not in the dispatched-list . The consumer shows a message acknowledgement going out. These errors repeat infinitely it seems. Once the 65535th message errors out then it starts all over again at the 1st message. Notice the ProducerSequenceId growing beyond 65535. I can't seem to avoid this error, even if I reinstantiate the producer sporadically. At the beginning of the source code I have included a loop which shows the behavior of incrementing a ushort beyond 65535. The variable resets to the lower bound as expected. [DEBUG] Apache.NMS.Tracer - Sending Ack: MessageAck[ Destination=queue://testmonday150 TransactionId=LocalTransactionId[ Value=30558 ConnectionId=ConnectionId[ Value=2b6ae5a1-c0e1-4523-8d9c-4143cc9d74e8 ] ] ConsumerId=ConsumerId[ ConnectionId=2b6ae5a1-c0e1-4523-8d9c-4143cc9d74e8 SessionId=1 Value=1 ] AckType=2 FirstMessageId=MessageId[ ProducerId=ProducerId[ ConnectionId=9e256437-df18-44e5-9cb2-b7f3feaebcfd Value=1 SessionId=1 ] ProducerSequenceId=30558 BrokerSequenceId=80280 ] LastMessageId=MessageId[ ProducerId=ProducerId[ ConnectionId=9e256437-df18-44e5-9cb2-b7f3feaebcfd Value=1 SessionId=1 ] ProducerSequenceId=30558 BrokerSequenceId=80280 ] MessageCount=1 ] ERROR Service - Async error occurred: javax.jms.JMSException: Unmatched acknowledege: MessageAc k {commandId = 26140, responseRequired = false, ackType = 2, consumerId = 41b092 97-da4b-4d11-9ed7-09d344825740:1:1, firstMessageId = 4128971e-c69b-4892-8be5-d99 868045881:1:1:30558, lastMessageId = 4128971e-c69b-4892-8be5-d99868045881:1:1:30 558, destination = queue://testwed924, transactionId = TX:41b09297-da4b-4d11-9ed 7-09d344825740:30558, messageCount = 1}; Could not find Message-ID 4128971e-c69b -4892-8be5-d99868045881:1:1:30558 in dispatched-list (start of ack) INFO | jvm 1 | 2009/10/07 14:03:27 | javax.jms.JMSException: Unmatched ackn owledege: MessageAck {commandId = 26140, responseRequired = false, ackType = 2, consumerId = 41b09297-da4b-4d11-9ed7-09d344825740:1:1, firstMessageId = 4128971e -c69b-4892-8be5-d99868045881:1:1:30558, lastMessageId = 4128971e-c69b-4892-8be5- d99868045881:1:1:30558, destination = queue://testwed924, transactionId = TX:41b 09297-da4b-4d11-9ed7-09d344825740:30558, messageCount = 1}; Could not find Messa ge-ID 4128971e-c69b-4892-8be5-d99868045881:1:1:30558 in dispatched-list (start o f ack) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.re gion.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:4 38) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.re gion.PrefetchSubscription.acknowledge(PrefetchSubscription.java:188) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.re gion.AbstractRegion.acknowledge(AbstractRegion.java:373) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.re gion.RegionBroker.acknowledge(RegionBroker.java:462) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Tr ansactionBroker.acknowledge(TransactionBroker.java:194) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Br okerFilter.acknowledge(BrokerFilter.java:74) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Br okerFilter.acknowledge(BrokerFilter.java:74) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Br okerFilter.acknowledge(BrokerFilter.java:74) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Br okerFilter.acknowledge(BrokerFilter.java:74) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Mu tableBrokerFilter.acknowledge(MutableBrokerFilter.java:85) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Tr ansportConnection.processMessageAck(TransportConnection.java:456) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.command.M essageAck.visit(MessageAck.java:205) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Tr ansportConnection.service(TransportConnection.java:305) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.broker.Tr ansportConnection$1.onCommand(TransportConnection.java:179) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.transport .TransportFilter.onCommand(TransportFilter.java:68) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.transport .WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.transport .InactivityMonitor.onCommand(InactivityMonitor.java:206) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.transport .TransportSupport.doConsume(TransportSupport.java:84) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.transport .tcp.TcpTransport.doRun(TcpTransport.java:203) INFO | jvm 1 | 2009/10/07 14:03:27 | at org.apache.activemq.transport .tcp.TcpTransport.run(TcpTransport.java:185) INFO | jvm 1 | 2009/10/07 14:03:27 | at java.lang.Thread.run(Unknown Source) -- This message is automatically generated by JIRA. - You can reply to this email to add a comment to the issue online.