You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@artemis.apache.org by "Anmol Saxena (Jira)" <ji...@apache.org> on 2026/09/09 10:16:00 UTC
[jira] [Commented] (ARTEMIS-6195) Log NoSuchElementException more clearly
[ https://issues.apache.org/jira/browse/ARTEMIS-6195?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18113262#comment-18113262 ]
Anmol Saxena commented on ARTEMIS-6195:
---------------------------------------
Hi [~jbertram] ,
Can I work on this ?
Thanks
> Log NoSuchElementException more clearly
> ---------------------------------------
>
> Key: ARTEMIS-6195
> URL: https://issues.apache.org/jira/browse/ARTEMIS-6195
> Project: Artemis
> Issue Type: Improvement
> Reporter: Justin Bertram
> Assignee: Justin Bertram
> Priority: Major
>
> Occasionally a cluster bridge failure might trigger logging like this:
> {noformat}
> 2026-07-21 09:34:19,901 WARN [org.apache.activemq.artemis.core.server] AMQ224143: Bridge $.artemis.internal.sf.my-cluster.db85c268-84d6-11f1-989c-0a580a81026c failed to send CoreMessage[messageID=323756, durable=true, userID=null, priority=0, timestamp=Tue Jul 21 09:34:19 GMT 2026, expiration=0, durable=true, address=testqueue, size=945, properties=TypedProperties[__AMQ_CID=camel-paho-f27c88a8-45ee-43ee-b5d8-45fe45987048, _AMQ_ROUTING_TYPE=0, mqtt.ordered.user.property.0.MQPERF_counter=7470, _AMQ_BRIDGE_DUP=[E7CC C414 84D6 11F1 AAEF 0A58 0A81 026D 0000 0000 0004 F0AC], mqtt.user.property.exists=2, mqtt.message.retain=false, mqtt.ordered.user.property.1.MQPERF_time=1784626459855, _AMQ_ROUTE_TO=[0000 0000 0000 0035], bytesAsLongs[53], mqtt.qos.level=1]]@1523062807: ActiveMQUnBlockedException AMQ219016: Connection failure detected. Unblocking a blocking call that will never get a response
> 2026-07-21 09:34:19,901 WARN [org.apache.activemq.artemis.core.server] AMQ224143: Bridge $.artemis.internal.sf.my-cluster.db85c268-84d6-11f1-989c-0a580a81026c failed to send CoreMessage[messageID=323748, durable=true, userID=null, priority=0, timestamp=Tue Jul 21 09:34:19 GMT 2026, expiration=0, durable=true, address=testqueue, size=945, properties=TypedProperties[__AMQ_CID=camel-paho-f27c88a8-45ee-43ee-b5d8-45fe45987048, _AMQ_ROUTING_TYPE=0, mqtt.ordered.user.property.0.MQPERF_counter=7467, _AMQ_BRIDGE_DUP=[E7CC C414 84D6 11F1 AAEF 0A58 0A81 026D 0000 0000 0004 F0A4], mqtt.user.property.exists=2, mqtt.message.retain=false, mqtt.ordered.user.property.1.MQPERF_time=1784626459853, _AMQ_ROUTE_TO=[0000 0000 0000 0035], bytesAsLongs[53], mqtt.qos.level=1]]@802935277: ActiveMQUnBlockedException AMQ219016: Connection failure detected. Unblocking a blocking call that will never get a response
> 2026-07-21 09:34:19,901 WARN [org.apache.activemq.artemis.core.server] AMQ224143: Bridge $.artemis.internal.sf.my-cluster.db85c268-84d6-11f1-989c-0a580a81026c failed to send CoreMessage[messageID=323771, durable=true, userID=null, priority=0, timestamp=Tue Jul 21 09:34:19 GMT 2026, expiration=0, durable=true, address=testqueue, size=945, properties=TypedProperties[__AMQ_CID=camel-paho-f27c88a8-45ee-43ee-b5d8-45fe45987048, _AMQ_ROUTING_TYPE=0, mqtt.ordered.user.property.0.MQPERF_counter=7472, _AMQ_BRIDGE_DUP=[E7CC C414 84D6 11F1 AAEF 0A58 0A81 026D 0000 0000 0004 F0BB], mqtt.user.property.exists=2, mqtt.message.retain=false, mqtt.ordered.user.property.1.MQPERF_time=1784626459855, _AMQ_ROUTE_TO=[0000 0000 0000 0035], bytesAsLongs[53], mqtt.qos.level=1]]@1125140974: ActiveMQUnBlockedException AMQ219016: Connection failure detected. Unblocking a blocking call that will never get a response
> 2026-07-21 09:34:19,903 WARN [org.apache.activemq.artemis.core.server] AMQ224143: Bridge $.artemis.internal.sf.my-cluster.db85c268-84d6-11f1-989c-0a580a81026c failed to send CoreMessage[messageID=323765, durable=true, userID=null, priority=0, timestamp=Tue Jul 21 09:34:19 GMT 2026, expiration=0, durable=true, address=testqueue, size=945, properties=TypedProperties[__AMQ_CID=camel-paho-f27c88a8-45ee-43ee-b5d8-45fe45987048, _AMQ_ROUTING_TYPE=0, mqtt.ordered.user.property.0.MQPERF_counter=7473, _AMQ_BRIDGE_DUP=[E7CC C414 84D6 11F1 AAEF 0A58 0A81 026D 0000 0000 0004 F0B5], mqtt.user.property.exists=2, mqtt.message.retain=false, mqtt.ordered.user.property.1.MQPERF_time=1784626459856, _AMQ_ROUTE_TO=[0000 0000 0000 0035], bytesAsLongs[53], mqtt.qos.level=1]]@79593320: ActiveMQUnBlockedException AMQ219016: Connection failure detected. Unblocking a blocking call that will never get a response
> 2026-07-21 09:34:19,874 WARN [org.apache.activemq.artemis.core.server] AMQ222094: Bridge unable to send message Reference[323774]:RELIABLE:CoreMessage[messageID=323774, durable=true, userID=null, priority=0, timestamp=Tue Jul 21 09:34:19 GMT 2026, expiration=0, durable=true, address=testqueue, size=1020, properties=TypedProperties[__AMQ_CID=camel-paho-f27c88a8-45ee-43ee-b5d8-45fe45987048, _AMQ_ROUTING_TYPE=0, mqtt.ordered.user.property.0.MQPERF_counter=7475, mqtt.user.property.exists=2, mqtt.message.retain=false, $.artemis.internal.sf.my-cluster.db85c268-84d6-11f1-989c-0a580a81026c=[0000 0000 0000 0035], bytesAsLongs[53], mqtt.ordered.user.property.1.MQPERF_time=1784626459858, mqtt.qos.level=1]]@1892606528, will try again once bridge reconnects
> org.apache.activemq.artemis.api.core.ActiveMQObjectClosedException: AMQ219018: Producer is closed
> at org.apache.activemq.artemis.core.client.impl.ClientProducerImpl.checkClosed(ClientProducerImpl.java:305)
> at org.apache.activemq.artemis.core.client.impl.ClientProducerImpl.send(ClientProducerImpl.java:122)
> at org.apache.activemq.artemis.core.server.cluster.impl.BridgeImpl.deliverStandardMessage(BridgeImpl.java:800)
> at org.apache.activemq.artemis.core.server.cluster.impl.BridgeImpl.handle(BridgeImpl.java:659)
> at org.apache.activemq.artemis.core.server.impl.QueueImpl.handle(QueueImpl.java:3923)
> at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliver(QueueImpl.java:3051)
> at org.apache.activemq.artemis.core.server.impl.QueueImpl$DeliverRunner.run(QueueImpl.java:4230)
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:59)
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:69)
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:120)
> 2026-07-21 09:34:19,907 WARN [org.apache.activemq.artemis.core.server] AMQ222095: Connection failed with failedOver=false
> 2026-07-21 09:34:19,909 WARN [org.apache.activemq.artemis.core.server.impl.QueueImpl] null
> java.util.NoSuchElementException
> at org.apache.activemq.artemis.utils.collections.PriorityLinkedListImpl$PriorityLinkedListIterator.repeat(PriorityLinkedListImpl.java:233)
> at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliver(QueueImpl.java:3074)
> at org.apache.activemq.artemis.core.server.impl.QueueImpl$DeliverRunner.run(QueueImpl.java:4230)
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:59)
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:69)
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:120){noformat}
> This seems kind of scary and might be interpreted as causing some kind of message loss. However, the {{NoSuchElementException}} is a known-but-harmless race caused by reentrant synchronization in the delivery loop. Here's the sequence:
> # {{QueueImpl.deliver()}} acquires the {{QueueImpl.this}} monitor and iterates the message list via {{holderIterator}}
> # It calls {{BridgeImpl.handle()}} which tries {{producer.send()}} which this throws because the connection just died
> # The bridge's exception handler synchronously calls {{connectionFailed()}} → {{fail()}} → {{queue.removeConsumer(this)}}, which closes the iterator (sets {{lastIter = null}})
> # Because Java monitors are reentrant, {{removeConsumer()}} succeeds even though the delivery thread already holds the lock
> # Control returns to {{deliver()}}, which sees {{BUSY}} status and calls {{holderIterator.repeat()}}, but the iterator has been closed out from under it, so {{repeat()}} throws {{NoSuchElementException}}
> There's a try-catch specifically for this scenario already in the code. The exception is logged as a warning (the {{null}} is because it logs {{e.getMessage()}} which is {{null}} for a bare {{NoSuchElementException}}), and the delivery loop continues normally. The bridge reconnects and resumes forwarding.
> We should look at improving this logging so it's clear there's no real problem.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@artemis.apache.org
For additional commands, e-mail: issues-help@artemis.apache.org