You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@artemis.apache.org by "Justin Bertram (Jira)" <ji...@apache.org> on 2026/08/18 03:11:00 UTC
[jira] [Created] (ARTEMIS-6195) Log NoSuchElementException more clearly
Justin Bertram created ARTEMIS-6195:
---------------------------------------
Summary: 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
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,
_AMQ_ROUTE_TO$.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