[ARTEMIS-3363] using parameter minLargeMessage on cluster connections results in stack traces

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.17.0
• Fix Version/s: 2.19.1, 2.20.0
• Component/s: Broker
• Assignee: Domenico Francesco Bruscino
• Reporter: Erwin Dondorp
• Created: 22/Jun/21 21:02
• Updated: 24/Jan/22 15:26
• Resolved: 20/Jan/22 14:02

Description

In an attempt to set the large message boundary on cluster connections, I added the parameter minLargeMessageSize=1000000 to the callback url.
This showed a stack trace error when it was used. The stack traces are repeated hundreds of times per second and seemed continuous.
Looking at the stack traces, there actually seems to be 2 different stack traces that are alternating. A copy of each is listed below.

Note that decimal 1850499442 = hex 6E4C6172 = ascii "nLar"; which are 4 characters that also appear in the parameter name minLargeMessageSize.

jun. 22, 2021 11:15:46 P.M. org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl fail
WARN: AMQ212037: Connection failure to hostname3/127.0.0.1:61616 has been detected: java.lang.IndexOutOfBoundsException: Error reading in simpleString, length
=1850499442 is greater than readableBytes=36 [code=GENERIC_EXCEPTION]
jun. 22, 2021 11:15:46 P.M. org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl bufferReceived
ERROR: AMQ214013: Failed to decode packet
java.lang.IndexOutOfBoundsException: Error reading in simpleString, length=1850499442 is greater than readableBytes=36
 at org.apache.activemq.artemis.api.core.SimpleString.readSimpleString(SimpleString.java:185)
 at org.apache.activemq.artemis.api.core.SimpleString.readSimpleString(SimpleString.java:173)
 at org.apache.activemq.artemis.core.buffers.impl.ChannelBufferWrapper.readStringInternal(ChannelBufferWrapper.java:113)
 at org.apache.activemq.artemis.core.buffers.impl.ChannelBufferWrapper.readNullableString(ChannelBufferWrapper.java:88)
 at org.apache.activemq.artemis.core.protocol.core.impl.wireformat.ClusterTopologyChangeMessage_V3.decodeRest(ClusterTopologyChangeMessage_V3.java:67)
 at org.apache.activemq.artemis.core.protocol.core.impl.PacketImpl.decode(PacketImpl.java:364)
 at org.apache.activemq.artemis.core.protocol.ServerPacketDecoder.slowPathDecode(ServerPacketDecoder.java:277)
 at org.apache.activemq.artemis.core.protocol.ServerPacketDecoder.decode(ServerPacketDecoder.java:149)
 at org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:377)
 at org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1230)
 at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
 at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
 at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
 at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
 at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
 at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
 at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
 at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
 at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
 at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)

jun. 22, 2021 11:15:46 P.M. org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler bufferReceived
ERROR: AMQ214031: Failed to decode buffer, disconnect immediately.
java.lang.IllegalStateException: java.lang.IndexOutOfBoundsException: Error reading in simpleString, length=1850499442 is greater than readableBytes=36
 at org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:390)
 at org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1230)
 at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
 at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
 at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
 at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
 at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
 at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
 at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
 at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
 at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
 at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
 at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
 at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
 at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
Caused by: java.lang.IndexOutOfBoundsException: Error reading in simpleString, length=1850499442 is greater than readableBytes=36
 at org.apache.activemq.artemis.api.core.SimpleString.readSimpleString(SimpleString.java:185)
 at org.apache.activemq.artemis.api.core.SimpleString.readSimpleString(SimpleString.java:173)
 at org.apache.activemq.artemis.core.buffers.impl.ChannelBufferWrapper.readStringInternal(ChannelBufferWrapper.java:113)
 at org.apache.activemq.artemis.core.buffers.impl.ChannelBufferWrapper.readNullableString(ChannelBufferWrapper.java:88)
 at org.apache.activemq.artemis.core.protocol.core.impl.wireformat.ClusterTopologyChangeMessage_V3.decodeRest(ClusterTopologyChangeMessage_V3.java:67)
 at org.apache.activemq.artemis.core.protocol.core.impl.PacketImpl.decode(PacketImpl.java:364)
 at org.apache.activemq.artemis.core.protocol.ServerPacketDecoder.slowPathDecode(ServerPacketDecoder.java:277)
 at org.apache.activemq.artemis.core.protocol.ServerPacketDecoder.decode(ServerPacketDecoder.java:149)
 at org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:377)
 ... 22 more

To repeat the scenario, add the following snippet to the file etc/broker.xml of a default broker instance. The hostnames hostname[123] can all resolve to localhost/127.0.0.1.
This sample is only valid for the first cluster member, but it is sufficient to start only that first cluster member to repeat this scenario.
Note the addition of url parameter minLargeMessageSize to one of the connectors.

      <connectors>
        <connector name="hostname2-connector">tcp://hostname2:61616</connector>
        <connector name="hostname3-connector">tcp://hostname3:61616</connector>

        <connector name="callback-connector">tcp://hostname1:61616?minLargeMessageSize=1000000</connector>
      </connectors>

      <cluster-connections>
         <cluster-connection name="myclustername">
            <address></address>
            <connector-ref>callback-connector</connector-ref>
            <check-period>5000</check-period>
            <connection-ttl>60000</connection-ttl>
            <retry-interval>5000</retry-interval>
            <initial-connect-attempts>-1</initial-connect-attempts>
            <reconnect-attempts>-1</reconnect-attempts>
            <use-duplicate-detection>true</use-duplicate-detection>
            <message-load-balancing>ON_DEMAND</message-load-balancing>
            <max-hops>1</max-hops>
            <call-failover-timeout>30000</call-failover-timeout>
            <static-connectors>
               <connector-ref>hostname2-connector</connector-ref>
               <connector-ref>hostname3-connector</connector-ref>
            </static-connectors>
         </cluster-connection>
      </cluster-connections>

Note that the property min-large-message-size (property of the cluster-connection) should have been used instead of the url parameter; and I'm already using that. Thanks jbertram for helping with that. But stack traces just look ugly, hence this report...

Issue Links

• links to: GitHub Pull Request #3799
• links to: GitHub Pull Request #3808