[jira] [Created] (ARTEMIS-4045) AMQ224041: Failed to deliver in mirror

["Stephen Baker (Jira)" <ji...@apache.org>]

Stephen Baker created ARTEMIS-4045:
--------------------------------------

             Summary: AMQ224041: Failed to deliver in mirror
                 Key: ARTEMIS-4045
                 URL: https://issues.apache.org/jira/browse/ARTEMIS-4045
             Project: ActiveMQ Artemis
          Issue Type: Bug
            Reporter: Stephen Baker


I saw the following stack trace when running artemis 2.25 to artemis 2.25 in a dual mirror configuration with docker instances.

The side that has the error is the only side running the message expiry scan.

Messages were added to the other side through JMS with a short (10s) expiry.
{code:java}
artemis-test-artemis-1-m-1   | 2022-10-12 22:02:13,468 ERROR [org.apache.activemq.artemis.core.server] AMQ224041: Failed to deliver: java.lang.IllegalStateException: this method requires to be called within the handler, use the executor
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.requireHandler(ProtonHandler.java:210) [artemis-amqp-protocol-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.protocol.amqp.proton.AMQPConnectionContext.requireInHandler(AMQPConnectionContext.java:197) [artemis-amqp-protocol-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.protocol.amqp.proton.ProtonAbstractReceiver.settle(ProtonAbstractReceiver.java:185) [artemis-amqp-protocol-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.protocol.amqp.connect.mirror.AMQPMirrorControllerTarget$ACKMessageOperation.run(AMQPMirrorControllerTarget.java:125) [artemis-amqp-protocol-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.protocol.amqp.connect.mirror.AMQPMirrorControllerTarget.performAck(AMQPMirrorControllerTarget.java:388) [artemis-amqp-protocol-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.protocol.amqp.connect.mirror.AMQPMirrorControllerTarget.lambda$performAck$2(AMQPMirrorControllerTarget.java:377) [artemis-amqp-protocol-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.core.server.impl.QueueImpl$2.skipDelivery(QueueImpl.java:1203) [artemis-server-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.core.server.impl.QueueImpl.doInternalPoll(QueueImpl.java:2932) [artemis-server-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliver(QueueImpl.java:2991) [artemis-server-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.core.server.impl.QueueImpl$DeliverRunner.run(QueueImpl.java:4250) [artemis-server-2.25.0.jar:2.25.0]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:56) [artemis-commons-2.25.0.jar:]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.25.0.jar:]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:67) [artemis-commons-2.25.0.jar:]
artemis-test-artemis-1-m-1   |     at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [java.base:]
artemis-test-artemis-1-m-1   |     at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [java.base:]
artemis-test-artemis-1-m-1   |     at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.25.0.jar:]
artemis-test-artemis-1-m-1   |{code}
I believe the stack may be enough to diagnose the issue. It's very specifically calling run directly where all the other code paths run it through an executor, and the error says that it can't be run directly.

 

From AMQPMirrorControllerTarget
{code:java}
switch (retry) {
   case 0:
      // first retry, after IO Operations
      sessionSPI.getSessionContext().executeOnCompletion(new RunnableCallback(() -> performAck(nodeID, messageID, targetQueue, ackMessageOperation, reason, (short) 1)));
      return;
   case 1:
      // second retry after the queue is flushed the temporary adds
      targetQueue.flushOnIntermediate(() -> {
         recoverContext();
         performAck(nodeID, messageID, targetQueue, ackMessageOperation, reason, (short)2);
      });
      return;
   case 2:
      // third retry, on paging
      if (reason != AckReason.EXPIRED) {
         // if expired, we don't need to check on paging
         // as the message will expire again when depaged (if on paging)
         performAckOnPage(nodeID, messageID, targetQueue, ackMessageOperation);
         return;
      } else {
         ackMessageOperation.run();
      }
} {code}
I'm not sure which is the right executor though. Nor do I have any insight why it's on the 3rd retry.



--
This message was sent by Atlassian Jira
(v8.20.10#820010)