Uploaded image for project: 'ActiveMQ Artemis'
  1. ActiveMQ Artemis
  2. ARTEMIS-1286

Server stops responding and throws OutOfDirectMemoryError when sending & receiving lots of 2MB MQTT messages.

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Closed
    • Blocker
    • Resolution: Fixed
    • 2.1.0
    • 2.6.0
    • Broker, MQTT
    • None

    Description

      Originally seen in v2.1 and present in v2.2.
      If you send and receive a lot of 2MB messages in short time thru Artemis via Netty connector, the server throws the following OutOfDirectMemoryError exception. The server stops responding and will not (any longer) accept connections without throwing exceptions in an infinite loop.

      11:24:07,434 INFO  [org.apache.activemq.artemis] AMQ241001: HTTP Server started at http://localhost:8161
      11:24:07,434 INFO  [org.apache.activemq.artemis] AMQ241002: Artemis Jolokia REST API available at http://localhost:8161/jolokia
      11:58:35,991 WARN  [org.apache.activemq.artemis.core.server] AMQ222151: removing consumer which did not handle a message, consumer=ServerConsumerImpl [id=2229, filter=null, binding=LocalQueueBinding [address=SOAP.S.PRN.ACBCAF6238234680, queue=QueueImpl[name=ACBCAF6238234680.SOAP.S.PRN.ACBCAF6238234680, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=afa7de73-67e7-11e7-a231-54ee7505882d], temp=false]@46adc2a5, filter=FilterImpl [sfilterString=NOT ((AMQAddress = 'activemq.management') OR (AMQAddress = 'activemq.notifications'))], name=ACBCAF6238234680.SOAP.S.PRN.ACBCAF6238234680, clusterName=ACBCAF6238234680.SOAP.S.PRN.ACBCAF6238234680afa7de73-67e7-11e7-a231-54ee7505882d]], message=Reference[3551]:NON-RELIABLE:CoreMessage[messageID=3551,durable=false,userID=null,priority=0, timestamp=0,expiration=0, durable=false, address=SOAP.S.PRN.ACBCAF6238234680,properties=TypedProperties[mqtt.message.retain=false,mqtt.qos.level=0]]@1305748199: io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 3729415 byte(s) of direct memory (used: 1070952692, max: 1073741824)
      	at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:585) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.util.internal.PlatformDependent.allocateDirectNoCleaner(PlatformDependent.java:539) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.UnpooledUnsafeNoCleanerDirectByteBuf.allocateDirect(UnpooledUnsafeNoCleanerDirectByteBuf.java:30) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.UnpooledByteBufAllocator$InstrumentedUnpooledUnsafeNoCleanerDirectByteBuf.allocateDirect(UnpooledByteBufAllocator.java:169) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.UnpooledUnsafeDirectByteBuf.<init>(UnpooledUnsafeDirectByteBuf.java:68) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.UnpooledUnsafeNoCleanerDirectByteBuf.<init>(UnpooledUnsafeNoCleanerDirectByteBuf.java:25) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.UnpooledByteBufAllocator$InstrumentedUnpooledUnsafeNoCleanerDirectByteBuf.<init>(UnpooledByteBufAllocator.java:164) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.UnpooledByteBufAllocator.newDirectBuffer(UnpooledByteBufAllocator.java:73) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:181) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:117) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:828) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.WrappedByteBuf.readBytes(WrappedByteBuf.java:616) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at org.apache.activemq.artemis.core.buffers.impl.ChannelBufferWrapper.readBytes(ChannelBufferWrapper.java:315) [artemis-commons-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTPublishManager.sendServerMessage(MQTTPublishManager.java:277) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTPublishManager.sendMessage(MQTTPublishManager.java:121) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTSessionCallback.sendMessage(MQTTSessionCallback.java:52) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at org.apache.activemq.artemis.core.server.impl.ServerConsumerImpl.deliverStandardMessage(ServerConsumerImpl.java:1078) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.server.impl.ServerConsumerImpl.proceedDeliver(ServerConsumerImpl.java:450) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.server.impl.QueueImpl.proceedDeliver(QueueImpl.java:2688) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.server.impl.QueueImpl.deliverDirect(QueueImpl.java:2673) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.server.impl.QueueImpl.addTail(QueueImpl.java:645) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.addReferences(PostOfficeImpl.java:1297) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.access$000(PostOfficeImpl.java:93) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl$1.done(PostOfficeImpl.java:1157) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.persistence.impl.journal.OperationContextImpl.executeOnCompletion(OperationContextImpl.java:181) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.persistence.impl.journal.OperationContextImpl.executeOnCompletion(OperationContextImpl.java:130) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.afterCompleteOperations(AbstractJournalStorageManager.java:303) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRoute(PostOfficeImpl.java:1149) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:787) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:689) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.doSend(ServerSessionImpl.java:1674) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1351) [artemis-server-2.2.0-SNAPSHOT.jar:2.2.0-SNAPSHOT]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTPublishManager.sendInternal(MQTTPublishManager.java:166) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTPublishManager.handleMessage(MQTTPublishManager.java:136) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTProtocolHandler.handlePublish(MQTTProtocolHandler.java:204) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTProtocolHandler.channelRead(MQTTProtocolHandler.java:118) [artemis-mqtt-protocol-2.2.0-SNAPSHOT.jar:]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:624) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:559) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:476) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_72]
      
      

      Subsequent attempts to connect with the server will fail and causes an infinite loop throwing the following exception into the log until the server is shut down.

      12:10:31,004 WARN  [io.netty.channel.DefaultChannelPipeline] An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.: io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 16777216 byte(s) of direct memory (used: 1070952692, max: 1073741824)
      	at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:585) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.util.internal.PlatformDependent.allocateDirectNoCleaner(PlatformDependent.java:539) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.PoolArena$DirectArena.allocateDirect(PoolArena.java:760) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.PoolArena$DirectArena.newChunk(PoolArena.java:736) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.PoolArena.allocateNormal(PoolArena.java:244) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.PoolArena.allocate(PoolArena.java:214) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.PoolArena.allocate(PoolArena.java:146) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:320) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:181) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:172) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.buffer.AbstractByteBufAllocator.ioBuffer(AbstractByteBufAllocator.java:133) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.DefaultMaxMessagesRecvByteBufAllocator$MaxMessageHandle.allocate(DefaultMaxMessagesRecvByteBufAllocator.java:80) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:122) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:624) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:559) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:476) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.9.Final.jar:4.1.9.Final]
      	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_72]
      
      

      Attachments

        1. artemis log showing v2.4 still having trouble handling large messages.log
          42 kB
          Phillip Jenkins
        2. broker.xml
          9 kB
          Phillip Jenkins
        3. image-2018-02-24-19-54-00-892.png
          44 kB
          Phillip Jenkins
        4. mqtt.zip
          7.67 MB
          Phillip Jenkins
        5. MQTTBasicPubSubExample2.zip
          3 kB
          Phillip Jenkins

        Activity

          People

            clebertsuconic Clebert Suconic
            pwjenkins Phillip Jenkins
            Votes:
            1 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: