Hi gtully,
here is the output of the consumer when it fails
27/03/14 12:35:39 - [TRACE,MessageListenerAdapter:360] No result object
given - no result to handle
27/03/14 12:35:39 - [TRACE,TransactionSynchronizationManager:140] Retrieved
value
[org.springframework.jms.listener.LocallyExposedJmsResourceHolder@639e59c6]
for key [org.apache.activemq.pool.PooledConnectionFactory@7e83a12a] bound to
thread
[org.springframework.jms.listener.DefaultMessageListenerContainer#3-1]
27/03/14 12:35:39 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:3:1 Transaction Commit
:TX:ID:birch-34593-1395916847390-0:3:14187
27/03/14 12:35:39 - [DEBUG,Connection:4:55] SENDING: MessageAck {commandId =
66468, responseRequired = false, ackType = 2, consumerId =
ID:birch-34593-1395916847390-0:3:1:1, firstMessageId =
ID:birch-60203-1395842814608-1:179:1:1:2050, lastMessageId =
ID:birch-60203-1395842814608-1:179:1:1:2050, destination =
queue://ReceiveQueue, transactionId =
TX:ID:birch-34593-1395916847390-0:3:14187, messageCount = 1}
27/03/14 12:35:39 - [DEBUG,TransactionContext:290] Commit:
TX:ID:birch-34593-1395916847390-0:3:14187 syncCount: 1
27/03/14 12:35:39 - [DEBUG,Connection:4:55] SENDING: TransactionInfo
{commandId = 66469, responseRequired = true, type = 2, connectionId =
ID:birch-34593-1395916847390-0:3, transactionId =
TX:ID:birch-34593-1395916847390-0:3:14187}
27/03/14 12:35:39 - [DEBUG,Connection:4:60] RECEIVED: Response {commandId =
0, responseRequired = false, correlationId = 66469}
27/03/14 12:35:39 - [TRACE,TransactionSynchronizationManager:243] Removed
value
[org.springframework.jms.listener.LocallyExposedJmsResourceHolder@639e59c6]
for key [org.apache.activemq.pool.PooledConnectionFactory@7e83a12a] from
thread
[org.springframework.jms.listener.DefaultMessageListenerContainer#3-1]
27/03/14 12:35:39 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:2:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:2:1,started=true} }] did not receive a
message
27/03/14 12:35:39 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:2:1 Transaction Commit :null
27/03/14 12:35:39 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:4:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:4:1,started=true} }] did not receive a
message
27/03/14 12:35:39 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:4:1 Transaction Commit :null
27/03/14 12:35:39 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:6:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:6:1,started=true} }] did not receive a
message
27/03/14 12:35:39 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:6:1 Transaction Commit :null
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:5:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:5:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:1:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:1:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:1:1 Transaction Commit :null
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:0:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:0:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:0:1 Transaction Commit :null
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:3:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:3:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:3:1 Transaction Commit :null
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:2:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:2:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:2:1 Transaction Commit :null
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:4:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:4:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:4:1 Transaction Commit :null
27/03/14 12:35:40 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:6:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:6:1,started=true} }] did not receive a
message
27/03/14 12:35:40 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:6:1 Transaction Commit :null
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 9999 ms elapsed since last
write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:152] Message sent since last
write check, resetting flag
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 10000 ms elapsed since
last write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:134] No message sent since last
write check, sending a KeepAliveInfo
27/03/14 12:35:47 - [DEBUG,Connection:2:55] SENDING: KeepAliveInfo {}
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 10000 ms elapsed since
last write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:134] No message sent since last
write check, sending a KeepAliveInfo
27/03/14 12:35:47 - [DEBUG,Connection:3:55] SENDING: KeepAliveInfo {}
27/03/14 12:35:47 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:2:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:2:1,started=true} }] did not receive a
message
27/03/14 12:35:47 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:2:1 Transaction Commit :null
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 9999 ms elapsed since last
write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:152] Message sent since last
write check, resetting flag
27/03/14 12:35:47 - [DEBUG,Connection:1:60] RECEIVED: KeepAliveInfo {}
27/03/14 12:35:47 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:4:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:4:1,started=true} }] did not receive a
message
27/03/14 12:35:47 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:4:1 Transaction Commit :null
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 10000 ms elapsed since
last write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:152] Message sent since last
write check, resetting flag
27/03/14 12:35:47 - [TRACE,DefaultMessageListenerContainer:351] Consumer
[ActiveMQMessageConsumer { value=ID:birch-34593-1395916847390-0:6:1:1,
started=true }] of session [PooledSession { ActiveMQSession
{id=ID:birch-34593-1395916847390-0:6:1,started=true} }] did not receive a
message
27/03/14 12:35:47 - [DEBUG,ActiveMQSession:556]
ID:birch-34593-1395916847390-0:6:1 Transaction Commit :null
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 10000 ms elapsed since
last write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:152] Message sent since last
write check, resetting flag
27/03/14 12:35:47 - [DEBUG,InactivityMonitor:106] 10000 ms elapsed since
last write check.
27/03/14 12:35:47 - [TRACE,InactivityMonitor:152] Message sent since last
write check, resetting flag
27/03/14 12:35:47 - [DEBUG,Connection:2:60] RECEIVED: KeepAliveInfo {}
27/03/14 12:35:47 - [DEBUG,Connection:3:60] RECEIVED: KeepAliveInfo {}
I checked the open file descriptor and it looks fine.
There are no errors in the broker log files that I can see:
2014-03-27 12:35:39,210 | DEBUG | localhost removing consumer:
ID:birch-60203-1395842814608-1:187:1:13330 for destination:
queue://SendQueue | org.apache.activemq.broker.region.AbstractRegion |
ActiveMQ Transport: tcp:///127.0.0.1:39612@61616
2014-03-27 12:35:39,210 | DEBUG | queue://SendQueue remove sub:
QueueSubscription: consumer=ID:birch-60203-1395842814608-1:187:1:13330,
destinations=1, dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0,
dequeues: 0, dispatched: 0, inflight: 0 |
org.apache.activemq.broker.region.Queue | ActiveMQ Transport:
tcp:///127.0.0.1:39612@61616
2014-03-27 12:35:39,210 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Queue,destinationName=SendQueue,endpoint=Consumer,clientId=ID_birch-60203-1395842814608-0_188,consumerId=ID_birch-60203-1395842814608-1_188_1_13382
| org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport:
tcp:///127.0.0.1:39614@61616
2014-03-27 12:35:39,210 | DEBUG | localhost removing consumer:
ID:birch-60203-1395842814608-1:188:1:13382 for destination:
queue://SendQueue | org.apache.activemq.broker.region.AbstractRegion |
ActiveMQ Transport: tcp:///127.0.0.1:39614@61616
2014-03-27 12:35:39,210 | DEBUG | queue://SendQueue remove sub:
QueueSubscription: consumer=ID:birch-60203-1395842814608-1:188:1:13382,
destinations=1, dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0,
dequeues: 0, dispatched: 0, inflight: 0 |
org.apache.activemq.broker.region.Queue | ActiveMQ Transport:
tcp:///127.0.0.1:39614@61616
2014-03-27 12:35:39,210 | TRACE | Running task iteration 0 -
queue://SendQueue, subscriptions=10, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,210 | TRACE | Running task iteration 1 -
queue://SendQueue, subscriptions=9, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,210 | TRACE | Run task done: queue://SendQueue,
subscriptions=9, memory=0%, size=0, in flight groups=active message group
buckets: 0 | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,210 | TRACE | Running task iteration 0 -
queue://SendQueue, subscriptions=9, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,210 | TRACE | Run task done: queue://SendQueue,
subscriptions=9, memory=0%, size=0, in flight groups=active message group
buckets: 0 | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,211 | TRACE | ack:MessageAck {commandId = 66468,
responseRequired = false, ackType = 2, consumerId =
ID:birch-34593-1395916847390-0:3:1:1, firstMessageId =
ID:birch-60203-1395842814608-1:179:1:1:2050, lastMessageId =
ID:birch-60203-1395842814608-1:179:1:1:2050, destination =
queue://ReceiveQueue, transactionId =
TX:ID:birch-34593-1395916847390-0:3:14187, messageCount = 1, poisonCause =
null} | org.apache.activemq.broker.region.PrefetchSubscription | ActiveMQ
Transport: tcp:///127.0.0.1:48219@61616
2014-03-27 12:35:39,211 | TRACE | ack of
ID:birch-60203-1395842814608-1:179:1:1:2050 with MessageAck {commandId =
66468, responseRequired = false, ackType = 2, consumerId =
ID:birch-34593-1395916847390-0:3:1:1, firstMessageId =
ID:birch-60203-1395842814608-1:179:1:1:2050, lastMessageId =
ID:birch-60203-1395842814608-1:179:1:1:2050, destination =
queue://ReceiveQueue, transactionId =
TX:ID:birch-34593-1395916847390-0:3:14187, messageCount = 1, poisonCause =
null} | org.apache.activemq.broker.region.Queue | ActiveMQ Transport:
tcp:///127.0.0.1:48219@61616
2014-03-27 12:35:39,211 | TRACE | Running task iteration 0 -
queue://ReceiveQueue, subscriptions=1, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,211 | TRACE | Run task done: queue://ReceiveQueue,
subscriptions=1, memory=0%, size=0, in flight groups=active message group
buckets: 0 | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,212 | DEBUG | commit:
TX:ID:birch-34593-1395916847390-0:3:14187 syncCount: 4 |
org.apache.activemq.transaction.LocalTransaction | ActiveMQ Transport:
tcp:///127.0.0.1:48219@61616
2014-03-27 12:35:39,212 | DEBUG | localhost Message
ID:birch-34593-1395916847390-0:3:1:1:23903 sent to
queue://InvalidAcetechMessageQueue | org.apache.activemq.broker.region.Queue
| ActiveMQ Transport: tcp:///127.0.0.1:48219@61616
2014-03-27 12:35:39,213 | TRACE | Running task iteration 0 -
queue://InvalidAcetechMessageQueue, subscriptions=0, memory=4%, size=20, in
flight groups=null | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,213 | DEBUG | InvalidAcetechMessageQueue toPageIn: 20,
Inflight: 0, pagedInMessages.size 2601, enqueueCount: 2621, dequeueCount: 0
| org.apache.activemq.broker.region.Queue | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,213 | TRACE | Run task done:
queue://InvalidAcetechMessageQueue, subscriptions=0, memory=4%, size=20, in
flight groups=null | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-474
2014-03-27 12:35:39,213 | TRACE | Running task iteration 0 -
queue://ReceiveQueue, subscriptions=1, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,213 | TRACE | Running task iteration 1 -
queue://ReceiveQueue, subscriptions=1, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,213 | TRACE | Run task done: queue://ReceiveQueue,
subscriptions=1, memory=0%, size=0, in flight groups=active message group
buckets: 0 | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,236 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Queue,destinationName=SendQueue,endpoint=Consumer,clientId=ID_birch-60203-1395842814608-0_186,consumerId=ID_birch-60203-1395842814608-1_186_1_13322
| org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport:
tcp:///127.0.0.1:39573@61616
2014-03-27 12:35:39,237 | DEBUG | localhost removing consumer:
ID:birch-60203-1395842814608-1:186:1:13322 for destination:
queue://SendQueue | org.apache.activemq.broker.region.AbstractRegion |
ActiveMQ Transport: tcp:///127.0.0.1:39573@61616
2014-03-27 12:35:39,237 | DEBUG | queue://SendQueue remove sub:
QueueSubscription: consumer=ID:birch-60203-1395842814608-1:186:1:13322,
destinations=1, dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0,
dequeues: 0, dispatched: 0, inflight: 0 |
org.apache.activemq.broker.region.Queue | ActiveMQ Transport:
tcp:///127.0.0.1:39573@61616
2014-03-27 12:35:39,237 | TRACE | Running task iteration 0 -
queue://SendQueue, subscriptions=8, memory=0%, size=0, in flight
groups=active message group buckets: 0 |
org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,237 | TRACE | Run task done: queue://SendQueue,
subscriptions=8, memory=0%, size=0, in flight groups=active message group
buckets: 0 | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ
BrokerService[localhost] Task-467
2014-03-27 12:35:39,247 | DEBUG | localhost adding consumer:
ID:birch-60203-1395842814608-1:175:1:13296 for destination:
queue://SendQueue | org.apache.activemq.broker.region.AbstractRegion |
ActiveMQ Transport: tcp:///127.0.0.1:39634@61616
2014-03-27 12:35:39,248 | DEBUG | queue://SendQueue add sub:
QueueSubscription: consumer=ID:birch-60203-1395842814608-1:175:1:13296,
destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0,
dispatched: 0, inflight: 0 | org.apache.activemq.broker.region.Queue |
ActiveMQ Transport: tcp:///127.0.0.1:39634@61616
Is there anything else, the resources on the machine look fine.
--
View this message in context:
http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679582.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
