You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by MicAnn <mb...@axway.com> on 2009/06/04 18:06:00 UTC

Duplicate message when HashIndex table is resized

Parameters :
Version : apache-activemq-5.2.0 on windows or AIX (unix)
JDK 1.5.0
Test with exclude queue (no remote consumer)
In the policyEntry queue, producerFlowControl is false.
 
Conditions:
I put 40000 little messages (or more) without active consumer by session of
10000 messages
I lunch listener and sometimes I get more than 40000 messages (up to 19
duplicates messages)

ActiveMQ log display this message during the get operations
      INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fLOCAL.Q3
from 1024 to 4096

When MessageID are recorded it's possible to see the double MessageID of
duplicate messages - marqued "duplicate" for the first and xxxxxx for the
duplicate.

rs37:/home/aep262ta/test_activemq> grep -n duplicate MessageID.txt
27209:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209   
duplicate
27210:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210   
duplicate
27211:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211   
duplicate
27212:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212   
duplicate
27213:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213   
duplicate
27214:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214   
duplicate
27246:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246   
duplicate
27247:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247   
duplicate
27248:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248   
duplicate
27249:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249   
duplicate
27250:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250   
duplicate
rs37:/home/aep262ta/test_activemq> grep -n xxxxx     MessageID.txt
28424:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209         
xxxxxxxxxxx
28425:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210         
xxxxxxxxxxx
28426:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211         
xxxxxxxxxxx
28427:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212         
xxxxxxxxxxx
28428:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213         
xxxxxxxxxxx
28429:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214         
xxxxxxxxxxx
28430:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246         
xxxxxxxxxxx
28431:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247         
xxxxxxxxxxx
28432:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248         
xxxxxxxxxxx
28433:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249         
xxxxxxxxxxx
28434:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250         
xxxxxxxxxxx  

Here, messages read the first time in 27209 pos. are provided a second time
in 28424 pos.

Issue is reproducible on Windows or unix system (AIX).

The JMX console shows that the QueueSize attribute has negative value (see
the image) http://www.nabble.com/file/p23872984/duplicate.jpeg  and Dequeue
count is bigger than EnqueueCount

Other condition:
With a non exclude queue, I can't reproduce the issue.
and the resized HashIndex is different
      INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1 from
1024 to 2048
      INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1 from
2048 to 4096

This issue is serious :  duplicate message or lost message is grave.

-- 
View this message in context: http://www.nabble.com/Duplicate-message-when-HashIndex-table-is-resized-tp23872984p23872984.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: Duplicate message when HashIndex table is resized

Posted by Gary Tully <ga...@gmail.com>.
glad to hear that :-) thanks for the update.

2009/6/5 MicAnn <mb...@axway.com>

>
>
>
> MicAnn wrote:
> >
> > Parameters :
> > Version : apache-activemq-5.2.0 on windows or AIX (unix)
> > JDK 1.5.0
> > Test with exclude queue (no remote consumer)
> > In the policyEntry queue, producerFlowControl is false.
> >
> > Conditions:
> > I put 40000 little messages (or more) without active consumer by session
> > of 10000 messages
> > I lunch listener and sometimes I get more than 40000 messages (up to 19
> > duplicates messages)
> >
> > ActiveMQ log display this message during the get operations
> >       INFO  HashIndex   - Resize hash bins
> > queue-data_queue#3a#2f#2fLOCAL.Q3 from 1024 to 4096
> >
> > When MessageID are recorded it's possible to see the double MessageID of
> > duplicate messages - marqued "duplicate" for the first and xxxxxx for the
> > duplicate.
> >
> > rs37:/home/aep262ta/test_activemq> grep -n duplicate MessageID.txt
> > 27209:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209
> > duplicate
> > 27210:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210
> > duplicate
> > 27211:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211
> > duplicate
> > 27212:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212
> > duplicate
> > 27213:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213
> > duplicate
> > 27214:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214
> > duplicate
> > 27246:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246
> > duplicate
> > 27247:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247
> > duplicate
> > 27248:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248
> > duplicate
> > 27249:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249
> > duplicate
> > 27250:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250
> > duplicate
> > rs37:/home/aep262ta/test_activemq> grep -n xxxxx     MessageID.txt
> > 28424:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209
> > xxxxxxxxxxx
> > 28425:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210
> > xxxxxxxxxxx
> > 28426:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211
> > xxxxxxxxxxx
> > 28427:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212
> > xxxxxxxxxxx
> > 28428:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213
> > xxxxxxxxxxx
> > 28429:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214
> > xxxxxxxxxxx
> > 28430:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246
> > xxxxxxxxxxx
> > 28431:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247
> > xxxxxxxxxxx
> > 28432:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248
> > xxxxxxxxxxx
> > 28433:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249
> > xxxxxxxxxxx
> > 28434:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250
> > xxxxxxxxxxx
> >
> > Here, messages read the first time in 27209 pos. are provided a second
> > time in 28424 pos.
> >
> > Issue is reproducible on Windows or unix system (AIX).
> >
> > The JMX console shows that the QueueSize attribute has negative value
> (see
> > the image) http://www.nabble.com/file/p23872984/duplicate.jpeg  and
> > Dequeue count is bigger than EnqueueCount
> >
> > Other condition:
> > With a non exclude queue, I can't reproduce the issue.
> > and the resized HashIndex is different
> >       INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1
> > from 1024 to 2048
> >       INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1
> > from 2048 to 4096
> >
> > This issue is serious :  duplicate message or lost message is grave.
> >
> >
>
> ---------------
> Gary Tully said : Can you try your test scenario with the 5.3 snapshot, I
> think it should
> behave better. There was an issue with the queue cache, i think this
> related
> to https://issues.apache.org/activemq/browse/AMQ-2020
> ----------------
> OK, this issue seems resolved with apache-activemq-5.3-SNAPSHOT. I can't
> reproduce it after five tests with the same conditions.
> Thanks
> --
> View this message in context:
> http://www.nabble.com/Duplicate-message-when-HashIndex-table-is-resized-tp23872984p23890000.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
>


-- 
http://blog.garytully.com

Open Source Integration
http://fusesource.com

Re: Duplicate message when HashIndex table is resized

Posted by MicAnn <mb...@axway.com>.


MicAnn wrote:
> 
> Parameters :
> Version : apache-activemq-5.2.0 on windows or AIX (unix)
> JDK 1.5.0
> Test with exclude queue (no remote consumer)
> In the policyEntry queue, producerFlowControl is false.
>  
> Conditions:
> I put 40000 little messages (or more) without active consumer by session
> of 10000 messages
> I lunch listener and sometimes I get more than 40000 messages (up to 19
> duplicates messages)
> 
> ActiveMQ log display this message during the get operations
>       INFO  HashIndex   - Resize hash bins
> queue-data_queue#3a#2f#2fLOCAL.Q3 from 1024 to 4096
> 
> When MessageID are recorded it's possible to see the double MessageID of
> duplicate messages - marqued "duplicate" for the first and xxxxxx for the
> duplicate.
> 
> rs37:/home/aep262ta/test_activemq> grep -n duplicate MessageID.txt
> 27209:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209   
> duplicate
> 27210:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210   
> duplicate
> 27211:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211   
> duplicate
> 27212:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212   
> duplicate
> 27213:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213   
> duplicate
> 27214:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214   
> duplicate
> 27246:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246   
> duplicate
> 27247:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247   
> duplicate
> 27248:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248   
> duplicate
> 27249:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249   
> duplicate
> 27250:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250   
> duplicate
> rs37:/home/aep262ta/test_activemq> grep -n xxxxx     MessageID.txt
> 28424:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209         
> xxxxxxxxxxx
> 28425:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210         
> xxxxxxxxxxx
> 28426:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211         
> xxxxxxxxxxx
> 28427:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212         
> xxxxxxxxxxx
> 28428:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213         
> xxxxxxxxxxx
> 28429:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214         
> xxxxxxxxxxx
> 28430:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246         
> xxxxxxxxxxx
> 28431:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247         
> xxxxxxxxxxx
> 28432:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248         
> xxxxxxxxxxx
> 28433:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249         
> xxxxxxxxxxx
> 28434:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250         
> xxxxxxxxxxx  
> 
> Here, messages read the first time in 27209 pos. are provided a second
> time in 28424 pos.
> 
> Issue is reproducible on Windows or unix system (AIX).
> 
> The JMX console shows that the QueueSize attribute has negative value (see
> the image) http://www.nabble.com/file/p23872984/duplicate.jpeg  and
> Dequeue count is bigger than EnqueueCount
> 
> Other condition:
> With a non exclude queue, I can't reproduce the issue.
> and the resized HashIndex is different
>       INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1
> from 1024 to 2048
>       INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1
> from 2048 to 4096
> 
> This issue is serious :  duplicate message or lost message is grave.
> 
> 

---------------
Gary Tully said : Can you try your test scenario with the 5.3 snapshot, I
think it should 
behave better. There was an issue with the queue cache, i think this related 
to https://issues.apache.org/activemq/browse/AMQ-2020
----------------
OK, this issue seems resolved with apache-activemq-5.3-SNAPSHOT. I can't
reproduce it after five tests with the same conditions.
Thanks
-- 
View this message in context: http://www.nabble.com/Duplicate-message-when-HashIndex-table-is-resized-tp23872984p23890000.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: Duplicate message when HashIndex table is resized

Posted by Gary Tully <ga...@gmail.com>.
Can you try your test scenario with the 5.3 snapshot, I think it should
behave better. There was an issue with the queue cache, i think this related
to https://issues.apache.org/activemq/browse/AMQ-2020

2009/6/4 MicAnn <mb...@axway.com>

>
> Parameters :
> Version : apache-activemq-5.2.0 on windows or AIX (unix)
> JDK 1.5.0
> Test with exclude queue (no remote consumer)
> In the policyEntry queue, producerFlowControl is false.
>
> Conditions:
> I put 40000 little messages (or more) without active consumer by session of
> 10000 messages
> I lunch listener and sometimes I get more than 40000 messages (up to 19
> duplicates messages)
>
> ActiveMQ log display this message during the get operations
>      INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fLOCAL.Q3
> from 1024 to 4096
>
> When MessageID are recorded it's possible to see the double MessageID of
> duplicate messages - marqued "duplicate" for the first and xxxxxx for the
> duplicate.
>
> rs37:/home/aep262ta/test_activemq> grep -n duplicate MessageID.txt
> 27209:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209
> duplicate
> 27210:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210
> duplicate
> 27211:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211
> duplicate
> 27212:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212
> duplicate
> 27213:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213
> duplicate
> 27214:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214
> duplicate
> 27246:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246
> duplicate
> 27247:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247
> duplicate
> 27248:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248
> duplicate
> 27249:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249
> duplicate
> 27250:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250
> duplicate
> rs37:/home/aep262ta/test_activemq> grep -n xxxxx     MessageID.txt
> 28424:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7209
> xxxxxxxxxxx
> 28425:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7210
> xxxxxxxxxxx
> 28426:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7211
> xxxxxxxxxxx
> 28427:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7212
> xxxxxxxxxxx
> 28428:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7213
> xxxxxxxxxxx
> 28429:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7214
> xxxxxxxxxxx
> 28430:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7246
> xxxxxxxxxxx
> 28431:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7247
> xxxxxxxxxxx
> 28432:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7248
> xxxxxxxxxxx
> 28433:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7249
> xxxxxxxxxxx
> 28434:  JMS MessageID     : ID:rs37-36072-1244118256815-0:0:1:1:7250
> xxxxxxxxxxx
>
> Here, messages read the first time in 27209 pos. are provided a second time
> in 28424 pos.
>
> Issue is reproducible on Windows or unix system (AIX).
>
> The JMX console shows that the QueueSize attribute has negative value (see
> the image) http://www.nabble.com/file/p23872984/duplicate.jpeg  and
> Dequeue
> count is bigger than EnqueueCount
>
> Other condition:
> With a non exclude queue, I can't reproduce the issue.
> and the resized HashIndex is different
>      INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1 from
> 1024 to 2048
>      INFO  HashIndex   - Resize hash bins queue-data_queue#3a#2f#2fM1 from
> 2048 to 4096
>
> This issue is serious :  duplicate message or lost message is grave.
>
> --
> View this message in context:
> http://www.nabble.com/Duplicate-message-when-HashIndex-table-is-resized-tp23872984p23872984.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
>


-- 
http://blog.garytully.com

Open Source Integration
http://fusesource.com