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