You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Keith Wall (JIRA)" <ji...@apache.org> on 2018/07/31 12:26:00 UTC

[jira] [Commented] (ARTEMIS-1993) AMQ224041: Failed to deliver: java.lang.ArrayIndexOutOfBoundsException occasionally seen when concurrent short-lived connections consume from the same queue

    [ https://issues.apache.org/jira/browse/ARTEMIS-1993?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16563577#comment-16563577 ] 

Keith Wall commented on ARTEMIS-1993:
-------------------------------------

Expanding on what I wrote above, I know understand that for the issue to manifest, not only do you need concurrent consumers, the consumers need to be disconnecting abnormally whilst the queue is delivering message to other consumers. I haven't got a elegant reproduction, but I do see the problem in the code.

In the {{org.apache.activemq.artemis.core.server.impl.QueueImpl#deliver}} method, if the {{org.apache.activemq.artemis.core.server.impl.QueueImpl#handle}} method throws any throwable, the consumer is removed (by the action of the _synchronous_ invocation {{#removeConsumer}}). This method removes the entry from the {{consumerList}}. Now, the {{#deliver}} has a local variable {{size}} in which it caches the size of the {{consumerList }}(recorded when the method entered its critical section). In the case where the consumer {{#handle}} method has thrown an exception, this value is stale (one too large). This means that {{if (pos >= size)}} condition on line 2398 won't be true, so on the next iteration of deliver's while loop, the {{ArrayIndexOutOfBoundsException}} can occur. The issue actually only manifests if it is the last consumer in the list that suffers the exception.

When the issue occurs there actually a AMQ222151 logged just prior to the {{ArrayIndexOutOfBoundsException}}
{noformat}
2018-07-31 12:28:44,128 WARN  [org.apache.activemq.artemis.core.server] AMQ222151: removing consumer which did not handle a message, consumer=ServerConsumerImpl [id=0, filter=null, binding=LocalQueueBinding [address=queue, queue=QueueImpl[name=queue, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=6070a915-94a9-11e8-a068-0c4de9a5c7e1], temp=false]@1001b9eb, filter=null, name=queue, clusterName=queue6070a915-94a9-11e8-a068-0c4de9a5c7e1]], message=Reference[2154473242]:NON-RELIABLE:AMQPMessage [durable=false, messageID=2154473242, address=queue, size=28, applicationProperties=null, properties=null, extraProperties = TypedProperties[_AMQ_AD=queue]]: java.lang.NullPointerException
        at org.apache.activemq.artemis.core.server.impl.ServerConsumerImpl.handle(ServerConsumerImpl.java:353) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl.handle(QueueImpl.java:3073) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliver(QueueImpl.java:2417) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl.access$2000(QueueImpl.java:109) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl$DeliverRunner.run(QueueImpl.java:3299) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_181]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_181]
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
(snip)
2018-07-31 12:28:44,142 ERROR [org.apache.activemq.artemis.core.server] AMQ224041: Failed to deliver: java.lang.ArrayIndexOutOfBoundsException: 3
        at java.util.concurrent.CopyOnWriteArrayList.get(CopyOnWriteArrayList.java:388) [rt.jar:1.8.0_181]
        at java.util.concurrent.CopyOnWriteArrayList.get(CopyOnWriteArrayList.java:397) [rt.jar:1.8.0_181]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliver(QueueImpl.java:2360) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl.access$2000(QueueImpl.java:109) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.core.server.impl.QueueImpl$DeliverRunner.run(QueueImpl.java:3299) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_181]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_181]
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
{noformat}

> AMQ224041: Failed to deliver: java.lang.ArrayIndexOutOfBoundsException occasionally seen when concurrent short-lived connections consume from the same queue
> ------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: ARTEMIS-1993
>                 URL: https://issues.apache.org/jira/browse/ARTEMIS-1993
>             Project: ActiveMQ Artemis
>          Issue Type: Bug
>    Affects Versions: 2.5.0
>            Reporter: Keith Wall
>            Priority: Major
>
> The following issue is occasionally seen when multiple short lived concurrent connections consume from the same queue.  When the issue occurs, there tends to be a swathe of these messages written to the logs at one time.   Apart from the error message, there is no other obvious functional defect. 
>  
> The issue has been reproduced with 2.5.0 and master (f0c13622ac7e821a81a354b0242ef5235b6e82df).
>  
> {noformat}
> 2018-07-27 14:47:54,491 ERROR [org.apache.activemq.artemis.core.server] AMQ224041: Failed to deliver: java.lang.ArrayIndexOutOfBoundsException: 78
> at java.util.concurrent.CopyOnWriteArrayList.get(CopyOnWriteArrayList.java:388) [rt.jar:1.8.0_181]
> at java.util.concurrent.CopyOnWriteArrayList.get(CopyOnWriteArrayList.java:397) [rt.jar:1.8.0_181]
> at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliver(QueueImpl.java:2289) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.server.impl.QueueImpl.access$2000(QueueImpl.java:107) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
> at org.apache.activemq.artemis.core.server.impl.QueueImpl$DeliverRunner.run(QueueImpl.java:3209) [artemis-server-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_181]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_181]
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.7.0-SNAPSHOT.jar:2.7.0-SNAPSHOT]{noformat}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)