Messages stuck in queue 5.9.0

classic Classic list List threaded Threaded
20 messages Options
Reply | Threaded
Open this post in threaded view
|

Messages stuck in queue 5.9.0

lookers
Hi,

I am having an issue with messages not being consumed in a queue with no errors generated.
Restart of the broker resolves the issue.

I was wondering of you could point me direction on how to resolve the issue.

Here is my configuration file:

<beans
  xmlns="http://www.springframework.org/schema/beans"
  xmlns:amq="http://activemq.apache.org/schema/core"
  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd
  http://activemq.apache.org/schema/core http://activemq.apache.org/schema/core/activemq-core.xsd">

    <bean class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
        <property name="locations">
            <value>file:${activemq.conf}/credentials.properties</value>
        </property>
    </bean>

    
    <broker xmlns="http://activemq.apache.org/schema/core" brokerName="localhost" dataDirectory="${activemq.data}">

      

        <destinationPolicy>
            <policyMap>
              <policyEntries>
                <policyEntry topic=">" producerFlowControl="true">
                    
                  <pendingMessageLimitStrategy>
                    <constantPendingMessageLimitStrategy limit="1000"/>
                  </pendingMessageLimitStrategy>
                </policyEntry>
                <policyEntry queue=">" producerFlowControl="false" >
                 
<deadLetterStrategy>

           <individualDeadLetterStrategy
              queuePrefix="DLQ." useQueueForQueueMessages="true" processNonPersistent="true"/>
            </deadLetterStrategy>
                </policyEntry>
              </policyEntries>
            </policyMap>
        </destinationPolicy>


     
        <managementContext>
            <managementContext createConnector="false"/>
        </managementContext>

        
        <persistenceAdapter>
            <kahaDB directory="${activemq.data}/kahadb"/>
        </persistenceAdapter>

  <transportConnectors>
            <transportConnector name="openwire" uri="tcp://0.0.0.0:61616?maximumConnections=1000&amp;wireFormat.maxFrameSize=104857600"/>
            <transportConnector name="amqp" uri="amqp://0.0.0.0:5672?maximumConnections=1000&amp;wireFormat.maxFrameSize=104857600"/>
<transportConnector name="stomp" uri="stomp://0.0.0.0:61612?transport.closeAsync=false"/>

        </transportConnectors>

        <shutdownHooks>
            <bean xmlns="http://www.springframework.org/schema/beans" class="org.apache.activemq.hooks.SpringContextHook" />
        </shutdownHooks>

    </broker>

    
    <import resource="jetty.xml"/>

</beans>


The queue normally consumes 100K to 150K messages per day.


There is only one producer and one consumer, all on the same host.



Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

gtully
is the inflight count 0 in the jconsole jmx view for your consumer?

enable trace level logging for org.apache.activemq.broker in log4j and
use jmx to have it refresh the log4j config - a broker operation.

send another message to that dest and see what is in the logs.

in other words, jmx and logging will help you understand what is going on.



On 20 March 2014 10:52, colm loughnane <[hidden email]> wrote:

> Hi,
>
> I am having an issue with messages not being consumed in a queue with no
> errors generated.
> Restart of the broker resolves the issue.
>
> I was wondering of you could point me direction on how to resolve the issue.
>
> Here is my configuration file:
>
>
>
>
> The queue normally consumes 100K to 150K messages per day.
>
>
> There is only one producer and one consumer, all on the same host.
>
>
>
>
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://redhat.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
This post was updated on .
Hi gtully

Here is a line in the logs with
ReceiveQueue toPageIn: 200, Inflight: 0, pagedInMessages.size 0, enqueueCount: 120149, dequeueCount: 113644 | org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[localhost] Task-619

This was when the messages are stuck

Does this give you any ideas?

sorry just spotted that you need the inlfight of the consumer, I will investigate this

Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

gtully
that looks fine. Is there a ttl on the messages, anything in the DLQ?
Can you browse the messages via jmx?

On 20 March 2014 14:36, lookers <[hidden email]> wrote:

> Hi gtully
>
> Here is a line in the logs with
> ReceiveQueue toPageIn: 200, Inflight: 0, pagedInMessages.size 0,
> enqueueCount: 120149, dequeueCount: 113644 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[localhost]
> Task-619
>
> This was when the messages are stuck
>
> Does this give you any ideas?
>
>
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679285.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://redhat.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers

There is no ttl on the messages. I have not tried browsing with JMS when they are stuck. I can try that when it fails again
No there is nothing in the DLQ for this queue.
It is happening quiet regularly. At lease twice a day. I have similar environment set up of different instance and it does not behave like this.




Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

gtully
any message selectors?
Is it just one consumer that does not get messages? Are they stomp/operwire?


I think the best bet to understand what is going is to capture full
trace logging.
Also trace=true on the openwire  (or relevant) tcp transport url.
Possibly a broker side thread dump. Any chance the os is low on file
descriptors?


On 20 March 2014 15:07, lookers <[hidden email]> wrote:

>
> There is no ttl on the messages. I have not tried browsing with JMS when
> they are stuck. I can try that when it fails again
> No there is nothing in the DLQ for this queue.
> It is happening quiet regularly. At lease twice a day. I have similar
> environment set up of different instance and it does not behave like this.
>
>
>
>
>
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679287.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://redhat.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
This post was updated on .
There are no message selectors on this queue. There are on others, but they are processed in a different thread.
There is just one consumer and it consumes messages in FIFO manner.

they are consumed using spring jms template.
the consumer is using a pooled connection

Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
In reply to this post by gtully
Hi,
I am unable to view messages in the queue through the JMX console when it is stuck
I can browse  other queues in the same broker though.

lookers
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
This post was updated on .
In reply to this post by gtully
Hi,
Please find attached a log file and thread dump of the incident. The freeze happens around 08:13:51.


I am using openwire to connect to the broker
 failover:(tcp://localhost:2345,tcp://localhost:2345)?initialReconnectDelay=100&randomize=false

and consumer url

tcp://localhost:2345

activemq.log.zip

stack.sh.zip

thanks for your help
lookers
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
In reply to this post by gtully
Hi gtully
where do you put the trace = true parameter. Is it on the consumer?

Regards
lookers
 
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

gtully
On a tcp transport url, client or broker.
tcp://localhost:2345?trace=true

If broker side all commands are logged. If client side it is per connection
in the clients log.
On 26 Mar 2014 09:09, "lookers" <[hidden email]> wrote:

> Hi gtully
> where do you put the trace = true parameter. Is it on the consumer?
>
> Regards
> lookers
>
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679528.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

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




Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

artnaseef
I recommend taking a step back and looking at a few fundamentals.

First, how are unconsumed messages on the queue detected?  The following seems to indicate there are none (pagedInMessage.size 0):

{noformat}
ReceiveQueue toPageIn: 200, Inflight: 0, pagedInMessages.size 0, enqueueCount: 120149, dequeueCount: 113644 | org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[localhost] Task-619
{noformat}

Note that enqueue and dequeue counts are useful, but I have seen them be misleading in the past.  For example, purging the queue may leave those numbers out-of-sync.

What does the JMX setting QueueSize say for the queue?

Also, does restarting the broker cause messages to be consumed that were previously unconsumed?

Note that if JMX cannot browse the messages, they either aren't there, or their TTLs have expired (I haven't checked the latter to see if expired TTLs will prevent messages from showing up via JMX).
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers

Hi Artnaseef,

Unconsumed messages are detected with the application which is time sensitive is not updating.

I am sure that there is data in the queue. When blocked for a period of time the enqueue will increase until the broker is restarted. The data payload is time stamped to I can tell that it is historic data when the application processes the data after the reset.

The ttl is not set on these message so it is default, which is unlimited.
Yes restarting the broker resumes progressing and previous unconsumed messages are consumed.

Not to sure what the jmx QueueSize is but it I can tell from the admin console that the enqueue is  increasing when  stuck

Thanks
lookers
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

artnaseef
That helps.  Is this a network of brokers?  Are clients using transactions?

In addition to the diagnostics Gary mentioned, grabbing a stack trace when
this happens may be helpful.

Are JMSXGroups in-use?

Also, are the producers using the failover transport, or using any other
technology that might hold and resend messages after a broker restart?

If you can reproduce this easily with a minimal test case, then I'll give
it a try.

>
>
>
> Hi Artnaseef,
>
> Unconsumed messages are detected with the application which is time
> sensitive is not updating.
>
> I am sure that there is data in the queue. When blocked for a period of
> time
> the enqueue will increase until the broker is restarted. The data payload
> is
> time stamped to I can tell that it is historic data when the application
> processes the data after the reset.
>
> The ttl is not set on these message so it is default, which is unlimited.
> Yes restarting the broker resumes progressing and previous unconsumed
> messages are consumed.
>
> Not to sure what the jmx QueueSize is but it I can tell from the admin
> console that the enqueue is  increasing when  stuck
>
> Thanks
> lookers
>
>
>
> _______________________________________________
> If you reply to this email, your message will be added to the discussion
> below:
> http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679607.html
> To start a new topic under ActiveMQ - User, email
> [hidden email]
> To unsubscribe from ActiveMQ - User, visit
>
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
Thanks again Artnaseef,
Just to answer your questions:

no it is not a network of  brokers. Standalone broker,producer,consumer.
The producers is using failover in the connection URL. Yes the messages are persistent and use transactions.
No, I'm not using JMSXGroups.

I think that I posted a stack trace when it happens in a previous post. I have updated the configuration to what is above to
handle by adding <conditionalNetworkBridgeFilterFactory replayWhenNoConsumers="true" />, because of issue seen before however this has not helped.

I am not sure I can create a test case, it does not seem to be deterministic.  Have you any hints for this. Or is it a matter of processing same data from one fail to the next?

Regards
lookers
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

lookers
Just checked the queuesize and it is increasing when it is blocked.
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

SuoNayi
Can you try to disable cache consumer option?
Or can you use a plain jms consumer to try to reproduce the issue?
Just guess it's maybe related with cache consumer and spring jms template.


2014-03-29 4:19 GMT+08:00 lookers <[hidden email]>:

> Just checked the queuesize and it is increasing when it is blocked.
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679651.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

gtully
two config options to disable some (possibly related) thread
complexity broker side:

               <policyEntry queue=">" ... expireMessagesPeriod="0">
               <kahaDB ... concurrentStoreAndDispatchQueues="false" />

On 4 April 2014 03:48, Yin Wang <[hidden email]> wrote:

> Can you try to disable cache consumer option?
> Or can you use a plain jms consumer to try to reproduce the issue?
> Just guess it's maybe related with cache consumer and spring jms template.
>
>
> 2014-03-29 4:19 GMT+08:00 lookers <[hidden email]>:
>
>> Just checked the queuesize and it is increasing when it is blocked.
>>
>>
>>
>> --
>> View this message in context:
>> http://activemq.2283324.n4.nabble.com/Messages-stuck-in-queue-5-9-0-tp4679266p4679651.html
>> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>>



--
http://redhat.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: Messages stuck in queue 5.9.0

artnaseef
In reply to this post by artnaseef
In JMX, can you see the subscriptions?  Are they growing at all?  Are the numbers of subscriptions consistent with the numbers expected?

One thing that may help - check the stack traces on the broker and clients.  Things to look for: are there consumer threads active on the clients?  Is the broker actively attempting to send messages.

I took a brief look at the trace, and it seems to indicate the clients are broker are both processing, but it would require a more thorough review of the code and the log messages to be sure just what information they have to offer.

Another thing to try: once flow stops, add another consumer, preferrably a plain JMS client that simply reports what it receives.  If such a consumer receives messages, that points to a problem specific to the existing consumers.  If such a consumer does not receive messages, that points to a problem with dispatching.

I would love to dig into this in more depth.  Just not sure I have the time at the moment.

By the way - are there any other symptoms which seem out of place, but which may not appear related?