Wildfly messaging-activemq statistics
mleite Feb 17, 2020 1:18 PMHello there,
The issue described here is about a JEE7 application running on Wildfly-11.0.0-Final.
Basically, this application produces messages in a queue. This queue has a fixed number of consumers/MDBs (20) controlled by a custom pool. These MDB instances consume the messages and call a SLSB that is responsible for the business rules. The SLSB executes it's stuff and produces another message in another queue. It all happens in a XA transaction to enlist all steps in a single block.
All stuff works as it should, the messages are consumed, processed and all the workflow works.
However, I have been working a little bit on home-made tools to show some statistics of what is going on under the hood and I noticed some points.
1) For example, the system produces 50 messages. Each message has a specific processing runtime, varying from a few seconds until 60 minutes, according to the business rules. These messages are consumed by a pool of consumers sized of 20. In this case, only 20 messages will be immediately consumed and the other 30 will be kept in the queue. Using the jboss-cli command below, I can see that the total of the delivering-count is 50. I thought the delivering-count was the total of messages being already processed by one of the consumers, but if all consumers are "busy", why the delivering-count is the same as the message-count?
/subsystem=messaging-activemq/server=default/jms-queue=MyQueue:read-resource(include-runtime)
{
"outcome" => "success",
"result" => {
"consumer-count" => 20,
"dead-letter-address" => "jms.queue.DLQ",
"delivering-count" => 50,
"durable" => true,
"entries" => ["java:/jms/queue/MyQueue"],
"expiry-address" => "jms.queue.ExpiryQueue",
"legacy-entries" => undefined,
"message-count" => 50L,
"messages-added" => 50L,
"paused" => false,
"queue-address" => "jms.queue.MyQueue",
"scheduled-count" => 0L,
"selector" => undefined,
"temporary" => false
}
}
2) Another point is that using the CLI command below I can see that the same consumer is associated with more than one message, not at the same time, but it looks like the command output is showing a kind of history of what was already processed. Is that the expected behavior?
All the messages associated with that consumer were already processed at the time the CLI command ran.
{
"consumerName" => "ServerConsumer [id=b5c4f5b4-48f6-11ea-b8a6-b8ac6f1512b0:b5c51cca-48f6-11ea-b8a6-b8ac6f1512b0:0, filter=null, binding=LocalQueueBinding [address=jms.queue.MyQueue, queue=QueueImpl[name=jms.queue.MyQueue, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=af100a57-48f6-11ea-b8a6-b8ac6f1512b0]]@255302e8]]",
"elements" => [
{
"durable" => true,
"address" => "jms.queue.MyQueue",
"__AMQ_CID" => "f9cead79-5195-11ea-b8a6-b8ac6f1512b0",
"messageID" => 1782327,
"expiration" => 1581955057127L,
"type" => 2,
"priority" => 4,
"userID" => "ID:f9cead7c-5195-11ea-b8a6-b8ac6f1512b0",
"timestamp" => 1581951517127L -> 17/02/2020 11:58:37:127
},
{
"durable" => true,
"address" => "jms.queue.MyQueue",
"__AMQ_CID" => "0bf294e8-5197-11ea-b8a6-b8ac6f1512b0",
"messageID" => 1783259,
"expiration" => 1581955517058L,
"type" => 2,
"priority" => 4,
"userID" => "ID:0bf294eb-5197-11ea-b8a6-b8ac6f1512b0",
"timestamp" => 1581951977058L -> 17/02/2020 12:06:17:58
},
{
"durable" => true,
"address" => "jms.queue.MyQueue",
"__AMQ_CID" => "e34b5d71-5197-11ea-b8a6-b8ac6f1512b0",
"messageID" => 1784271,
"expiration" => 1581955878352L,
"type" => 2,
"priority" => 4,
"userID" => "ID:e34bab94-5197-11ea-b8a6-b8ac6f1512b0",
"timestamp" => 1581952338352L -> 17/02/2020 12:12:18:352
},
{
"durable" => true,
"address" => "jms.queue.MyQueue",
"__AMQ_CID" => "de2692c0-5198-11ea-b8a6-b8ac6f1512b0",
"messageID" => 1785126,
"expiration" => 1581956299218L,
"type" => 2,
"priority" => 4,
"userID" => "ID:de26b9d3-5198-11ea-b8a6-b8ac6f1512b0",
"timestamp" => 1581952759218L -> 17/02/2020 12:19:19:218
}
]
}
3) To finalize, it looks that, after some time, the queue message-count does not reflect exactly the amount of messages in the queue, it looks like is being kept a kind of cache or not accurate information. Do you know something related to that?
Thanks in advance,