You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by David Sitsky <si...@nuix.com> on 2007/10/05 08:37:57 UTC

RecoveryListenerAdapter - Message id ID... could not be recovered from the data store: WAS: [Duplicate message delivered to consumers on queue with kaha persistence]

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

Re: Duplicate message delivered to consumers on queue with AMQ persistence

Posted by David Sitsky <si...@nuix.com>.
Hi Rob,

I'm afraid I didn't get any time today, and my project has moved on to 
not using JMS persistence for messaging.  We are using custom 
checkpointing instead, which is a bit more lightweight than full JMS 
persistence.

I'd still like to see this issue fixed, so I'll try to find some time in 
the next week or so to produce a unit test which will hopefully show the 
issue.

Cheers,
David

David Sitsky wrote:
> Hi Rob,
> 
> Sorry to hear that - I've also spent ages.  FWIW, it happens regardless 
> of the value for persistentIndex, I've used both true and false.  Ditto 
> with syncOnWrite, which I guess is not surprising.
> 
> I'll try to modify my unit test further today to more closely mimic my 
> real application to see if I can reproduce it.
> 
> Cheers,
> David
> 
> Rob Davies wrote:
>> Hi Dave,
>>
>> spent ages trying to reproduce this with no luck - anybody else had 
>> luck reproducing this on the latest?
>>
>>
>> cheers,
>>
>> Rob
>>
>> http://rajdavies.blogspot.com/
>>
>>
>>
>> On Oct 9, 2007, at 6:28 AM, David Sitsky wrote:
>>
>>> Hi Rob,
>>>
>>> Looks like the original issue I reported with duplicate messages 
>>> being dispatched has resurfaced again.  I don't see it happening in 
>>> the original situation where I saw it with kaha persistence, but now 
>>> with different data loaded in my application.
>>>
>>> This time the issue occurs with AMQ persistence.  I have tried to add 
>>> as much detail as possible here: 
>>> https://issues.apache.org/activemq/browse/AMQ-1452.
>>>
>>> Unfortunately, I have had no luck with reproducing this issue in a 
>>> unit test... but I hope the message logs attached to the issue might 
>>> provide you with some clues.
>>>
>>> Cheers,
>>> David
>>>
>>> David Sitsky wrote:
>>>> 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.
>>>>>>>>>>>

Re: Duplicate message delivered to consumers on queue with AMQ persistence

Posted by David Sitsky <si...@nuix.com>.
Hi Rob,

Sorry to hear that - I've also spent ages.  FWIW, it happens regardless 
of the value for persistentIndex, I've used both true and false.  Ditto 
with syncOnWrite, which I guess is not surprising.

I'll try to modify my unit test further today to more closely mimic my 
real application to see if I can reproduce it.

Cheers,
David

Rob Davies wrote:
> Hi Dave,
> 
> spent ages trying to reproduce this with no luck - anybody else had luck 
> reproducing this on the latest?
> 
> 
> cheers,
> 
> Rob
> 
> http://rajdavies.blogspot.com/
> 
> 
> 
> On Oct 9, 2007, at 6:28 AM, David Sitsky wrote:
> 
>> Hi Rob,
>>
>> Looks like the original issue I reported with duplicate messages being 
>> dispatched has resurfaced again.  I don't see it happening in the 
>> original situation where I saw it with kaha persistence, but now with 
>> different data loaded in my application.
>>
>> This time the issue occurs with AMQ persistence.  I have tried to add 
>> as much detail as possible here: 
>> https://issues.apache.org/activemq/browse/AMQ-1452.
>>
>> Unfortunately, I have had no luck with reproducing this issue in a 
>> unit test... but I hope the message logs attached to the issue might 
>> provide you with some clues.
>>
>> Cheers,
>> David
>>
>> David Sitsky wrote:
>>> 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


-- 
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

Re: Duplicate message delivered to consumers on queue with AMQ persistence

Posted by Rob Davies <ra...@gmail.com>.
Hi Dave,

spent ages trying to reproduce this with no luck - anybody else had  
luck reproducing this on the latest?


cheers,

Rob

http://rajdavies.blogspot.com/



On Oct 9, 2007, at 6:28 AM, David Sitsky wrote:

> Hi Rob,
>
> Looks like the original issue I reported with duplicate messages  
> being dispatched has resurfaced again.  I don't see it happening in  
> the original situation where I saw it with kaha persistence, but  
> now with different data loaded in my application.
>
> This time the issue occurs with AMQ persistence.  I have tried to  
> add as much detail as possible here: https://issues.apache.org/ 
> activemq/browse/AMQ-1452.
>
> Unfortunately, I have had no luck with reproducing this issue in a  
> unit test... but I hope the message logs attached to the issue  
> might provide you with some clues.
>
> Cheers,
> David
>
> David Sitsky wrote:
>> 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


Re: Duplicate message delivered to consumers on queue with AMQ persistence

Posted by Rob Davies <ra...@gmail.com>.
Hi David,

are you trying this with the persistentIndex option?

thanks,

Rob
On Oct 9, 2007, at 6:28 AM, David Sitsky wrote:

> Hi Rob,
>
> Looks like the original issue I reported with duplicate messages  
> being dispatched has resurfaced again.  I don't see it happening in  
> the original situation where I saw it with kaha persistence, but  
> now with different data loaded in my application.
>
> This time the issue occurs with AMQ persistence.  I have tried to  
> add as much detail as possible here: https://issues.apache.org/ 
> activemq/browse/AMQ-1452.
>
> Unfortunately, I have had no luck with reproducing this issue in a  
> unit test... but I hope the message logs attached to the issue  
> might provide you with some clues.
>
> Cheers,
> David
>
> David Sitsky wrote:
>> 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


Duplicate message delivered to consumers on queue with AMQ persistence

Posted by David Sitsky <si...@nuix.com>.
Hi Rob,

Looks like the original issue I reported with duplicate messages being 
dispatched has resurfaced again.  I don't see it happening in the 
original situation where I saw it with kaha persistence, but now with 
different data loaded in my application.

This time the issue occurs with AMQ persistence.  I have tried to add as 
much detail as possible here: 
https://issues.apache.org/activemq/browse/AMQ-1452.

Unfortunately, I have had no luck with reproducing this issue in a unit 
test... but I hope the message logs attached to the issue might provide 
you with some clues.

Cheers,
David

David Sitsky wrote:
> 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

Re: RecoveryListenerAdapter - Message id ID... could not be recovered from the data store: WAS: [Duplicate message delivered to consumers on queue with kaha persistence]

Posted by David Sitsky <si...@nuix.com>.
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

Re: RecoveryListenerAdapter - Message id ID... could not be recovered from the data store: WAS: [Duplicate message delivered to consumers on queue with kaha persistence]

Posted by Rob Davies <ra...@gmail.com>.
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


Re: RecoveryListenerAdapter - Message id ID... could not be recovered from the data store: WAS: [Duplicate message delivered to consumers on queue with kaha persistence]

Posted by David Sitsky <si...@nuix.com>.
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

Re: RecoveryListenerAdapter - Message id ID... could not be recovered from the data store: WAS: [Duplicate message delivered to consumers on queue with kaha persistence]

Posted by Rob Davies <ra...@gmail.com>.
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