You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Robbie Gemmell (Jira)" <ji...@apache.org> on 2023/04/14 14:40:00 UTC
[jira] [Comment Edited] (ARTEMIS-4242) closing session with recent 'async acks' can lead to exceptions from apparent consumer cleanup race
[ https://issues.apache.org/jira/browse/ARTEMIS-4242?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17712421#comment-17712421 ]
Robbie Gemmell edited comment on ARTEMIS-4242 at 4/14/23 2:39 PM:
------------------------------------------------------------------
The above change isolates the test to stop other tests sporadically failing (i.e ARTEMIS-4082). It doesnt fix anything around the actual issue, this JIRA should remain open to track the issue.
was (Author: gemmellr):
The above change isolates the test to stop other tests sporadically failing (i.e ARTEMIS-4242). It doesnt fix anything around the actual issue, this JIRA should remain open to track the issue.
> closing session with recent 'async acks' can lead to exceptions from apparent consumer cleanup race
> ---------------------------------------------------------------------------------------------------
>
> Key: ARTEMIS-4242
> URL: https://issues.apache.org/jira/browse/ARTEMIS-4242
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: Broker
> Affects Versions: 2.28.0
> Reporter: Robbie Gemmell
> Priority: Major
>
> (Title is a little bit of a guess based on what a test is doing, the exceptions logged as a result, and the fact it poisoned a subsequent test).
> Closing a session with recent 'async acks' from using option 'blockOnAcknowledge=false' appears to lead to possible exceptions on the broker (snippet later), seemingly from a race between consumer cleanup during this, and processing of the previous acknowledgements.
> AcknowledgementTest.testNonBlockingAckPerf sends messages and then consumes them two seperate queues with 'blockOnAcknowledge=false' and 'blockOnAcknowledge=true' and compares duration. Invariably, it logs stacktraces like below during execution of this test (not obvious from default output, but is when turning on some debug instrumentation of which test is starting/stopping). After this happens, the test that follows would fail due to finding an extra message on a queue (queue1) they both used (this was reported in ARTEMIS-4082 against testDupsOKAcknowledgeQueue).
> Changing AcknowledgementTest.testNonBlockingAckPerf to closely inspect the counts after it is main work is finished, it then fails sporadically as or mroe often than it was causing testDupsOKAcknowledgeQueue to fail.
> Example output during failure in recent run: https://github.com/apache/activemq-artemis/actions/runs/4691971133/jobs/8317110969#step:5:33384
> {noformat}
> [Thread-0 (ActiveMQ-remoting-threads-ActiveMQServerImpl::name=localhost-195163481)] 17:20:43,422 WARN [org.apache.activemq.artemis.core.server] AMQ222061: Client connection failed, clearing up resources for session 855206e2-da1f-11ed-8303-000d3aa462b0
> [Thread-0 (ActiveMQ-remoting-threads-ActiveMQServerImpl::name=localhost-195163481)] 17:20:43,430 WARN [org.apache.activemq.artemis.core.server] AMQ222107: Cleared up resources for session 855206e2-da1f-11ed-8303-000d3aa462b0
> [Thread-7 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@fd46303)] 17:20:43,446 ERROR [org.apache.activemq.artemis.core.server] AMQ224016: Caught exception
> org.apache.activemq.artemis.api.core.ActiveMQIllegalStateException: AMQ229028: Consumer 0 doesn't exist on the server
> at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.findConsumer(ServerSessionImpl.java:1267) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.acknowledge(ServerSessionImpl.java:1234) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.onSessionAcknowledge(ServerSessionPacketHandler.java:762) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.onMessagePacket(ServerSessionPacketHandler.java:302) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.utils.actors.Actor.doTask(Actor.java:32) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> [Thread-7 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@fd46303)] 17:20:43,463 ERROR [org.apache.activemq.artemis.core.server] AMQ224016: Caught exception
> org.apache.activemq.artemis.api.core.ActiveMQIllegalStateException: AMQ229028: Consumer 0 doesn't exist on the server
> at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.findConsumer(ServerSessionImpl.java:1267) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.acknowledge(ServerSessionImpl.java:1234) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.onSessionAcknowledge(ServerSessionPacketHandler.java:762) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.onMessagePacket(ServerSessionPacketHandler.java:302) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.utils.actors.Actor.doTask(Actor.java:32) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> [Thread-7 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@fd46303)] 17:20:43,470 ERROR [org.apache.activemq.artemis.core.server] AMQ224016: Caught exception
> org.apache.activemq.artemis.api.core.ActiveMQIllegalStateException: AMQ229028: Consumer 0 doesn't exist on the server
> at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.findConsumer(ServerSessionImpl.java:1267) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.acknowledge(ServerSessionImpl.java:1234) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.onSessionAcknowledge(ServerSessionPacketHandler.java:762) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.protocol.core.ServerSessionPacketHandler.onMessagePacket(ServerSessionPacketHandler.java:302) ~[artemis-server-2.29.0-SNAPSHOT.jar:2.29.0-SNAPSHOT]
> at org.apache.activemq.artemis.utils.actors.Actor.doTask(Actor.java:32) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) ~[artemis-commons-2.29.0-SNAPSHOT.jar:?]
> ..etc etc etc..
> {noformat}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)