activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Gary Tully (JIRA)" <j...@apache.org>
Subject [jira] Resolved: (AMQ-2500) Active MQ Blocks when sending and receiving messages and doesn't release resources even after queue is empty
Date Tue, 24 Nov 2009 16:19:52 GMT

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


Mime
View raw message