Our environment consists of 3 jboss servers(portal,jms,reconciliation).
- Reconciliation server hosts camel routes which has a Route consuming from queue(SLAQueue).
- JMS server has all our queues hosted.
- Recently we identified a bug where some of messages in TaskQueue hosted on JMS server are not being delivered to MDB's on portal server. For some reason they are stuck and when we restart the JMS server the stuck messages are delivered.
To investigate we enabled TRACE level logging on "org.apache.activemq.artemis". We are noticing lot of chatter between our camel jms component and JMS server. One instance of chatter is listed below, logs like these get written every 1 second.
Questions :
- What is the mechanism camel jms component uses to get messages from queue? Does JMS component poll the queue every second(pull) ? or JMS component gets notified when the message arrives in the queue ?
- Is the mechanism different from J2EE Message driven beans? The MDB' get notified when the message arrives in the queue.
- Based on the chatter below i think it is polling. If it is polling can the polling window be configured ? I have tried receiveTimeout option with no luck.
**Example chatter in the logs between camel JMS component and JMS server : **
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) createdConsumer ActiveMQSession->ClientSessionImpl [name=eebaf2ec-47b3-11ec-ad21-0242ac110003, username=null, closed=false, factory = org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl@413c962e, metaData=(jms-session=,)]@72d15942 consumer=org.apache.activemq.artemis.ra.ActiveMQRAMessageConsumer@1dd2e8b
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) addConsumer(org.apache.activemq.artemis.ra.ActiveMQRAMessageConsumer@1dd2e8b)
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl] (Thread-206 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=b5ba8675-1a62-11ec-b397-0242ac110002-1886035738)) RemotingConnectionID=eeb5e9d6-47b3-11ec-ad21-0242ac110003 handling packet PACKET(SessionConsumerFlowCreditMessage)[type=70, channelID=12, responseAsync=false, requiresResponse=false, correlationID=-1, packetObject=SessionConsumerFlowCreditMessage, consumerID=5086, credits=1048576]
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) unlock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.remoting.impl.invm.InVMConnection] (Thread-206 (ActiveMQ-remoting-threads-ActiveMQServerImpl::serverUUID=b5ba8675-1a62-11ec-b397-0242ac110002-1886035738)) InVMConnection [serverID=0, id=eeb5e9d6-47b3-11ec-ad21-0242ac110003]::packet sent done
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) unlock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) lock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) tryLock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) getUseTryLock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) getUseTryLock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) lock()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) receive org.apache.activemq.artemis.ra.ActiveMQRAMessageConsumer@1dd2e8b timeout=120000
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.ra] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) checkState()
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl@5e7ed34b{consumerContext=ActiveMQConsumerContext{id=5086}, queueName=jms.queue.SLAQueue}:: receive(120000)
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl] (Camel (camelContextReconciliation) thread #0 - JmsConsumer[SLAQueue]) org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl@5e7ed34b{consumerContext=ActiveMQConsumerContext{id=5086}, queueName=jms.queue.SLAQueue}::receive(120000, false)
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler] (Thread-1288 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@775fa129)) ServerSessionPacketHandler::handlePacket,PACKET(SessionConsumerFlowCreditMessage)[type=70, channelID=12, responseAsync=false, requiresResponse=false, correlationID=-1, packetObject=SessionConsumerFlowCreditMessage, consumerID=5086, credits=1048576]
2021-11-17 16:39:24,612 DEBUG [org.apache.activemq.artemis.core.server.impl.ServerConsumerImpl] (Thread-1288 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@775fa129)) ServerConsumerImpl [id=5086, filter=null, binding=LocalQueueBinding [address=jms.queue.SLAQueue, queue=QueueImpl[name=jms.queue.SLAQueue, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=b5ba8675-1a62-11ec-b397-0242ac110002], temp=false]@3b0e1e9f, filter=null, name=jms.queue.SLAQueue, clusterName=jms.queue.SLAQueueb5ba8675-1a62-11ec-b397-0242ac110002]]::FlowControl::Received 1048576 credits, previous value = 0 currentValue = 1048576
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.server.impl.ServerConsumerImpl] (Thread-1288 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@775fa129)) ServerConsumerImpl [id=5086, filter=null, binding=LocalQueueBinding [address=jms.queue.SLAQueue, queue=QueueImpl[name=jms.queue.SLAQueue, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=b5ba8675-1a62-11ec-b397-0242ac110002], temp=false]@3b0e1e9f, filter=null, name=jms.queue.SLAQueue, clusterName=jms.queue.SLAQueueb5ba8675-1a62-11ec-b397-0242ac110002]]::calling promptDelivery from receiving credits
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler] (Thread-1288 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@775fa129)) ServerSessionPacketHandler::scheduling response::null
2021-11-17 16:39:24,612 TRACE [org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler] (Thread-1288 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@775fa129)) ServerSessionPacketHandler::regular response sent::null
