From users-return-10898-apmail-activemq-users-archive=activemq.apache.org@activemq.apache.org Mon Oct 08 05:29:40 2007 Return-Path: Delivered-To: apmail-activemq-users-archive@www.apache.org Received: (qmail 24167 invoked from network); 8 Oct 2007 05:29:39 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 8 Oct 2007 05:29:39 -0000 Received: (qmail 53376 invoked by uid 500); 8 Oct 2007 05:29:26 -0000 Delivered-To: apmail-activemq-users-archive@activemq.apache.org Received: (qmail 53352 invoked by uid 500); 8 Oct 2007 05:29:26 -0000 Mailing-List: contact users-help@activemq.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: users@activemq.apache.org Delivered-To: mailing list users@activemq.apache.org Received: (qmail 53343 invoked by uid 99); 8 Oct 2007 05:29:26 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 07 Oct 2007 22:29:26 -0700 X-ASF-Spam-Status: No, hits=-0.0 required=10.0 tests=SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: local policy) Received: from [203.217.22.128] (HELO web1.nuix.com.au) (203.217.22.128) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 08 Oct 2007 05:29:27 +0000 Received: from [192.168.222.61] (unknown [192.168.222.61]) by web1.nuix.com.au (Postfix) with ESMTP id 991041DF101 for ; Mon, 8 Oct 2007 15:29:37 +1000 (EST) Message-ID: <4709C089.2000105@nuix.com> Date: Mon, 08 Oct 2007 15:30:49 +1000 From: David Sitsky Organization: NUIX Pty Ltd User-Agent: Thunderbird 2.0.0.6 (Windows/20070728) MIME-Version: 1.0 To: users@activemq.apache.org Subject: Re: RecoveryListenerAdapter - Message id ID... could not be recovered from the data store: WAS: [Duplicate message delivered to consumers on queue with kaha persistence] References: <470349B9.7060603@nuix.com> <6EC5F211-DC83-4B53-A58A-0A0051D1457E@gmail.com> <47044A49.2030506@nuix.com> <4705DBC5.4010305@nuix.com> <003FD31C-A521-46C3-A065-63AF433BA083@gmail.com> <47098C84.6070807@nuix.com> <286F0CE9-4129-46C2-B193-37A1A07D849B@gmail.com> In-Reply-To: <286F0CE9-4129-46C2-B193-37A1A07D849B@gmail.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Checked: Checked by ClamAV on apache.org Hi Rob, Yes - I haven't seen the issue in my application since updating. Many thanks again. Cheers, David Rob Davies wrote: > Hi David, > > I had a test case that periodically could reproduce this - it now can't > after ensuring references are always freshed in the Kaha reference store > part of AMQ Store. Is your application now fixed? > > thanks, > > Rob > On Oct 8, 2007, at 2:48 AM, David Sitsky wrote: > >> Hi Rob, >> >> Looks like you have fixed this issue - many thanks. >> >> Cheers, >> David >> >> Rob Davies wrote: >>> Hi David, >>> I've had a look through the log you've attached to AMQ-1445 - but I >>> think i'll need some more information to successfully resolve whats >>> going on. Obviously there's an attempt to retrieve a message that's >>> already been deleted - I just need to find out why ;) >>> Could I trouble you to try and devise a junit test case to reproduce? >>> thanks, >>> Rob >>> On Oct 5, 2007, at 7:37 AM, David Sitsky wrote: >>>> Hi Rob, >>>> >>>> I think I spoke too soon. While using AMQ store fixed the initial >>>> issue I was dealing with, it seems to have other issues in my >>>> application, where I see the following message before everything hangs: >>>> >>>> RecoveryListenerAdapter - Message id ID... could not be recovered >>>> from the data store! >>>> >>>> I created a JIRA record which contains the detailed debug message logs: >>>> >>>> https://issues.apache.org/activemq/browse/AMQ-1445 >>>> >>>> FWIW, JDBC persistence works fine. Any ideas what might be wrong? >>>> >>>> Cheers, >>>> David >>>> >>>> David Sitsky wrote: >>>>> Hi Rob, >>>>> Looks like the AMQ store works correctly - thanks for the advice. >>>>> Cheers, >>>>> David >>>>> Rob Davies wrote: >>>>>> Do you get the same using AMQ store (the default in 5.0) - its the >>>>>> prefered store over kaha in ActiveMQ 5.0 >>>>>> >>>>>> >>>>>> >>>>>> cheers, >>>>>> >>>>>> Rob >>>>>> >>>>>> http://rajdavies.blogspot.com/ >>>>>> >>>>>> >>>>>> >>>>>> On Oct 3, 2007, at 8:50 AM, David Sitsky wrote: >>>>>> >>>>>>> I have discovered an issue with the latest activemq 5.0 (revision >>>>>>> 581510) which seems to have been present for some time, at least >>>>>>> for the last month. >>>>>>> >>>>>>> I have an application using transactions, and kaha persistence, >>>>>>> and two consumers feeding off a queue. >>>>>>> >>>>>>> I sometimes see the same message being sent to two consumers. >>>>>>> All transactions were committed (no rollbacks), and as you can >>>>>>> see by the debug dump, the message has the same message-ID, but >>>>>>> was delivered to two separate consumers, running on separate >>>>>>> threads, using sync receives with a prefetch of 0, with separate >>>>>>> sessions of course. >>>>>>> >>>>>>> Is this a known problem? It doesn't always happen - seems to be >>>>>>> a race condition. If I turn off persistence, I don't seem to see >>>>>>> it. >>>>>>> >>>>>>> Here is the message being delivered to consumer 1: >>>>>>> >>>>>>> 2007-10-03 17:21:37,310 [Worker 060bacd87f4a40a4867113e2e3e553dd] >>>>>>> 85475 DEBUG org.apache.activemq.ActiveMQMessageConsumer - >>>>>>> ID:tamarama-62436-1191396093006-2:2:3:2 received message: >>>>>>> MessageDispatch {commandId = 0, responseRequired = false, >>>>>>> consumerId = ID:tamarama-62436-1191396093006-2:2:3:2, destination >>>>>>> = queue://worker-items, message = ActiveMQObjectMessage >>>>>>> {commandId = 50, responseRequired = false, messageId = >>>>>>> ID:tamarama-62436-1191396093006-2:2:1:3:1, originalDestination = >>>>>>> null, originalTransactionId = null, producerId = >>>>>>> ID:tamarama-62436-1191396093006-2:2:1:3, destination = >>>>>>> queue://worker-items, transactionId = >>>>>>> TX:ID:tamarama-62436-1191396093006-2:2:5, expiration = 0, >>>>>>> timestamp = 1191396097286, arrival = 0, brokerInTime = >>>>>>> 1191396097290, brokerOutTime = 1191396097303, correlationId = >>>>>>> null, replyTo = null, persistent = true, type = null, priority = >>>>>>> 4, groupID = null, groupSequence = 0, targetConsumerId = null, >>>>>>> compressed = false, userID = null, content = >>>>>>> org.apache.activemq.util.ByteSequence@fa8cbc, >>>>>>> marshalledProperties = null, dataStructure = null, >>>>>>> redeliveryCounter = 0, size = 0, properties = null, >>>>>>> readOnlyProperties = true, readOnlyBody = true, droppable = >>>>>>> false}, redeliveryCounter = 0} >>>>>>> >>>>>>> Here is the same message (check the message ID) being delivered >>>>>>> to consumer 2: >>>>>>> >>>>>>> 2007-10-03 17:21:37,422 [Worker 2c3169d1726b4781a423a239f65c7bd1] >>>>>>> 85587 DEBUG org.apache.activemq.ActiveMQMessageConsumer - >>>>>>> ID:tamarama-62436-1191396093006-2:2:1:2 received message: >>>>>>> MessageDispatch {commandId = 0, responseRequired = false, >>>>>>> consumerId = ID:tamarama-62436-1191396093006-2:2:1:2, destination >>>>>>> = queue://worker-items, message = ActiveMQObjectMessage >>>>>>> {commandId = 50, responseRequired = false, messageId = >>>>>>> ID:tamarama-62436-1191396093006-2:2:1:3:1, originalDestination = >>>>>>> null, originalTransactionId = null, producerId = >>>>>>> ID:tamarama-62436-1191396093006-2:2:1:3, destination = >>>>>>> queue://worker-items, transactionId = >>>>>>> TX:ID:tamarama-62436-1191396093006-2:2:5, expiration = 0, >>>>>>> timestamp = 1191396097286, arrival = 0, brokerInTime = >>>>>>> 1191396097290, brokerOutTime = 1191396097417, correlationId = >>>>>>> null, replyTo = null, persistent = true, type = null, priority = >>>>>>> 4, groupID = null, groupSequence = 0, targetConsumerId = null, >>>>>>> compressed = false, userID = null, content = >>>>>>> org.apache.activemq.util.ByteSequence@1a881cc, >>>>>>> marshalledProperties = null, dataStructure = null, >>>>>>> redeliveryCounter = 0, size = 0, properties = null, >>>>>>> readOnlyProperties = true, readOnlyBody = true, droppable = >>>>>>> false}, redeliveryCounter = 0} >>>>>>> >>>>>>> I'll need to do more investigations tomorrow, but if anybody has >>>>>>> any ideas, I'd appreciate some insights. >>>>>>> >>>>>>> -- >>>>>>> Cheers, >>>>>>> David >>>>>>> >>>>>>> Nuix Pty Ltd >>>>>>> Suite 79, 89 Jones St, Ultimo NSW 2007, Australia Ph: +61 2 >>>>>>> 9280 0699 >>>>>>> Web: http://www.nuix.com Fax: +61 2 >>>>>>> 9212 6902 >>>> >>>> >>>> -- >>>> Cheers, >>>> David >>>> >>>> Nuix Pty Ltd >>>> Suite 79, 89 Jones St, Ultimo NSW 2007, Australia Ph: +61 2 9280 >>>> 0699 >>>> Web: http://www.nuix.com Fax: +61 2 9212 >>>> 6902 >> >> >> -- >> Cheers, >> David >> >> Nuix Pty Ltd >> Suite 79, 89 Jones St, Ultimo NSW 2007, Australia Ph: +61 2 9280 0699 >> Web: http://www.nuix.com Fax: +61 2 9212 6902 -- Cheers, David Nuix Pty Ltd Suite 79, 89 Jones St, Ultimo NSW 2007, Australia Ph: +61 2 9280 0699 Web: http://www.nuix.com Fax: +61 2 9212 6902