You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Gary Tully (JIRA)" <ji...@apache.org> on 2009/11/24 17:19:52 UTC
[jira] Resolved: (AMQ-2500) Active MQ Blocks when sending and
receiving messages and doesn't release resources even after queue is empty
[ https://issues.apache.org/activemq/browse/AMQ-2500?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Gary Tully resolved AMQ-2500.
-----------------------------
Resolution: Fixed
Fix Version/s: 5.3.0
resolving based on comment from Matthias.
> Active MQ Blocks when sending and receiving messages and doesn't release resources even after queue is empty
> ------------------------------------------------------------------------------------------------------------
>
> Key: AMQ-2500
> URL: https://issues.apache.org/activemq/browse/AMQ-2500
> Project: ActiveMQ
> Issue Type: Bug
> Affects Versions: 5.2.0
> Environment: JDK 1.6.0.x, Windows XP and Vista, ActiveMQ Default-configurations
> Reporter: Matthias Strolz
> Fix For: 5.3.0
>
> Attachments: DummyMessageConsumer.java, JMX-Screenshot.PNG
>
>
> The following test-programm reads and writes messages into the same queue (testQueue). After Reading several messages the class starts two threads that are writing messages in the same queue. After writing several messages the producer hangs on:
> producer.send()
> and doesn't recover even if the reader continues reading messages from the queue. Even stopping the clients (via kill) doesn't change the broker's behaviour. In this state further connections opened from other clients hang on the same method call (producer.send()). The client's connections will remain open as you can see in the jconsole-screenshot, that has been taken after the producer in the example hung. Althogh the consumer may continue reading new producer can only continue writing messages into the queue after activeMQ has been restarted.
> The following two snippets show the difference between the first (127.0.0.1:49372) and the second (127.0.0.1:49385) message producer: The first producer works as expected and adds it's messages to the queue. The second producer stops with the following log-entry: 2009-11-13 09:41:45,639 [127.0.0.1:49385] DEBUG AbstractRegion - Adding consumer: ID:JoergsPC-49370-1258101701975-0:14:-1:1
> ...
> 2009-11-13 09:41:42,376 [eue://testQueue] DEBUG Queue - queue://testQueue - Recovery - Message pushed '21290107 - Message ID:JoergsPC-50687-1258047095293-0:2810:1:1:1 dropped=false locked=false' to subscription: 'QueueSubscription: consumer=ID:JoergsPC-49370-1258101701975-0:0:1:1, destinations=1, dispatched=197, delivered=0, pending=0'
> 2009-11-13 09:41:42,376 [eue://testQueue] DEBUG Queue - queue://testQueue - Recovery - Message pushed '31931917 - Message ID:JoergsPC-50687-1258047095293-0:2811:1:1:1 dropped=false locked=false' to subscription: 'QueueSubscription: consumer=ID:JoergsPC-49370-1258101701975-0:0:1:1, destinations=1, dispatched=198, delivered=0, pending=0'
> 2009-11-13 09:41:42,376 [eue://testQueue] DEBUG Queue - queue://testQueue - Recovery - Message pushed '10144386 - Message ID:JoergsPC-50687-1258047095293-0:2812:1:1:1 dropped=false locked=false' to subscription: 'QueueSubscription: consumer=ID:JoergsPC-49370-1258101701975-0:0:1:1, destinations=1, dispatched=199, delivered=0, pending=0'
> 2009-11-13 09:41:42,381 [127.0.0.1:49372] DEBUG WireFormatNegotiator - Received WireFormat: WireFormatInfo { version=3, properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2009-11-13 09:41:42,381 [127.0.0.1:49372] DEBUG WireFormatNegotiator - Sending: WireFormatInfo { version=3, properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2009-11-13 09:41:42,382 [127.0.0.1:49372] DEBUG WireFormatNegotiator - tcp:///127.0.0.1:49372 before negotiation: OpenWireFormat{version=3, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2009-11-13 09:41:42,394 [127.0.0.1:49372] DEBUG WireFormatNegotiator - tcp:///127.0.0.1:49372 after negotiation: OpenWireFormat{version=3, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2009-11-13 09:41:42,395 [127.0.0.1:49372] DEBUG TransportConnection - Setting up new connection: /127.0.0.1:49372
> 2009-11-13 09:41:42,409 [127.0.0.1:49372] DEBUG AbstractRegion - Adding consumer: ID:JoergsPC-49370-1258101701975-0:1:-1:1
> 2009-11-13 09:41:42,414 [127.0.0.1:49372] DEBUG AbstractRegion - Adding destination: topic://ActiveMQ.Advisory.Producer.Queue.testQueue
> 2009-11-13 09:41:42,416 [127.0.0.1:49372] DEBUG AMQMessageStore - Journalled message add for: ID:JoergsPC-49370-1258101701975-0:1:1:1:1, at: offset = 10684963, file = 4, size = 270, type = 1
> 2009-11-13 09:41:42,416 [eue://testQueue] DEBUG AMQMessageStore - Doing batch update... adding: 1 removing: 0
> 2009-11-13 09:41:42,417 [eue://testQueue] DEBUG AMQMessageStore - Batch update done.
> 2009-11-13 09:41:42,418 [eue://testQueue] DEBUG Usage - Memory usage change. from: 7, to: 8
> 2009-11-13 09:41:42,418 [eue://testQueue] DEBUG Usage - Memory usage change. from: 1, to: 2
> 2009-11-13 09:41:42,425 [eue://testQueue] DEBUG Usage - Memory usage change. from: 8, to: 9
> 2009-11-13 09:41:42,433 [eue://testQueue] DEBUG Usage - Memory usage change. from: 9, to: 10
> 2009-11-13 09:41:42,440 [eue://testQueue] DEBUG Usage - Memory usage change. from: 10, to: 11
> 2009-11-13 09:41:42,470 [127.0.0.1:49371] DEBUG AbstractRegion - Removing consumer: ID:JoergsPC-49370-1258101701975-0:0:1:1
> 2009-11-13 09:41:42,474 [127.0.0.1:49371] DEBUG AMQMessageStore - flush starting ...
> 2009-11-13 09:41:42,474 [127.0.0.1:49371] DEBUG AbstractRegion - Removing consumer: ID:JoergsPC-49370-1258101701975-0:0:-1:1
> 2009-11-13 09:41:42,477 [127.0.0.1:49371] DEBUG TransportConnection - Stopping connection: /127.0.0.1:49371
> ...
> ...
> 2009-11-13 09:41:45,319 [eue://testQueue] DEBUG Queue - queue://testQueue - Recovery - Message pushed '21569784 - Message ID:JoergsPC-50687-1258047095293-0:3422:1:1:1 dropped=false locked=false' to subscription: 'QueueSubscription: consumer=ID:JoergsPC-49370-1258101701975-0:13:1:1, destinations=1, dispatched=797, delivered=0, pending=0'
> 2009-11-13 09:41:45,320 [eue://testQueue] DEBUG Usage - Memory usage change. from: 181, to: 182
> 2009-11-13 09:41:45,327 [eue://testQueue] DEBUG Usage - Memory usage change. from: 182, to: 183
> 2009-11-13 09:41:45,331 [eue://testQueue] DEBUG Usage - Memory usage change. from: 183, to: 184
> 2009-11-13 09:41:45,332 [eue://testQueue] DEBUG Usage - Memory usage change. from: 45, to: 46
> 2009-11-13 09:41:45,338 [eue://testQueue] DEBUG Usage - Memory usage change. from: 184, to: 185
> 2009-11-13 09:41:45,344 [eue://testQueue] DEBUG Usage - Memory usage change. from: 185, to: 186
> 2009-11-13 09:41:45,349 [eue://testQueue] DEBUG Usage - Memory usage change. from: 186, to: 187
> 2009-11-13 09:41:45,356 [eue://testQueue] DEBUG Usage - Memory usage change. from: 187, to: 188
> 2009-11-13 09:41:45,356 [eue://testQueue] DEBUG Usage - Memory usage change. from: 46, to: 47
> 2009-11-13 09:41:45,442 [127.0.0.1:49384] DEBUG AbstractRegion - Removing consumer: ID:JoergsPC-49370-1258101701975-0:13:1:1
> 2009-11-13 09:41:45,445 [eue://testQueue] DEBUG Usage - Memory usage change. from: 188, to: 189
> 2009-11-13 09:41:45,443 [127.0.0.1:49372] DEBUG AbstractRegion - Removing consumer: ID:JoergsPC-49370-1258101701975-0:1:-1:1
> 2009-11-13 09:41:45,632 [127.0.0.1:49372] DEBUG TransportConnection - Stopping connection: /127.0.0.1:49372
> 2009-11-13 09:41:45,632 [127.0.0.1:49372] DEBUG TcpTransport - Stopping transport tcp:///127.0.0.1:49372
> 2009-11-13 09:41:45,632 [127.0.0.1:49372] DEBUG TransportConnection - Stopped transport: /127.0.0.1:49372
> 2009-11-13 09:41:45,632 [127.0.0.1:49372] DEBUG TransportConnection - Connection Stopped: /127.0.0.1:49372
> 2009-11-13 09:41:45,636 [127.0.0.1:49385] DEBUG WireFormatNegotiator - Sending: WireFormatInfo { version=3, properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2009-11-13 09:41:45,638 [127.0.0.1:49385] DEBUG WireFormatNegotiator - Received WireFormat: WireFormatInfo { version=3, properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2009-11-13 09:41:45,638 [127.0.0.1:49385] DEBUG WireFormatNegotiator - tcp:///127.0.0.1:49385 before negotiation: OpenWireFormat{version=3, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2009-11-13 09:41:45,638 [127.0.0.1:49385] DEBUG WireFormatNegotiator - tcp:///127.0.0.1:49385 after negotiation: OpenWireFormat{version=3, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2009-11-13 09:41:45,638 [127.0.0.1:49385] DEBUG TransportConnection - Setting up new connection: /127.0.0.1:49385
> 2009-11-13 09:41:45,639 [127.0.0.1:49385] DEBUG AbstractRegion - Adding consumer: ID:JoergsPC-49370-1258101701975-0:14:-1:1
> 2009-11-13 09:41:45,641 [eue://testQueue] DEBUG Usage - Memory usage change. from: 189, to: 190
> 2009-11-13 09:41:45,647 [eue://testQueue] DEBUG Usage - Memory usage change. from: 190, to: 191
> 2009-11-13 09:41:45,653 [eue://testQueue] DEBUG Usage - Memory usage change. from: 191, to: 192
> 2009-11-13 09:41:45,653 [eue://testQueue] DEBUG Usage - Memory usage change. from: 47, to: 48
> 2009-11-13 09:41:45,658 [eue://testQueue] DEBUG Usage - Memory usage change. from: 192, to: 193
> 2009-11-13 09:41:45,663 [127.0.0.1:49384] DEBUG Usage - Memory usage change. from: 193, to: 192
> 2009-11-13 09:41:45,663 [127.0.0.1:49384] DEBUG Usage - Memory usage change. from: 192, to: 191
> 2009-11-13 09:41:45,663 [127.0.0.1:49384] DEBUG Usage - Memory usage change. from: 48, to: 47
> 2009-11-13 09:41:45,663 [127.0.0.1:49384] DEBUG Usage - Memory usage change. from: 191, to: 190
> 2009-11-13 09:41:45,664 [127.0.0.1:49384] DEBUG Usage - Memory usage change. from: 190, to: 189
> 2009-11-13 09:41:45,664 [127.0.0.1:49384] DEBUG AMQMessageStore - flush starting ...
> 2009-11-13 09:41:45,664 [127.0.0.1:49384] DEBUG AbstractRegion - Removing consumer: ID:JoergsPC-49370-1258101701975-0:13:-1:1
> 2009-11-13 09:41:45,665 [127.0.0.1:49384] DEBUG TransportConnection - Stopping connection: /127.0.0.1:49384
> ...
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.