[ARTEMIS-4307] AMQP Artemis "hangs" on single message delivery

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Cannot Reproduce
• Affects Version/s: 2.28.0
• Component/s: AMQP
• Assignee: Unassigned
• Reporter: daves
• Created: 09/Jun/23 13:33
• Updated: 11/Apr/24 17:49
• Resolved: 11/Apr/24 17:49

Description

My Setup:

• Multiple clients ~500 send messages to a queue in Artemis using AMQP
• A single application reads consumes the messages from the queue using AMQP

At some point - I sadly don't know how to reproduce it - my consuming client does not receive messages anymore.

From the perspective of my client the call to receiving new messages (AMQP.NET lite) just hands/waits for messages and never returns. Also, It still looks like the connection is open and healthy.

On the Artemis side I see two different pictures.

• In the Broker console I can see a consumer from my client, and it tells me that 1 Messages is in Transit. ...as if Artemis is waiting for an ACK for the message.

In the Artemis log is see this: 

2023-06-09 15:11:37,934 WARN  [org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext] Array must not be empty or null
java.lang.IllegalArgumentException: Array must not be empty or null
    at org.apache.qpid.proton.codec.CompositeReadableBuffer.append(CompositeReadableBuffer.java:691) ~[proton-j-0.34.0.jar:?]
    at org.apache.qpid.proton.engine.impl.DeliveryImpl.send(DeliveryImpl.java:345) ~[proton-j-0.34.0.jar:?]
    at org.apache.qpid.proton.engine.impl.SenderImpl.send(SenderImpl.java:74) ~[proton-j-0.34.0.jar:?]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext$LargeMessageDeliveryContext.deliverInitialPacket(ProtonServerSenderContext.java:715) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext$LargeMessageDeliveryContext.deliver(ProtonServerSenderContext.java:622) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.deliverLarge(ProtonServerSenderContext.java:837) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.executeDelivery(ProtonServerSenderContext.java:567) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.core.paging.cursor.PagedReferenceImpl.run(PagedReferenceImpl.java:116) ~[artemis-server-2.28.0.jar:2.28.0]
    at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) ~[artemis-commons-2.28.0.jar:?]
2023-06-09 15:11:37,934 WARN  [org.apache.activemq.artemis.core.server] AMQ222151: removing consumer which did not handle a message, consumer=ServerConsumerImpl [id=3, filter=null, binding=LocalQueueBinding [address=MyQName, queue=QueueImpl[name=MyQName, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::name=MyApp], temp=false]@776d381a, filter=null, name=MyQName, clusterName=MyQName431ed7e1-05dd-11ee-ade9-f44d30e2ecf9]], message=PagedReferenceImpl [message=PagedMessageImpl [queueIDs=[47], transactionID=-1, page=25, message=AMQPLargeMessage( [durable=false, messageID=12940183, address=MyQName, size=0, scanningStatus=SCANNED, applicationProperties={atmid=CHE80000128, content-type=application/x-protobuf, content-version=2.0, process-id=FireAndForgetJob_AtmStatusRequest_CHE80000128_ConfigurationRequest_f2eb7a14-fc1e-4439-8c83-4e836e83c818, content-status=200, Issued=2023-06-08 19:46:55.862 +02:00, x-version=7.9.44.348, AtmJobId=-1, AtmCommandTaskId=4, AtmCommandTaskResultId=-1, extensions=1, content-length=8145690}, messageAnnotations={}, properties=Properties{messageId=MyQName_2023-06-08T19:46:55.8712925+02:00_208f699f-9636-493f-9bfd-af4317e3dc45, userId=null, to='MyQName', subject='null', replyTo='null', correlationId=null, contentType=null, contentEncoding=null, absoluteExpiryTime=Fri Jun 07 19:46:55 CEST 2024, creationTime=null, groupId='null', groupSequence=null, replyToGroupId='null'}, extraProperties = TypedProperties[_AMQ_AD=MyQName]]], deliveryTime=0, persistedCount=0, deliveryCount=1, subscription=PageSubscriptionImpl [cursorId=47, queue=QueueImpl[name=MyQName, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::name=MyApp], temp=false]@776d381a, filter = null]]
java.lang.IllegalArgumentException: Array must not be empty or null
    at org.apache.qpid.proton.codec.CompositeReadableBuffer.append(CompositeReadableBuffer.java:691) ~[proton-j-0.34.0.jar:?]
    at org.apache.qpid.proton.engine.impl.DeliveryImpl.send(DeliveryImpl.java:345) ~[proton-j-0.34.0.jar:?]
    at org.apache.qpid.proton.engine.impl.SenderImpl.send(SenderImpl.java:74) ~[proton-j-0.34.0.jar:?]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext$LargeMessageDeliveryContext.deliverInitialPacket(ProtonServerSenderContext.java:715) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext$LargeMessageDeliveryContext.deliver(ProtonServerSenderContext.java:622) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.deliverLarge(ProtonServerSenderContext.java:837) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.executeDelivery(ProtonServerSenderContext.java:567) ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
    at org.apache.activemq.artemis.core.paging.cursor.PagedReferenceImpl.run(PagedReferenceImpl.java:116) ~[artemis-server-2.28.0.jar:2.28.0]
    at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:566) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) ~[artemis-commons-2.28.0.jar:?]

 

To me it looks like Artemis tries to close the session/connection of my consuming client but fails to do so. 

Restarting Artemis or restarting my consumer does not change anything. So as soon as the problem occurs it does not go away anymore unless a delete the messages in the queue.

So far I've no way to force/reproduce this problem, it just sporadically occurs.

Issue Links

• is related to: ARTEMIS-4233 QueueImpl::NPE on holder.iter == null