activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From magellings <mark.gelli...@qg.com>
Subject Re: Async error occurred -> ActiveMQ 5.2 and NMS
Date Mon, 19 Oct 2009 16:07:15 GMT

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.


Mime
View raw message