[
https://issues.apache.org/jira/browse/ARTEMIS-4095?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17736122#comment-17736122
]
Artyom Tarasenko commented on ARTEMIS-4095:
-------------------------------------------
Looking further into the issue. I turned on debugging, and initially it doesn't
show anything suspicious:
2023-06-22 11:50:37,376 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0
Then I looked up how d06459df5 (ARTEMIS-3943) calculates needsDepage() :
if (... && (queueMemorySize.getSize() + deliveringMetrics.getPersistentSize())
< maxReadBytes) && ...)
The deliveringMetrics.getPersistentSize is crucial for the decision, but is
not logged by default, so I added it to the logging:
{code:java}
---
a/artemis-server/src/main/java/org/apache/activemq/artemis/core/server/impl/QueueImpl.java
+++
b/artemis-server/src/main/java/org/apache/activemq/artemis/core/server/impl/QueueImpl.java
@@ -4598,1 +4598,1 @@ public class QueueImpl extends CriticalComponentImpl
implements Queue {
- logger.debug("Queue Memory Size after depage on queue=" +
this.getName() + " is " + queueMemorySize.getSize() + " with maxSize = " +
maxSize + ". Depaged " + depaged + " messages, pendingDelivery=" +
messageReferences.size() + ", intermediateMessageReferences= " +
intermediateMessageReferences.size() + ", queueDelivering=" +
deliveringMetrics.getMessageCount());
+ logger.debug("Queue Memory Size after depage on queue=" +
this.getName() + " is " + queueMemorySize.getSize() + " with maxSize = " +
maxSize + ". Depaged " + depaged + " messages, pendingDelivery=" +
messageReferences.size() + ", intermediateMessageReferences= " +
intermediateMessageReferences.size() + ", queueDelivering=" +
deliveringMetrics.getMessageCount()+ ", delivering Persistent=" +
deliveringMetrics.getPersistentSize());{code}
and now the real reason is visible:
{noformat}
2023-06-22 13:29:36,261 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 9771 with maxSize = 10485760.
Depaged 1 messages, pendingDelivery=0, intermediateMessageReferences= 1,
queueDelivering=229, delivering Persistent=20962487
2023-06-22 13:29:36,261 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 9771 with maxSize = 10485760.
Depaged 1 messages, pendingDelivery=0, intermediateMessageReferences= 1,
queueDelivering=230, delivering Persistent=20969077
2023-06-22 13:29:36,372 INFO [org.apache.activemq.artemis.core.server]
AMQ224108: Stopped paging on address 'test-channel'; size=0 bytes (0 messages);
maxSize=-1 bytes (-1 messages); globalSize=0 bytes (0 messages);
globalMaxSize=419430400 bytes (-1 messages);
2023-06-22 13:29:58,667 INFO [org.apache.activemq.artemis.core.server]
AMQ222038: Starting paging on address 'test-channel'; size=419678295 bytes
(42647 messages); maxSize=-1 bytes (-1 messages); globalSize=419678295 bytes
(42647 messages); globalMaxSize=419430400 bytes (-1 messages);
2023-06-22 13:31:07,394 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
2023-06-22 13:31:37,369 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
2023-06-22 13:32:07,369 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
2023-06-22 13:32:37,369 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
2023-06-22 13:33:07,370 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
2023-06-22 13:33:37,370 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
2023-06-22 13:34:07,370 DEBUG
[org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue Memory Size
after depage on queue=test-queue#test-channel is 0 with maxSize = 10485760.
Depaged 0 messages, pendingDelivery=0, intermediateMessageReferences= 0,
queueDelivering=0, delivering Persistent=24266844
{noformat}
deliveringMetrics.getPersistentSize() seems to be not always decremented after
the messages are consumed with an OpenWire RA-consumer. And once it reaches
the threshold, Artemis doesn't depage anymore. What is this value?
> OpenWire clients are unable to consume from mutlicast queue after 2nd paging
> ----------------------------------------------------------------------------
>
> Key: ARTEMIS-4095
> URL: https://issues.apache.org/jira/browse/ARTEMIS-4095
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: OpenWire
> Affects Versions: 2.26.0, 2.27.0, 2.27.1, 2.28.0, 2.29.0
> Environment: Artemis, deployed through the official docker image in
> version {{2.26.0}} in an OpenShift cluster
> Reporter: Marco Bungart
> Priority: Major
> Attachments: artemis-Xmx1G.png, artemis-Xmx2G.png, graph1.png,
> graph2.png, jmeter-orders-6500-localhost.jmx, jmsconsumer-1.0-SNAPSHOT.jar
>
>
> I observed that after artemis went into paging for the 2nd time, OpenWire
> clients were not able to read messages from their corresponding addresses.
> Restarting the applications connected as clients does not fix the issue.
> Restarting artemis, however, does fix the issue.
> Both images attached show the messages of two queues.
> - The upper (orange) line in the 1st graph shows count of messages in a queue
> to which core clients are connected.
> - The lower (blue) line in the 1stg raph shows count of messages in a queue
> to which OpenWire clients are connected.
> - in the 2nd graph, the upper (violet) line shows count of messages in a
> queue to which core clients are connected.
> - in the 2nd graph, the lower (green) line shows count of messages in a queue
> to which OpenWire clients are connected.
> I have a heap dump that we could share, showing the accumulated objects. the
> dump is about 90 MB in size If this would be helpful to have, please let me
> know.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
