Try the latest trunk. A bug fix was made.
Daniel Ellis wrote:
>
> We have also experienced this issue when using ActiveMQ 1.2 with NMS.
>
> On the server, the wrapper.log file is full of these errors:-
>
> INFO | jvm 1 | 2009/10/17 13:07:00 | ERROR Service
> - Async error occurred: javax.jms.JMSException: Unmatched acknowledege:
> MessageAck {commandId = 149, responseRequired = false, ackType = 2,
> consumerId = dcfc7fed-2e32-49eb-923e-a823b0151117:12:1, firstMessageId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:1, lastMessageId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:1, destination =
> queue://Progression.Scheduler, transactionId =
> TX:dcfc7fed-2e32-49eb-923e-a823b0151117:1, messageCount = 1}; Could not
> find Message-ID dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:1 in
> dispatched-list (start of ack)
> INFO | jvm 1 | 2009/10/17 13:07:00 | javax.jms.JMSException:
> Unmatched acknowledege: MessageAck {commandId = 149, responseRequired =
> false, ackType = 2, consumerId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:12:1, firstMessageId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:1, lastMessageId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:1, destination =
> queue://Progression.Scheduler, transactionId =
> TX:dcfc7fed-2e32-49eb-923e-a823b0151117:1, messageCount = 1}; Could not
> find Message-ID dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:1 in
> dispatched-list (start of ack)
> INFO | jvm 1 | 2009/10/17 13:07:00 | at..................
>
> On the client we see the log full with:-
>
> Apache.NMS.NMSConnectionException: Unmatched acknowledege: MessageAck
> {commandId = -4156, responseRequired = false, ackType = 2, consumerId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:12:1, firstMessageId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:5061, lastMessageId =
> dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:5061, destination =
> queue://Progression.Scheduler, transactionId =
> TX:dcfc7fed-2e32-49eb-923e-a823b0151117:5028, messageCount = 1}; Could not
> find Message-ID dcfc7fed-2e32-49eb-923e-a823b0151117:1:2:5061 in
> dispatched-list (start of ack)
>
> I think this may be due to incorrect handling in the failover transport of
> NMS. My guess is that the failover transport is handling the exception by
> reconnecting, and then attempting to perform the exact same command which
> is causing the same exception to occur, and round and round it goes %-|.
>
>
>
> magellings wrote:
>>
>> I captured some stats from the broker before after this happened...
>>
>> http://www.nabble.com/file/p25721340/stats2.txt Before
>> http://www.nabble.com/file/p25721340/stats5.txt After
>>
>> Does anyone see any stat that sticks out as a problem?
>>
>>
>> magellings wrote:
>>>
>>> I found something interesting.
>>>
>>> If I remove delete privs on the ACTIVEMQ_MSGS TABLE (we're doing JDBC
>>> Master/Slave) there are a couple things happening...
>>>
>>> #1) I receive Async errors to the looks of it the same as before.
>>> #2) The same messages are getting delivered to the listener after a
>>> restart of the broker despite the fact the consumer already processed
>>> them successfully.
>>>
>>> What I'm wondering is if maybe there's is some sort of hiccup with Sql
>>> Server during our high throughput tests and it wreaks havoc.
>>>
>>> 2009-09-25 15:47:57,176 [//10.0.1.5:4831] ERROR Service
>>>
>>> - Async error occurred: javax.jms.JMSException: Unmatched acknowledege:
>>> MessageAck {commandId = 788, responseRequired = false, ackType = 2,
>>> consumerId = 34be0700-62a7-4594-9ce3-decfe067be28:1:1, firstMessageId =
>>> 7a67e547-4dea-4ee5-9c4d-0460f3d2c005:1:1:61, lastMessageId =
>>> 7a67e547-4dea-4ee5-9c4d-0460f3d2c005:1:1:61, destination =
>>> queue://testme, transactionId =
>>> TX:34be0700-62a7-4594-9ce3-decfe067be28:262, messageCount = 1}; Could
>>> not find Message-ID 7a67e547-4dea-4ee5-9c4d-0460f3d2c005:1:1:61 in
>>> dispatched-list (start of ack)
>>> javax.jms.JMSException: Unmatched acknowledege: MessageAck {commandId =
>>> 788, responseRequired = false, ackType = 2, consumerId =
>>> 34be0700-62a7-4594-9ce3-decfe067be28:1:1, firstMessageId =
>>> 7a67e547-4dea-4ee5-9c4d-0460f3d2c005:1:1:61, lastMessageId =
>>> 7a67e547-4dea-4ee5-9c4d-0460f3d2c005:1:1:61, destination =
>>> queue://testme, transactionId =
>>> TX:34be0700-62a7-4594-9ce3-decfe067be28:262, messageCount = 1}; Could
>>> not find Message-ID 7a67e547-4dea-4ee5-9c4d-0460f3d2c005:1:1:61 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)
>>> at
>>> org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:194)
>>> at
>>> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
>>> at
>>> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
>>> at
>>> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
>>> at
>>> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
>>> at
>>> org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:85)
>>> at
>>> org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:456)
>>> at org.apache.activemq.command.MessageAck.visit(MessageAck.java:205)
>>> at
>>> org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305)
>>> at
>>> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
>>> at
>>> org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
>>> at
>>> org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143)
>>> at
>>> org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206)
>>> at
>>> org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
>>> at
>>> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
>>> at
>>> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
>>> at java.lang.Thread.run(Unknown Source)
>>>
>>>
>>>
>>> magellings wrote:
>>>>
>>>> I was able to replicate this problem and am attaching a console
>>>> application written with .NET/VS 2008 using the official NMS 1.1.
>>>> provider. We are using ActiveMQ 5.2 with same config file as I
>>>> attached previously.
>>>>
>>>> To replicate send 1,000,000 messages through. Make a copy of the
>>>> console application in "Debug" to a separate directory and run the
>>>> producer and consumer in separate applications. Enter 0 for a pace
>>>> with producer.
>>>>
>>>> http://www.nabble.com/file/p25515100/NativeNMSConsumerAndProducer.zip
>>>> NativeNMSConsumerAndProducer.zip
>>>>
>>>> The Async error occurs around 650,000 msgs and producer, consumer, and
>>>> broker does not recover. One can use Sql Server Express to set up the
>>>> database needed for jdbc master/slave. I did not test in another
>>>> master/slave configuration.
>>>>
>>>>
>>>>
>>>>
>>>> magellings wrote:
>>>>>
>>>>> Hello. We are stress testing ActiveMQ 5.2 using NMS for .NET
>>>>> producers/consumers. We are sending 200,000 messages through our
>>>>> system and we ran into the error "Async error occurred" shortened for
>>>>> brevity. Log file is attached. It seems this error keeps reoccuring
>>>>> after the first one and fills the wrapper.log file to 29GB before disk
>>>>> space fills up and broker stops working. We are running the broker in
>>>>> a windows service on Windows Server 2008.
>>>>>
>>>>> Can anyone take a look at the log file and provide me input into what
>>>>> the problem is? Or some suggestions on modifying our activemq.xml
>>>>> configuration. I'm thinking of setting our prefetch higher than 5 for
>>>>> our consumers. With the thought this will reduce network activity
>>>>> between the broker and consumers.
>>>>>
>>>>> a log with a snippet of the exceptions and activemq.xml attached.
>>>>>
>>>>> Thoughts?
>>>>>
>>>>> http://www.nabble.com/file/p25474605/activemq.xml activemq.xml
>>>>> http://www.nabble.com/file/p25474605/LogSnippet.txt LogSnippet.txt
>>>>>
>>>>
>>>>
>>>
>>>
>>
>>
>
>
--
View this message in context:
http://www.nabble.com/Async-error-occurred--%3E-ActiveMQ-5.2-and-NMS-tp25474605p25960994.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
