[
https://issues.apache.org/activemq/browse/AMQ-2500?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Matthias Strolz updated AMQ-2500:
---------------------------------
Attachment: DummyMessageConsumer.java
I appended a version without internal dependency to AbstractConsumer
> 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
> 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.
