Uploaded image for project: 'AMQ Broker'
  1. AMQ Broker
  2. ENTMQBR-976

[org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler] Sasl can't be initiated after transport has started processing

    XMLWordPrintable

Details

    • Bug
    • Resolution: Obsolete
    • Minor
    • None
    • AMQ 7.0.3.GA
    • amqp-protocol

    Description

      While trying to reproduce ENTMQCL-600, which involved starting a stopping AMQ 7.0.3 broker in a loop while a client was reconnecting to it, I noticed the following error message. It has appeared only once (as far as I've noticed) and I was not able to reproduce it since.

      Does it signal any problem with the broker that needs to be investigated, or can it be safely ignored?

      I have seen this once before already, https://issues.apache.org/jira/browse/QPIDJMS-345

         /  \  | \  / | |  | | | |_) |_  _ | | ___ _ 
   / /\ \ | |\/| | |  | | |  _ <| '/ _ \| |/ / _ \ '|
  / __ \| |  | | || | | |_) | | | (_) |   <  __/ |
 /_/    \_\_|  |_|\_\_\ |/|_|  \_/|_|\_\___|_|

 Red Hat JBoss AMQ 7.0.3.GA


17:08:48,099 INFO  [org.apache.activemq.artemis.integration.bootstrap] AMQ101000: Starting ActiveMQ Artemis Server
17:08:48,206 INFO  [org.apache.activemq.artemis.core.server] AMQ221000: live Message Broker is starting with configuration Broker Configuration (clustered=true,journalDirectory=./data/journal,bindingsDirectory=./data/bindings,largeMessagesDirectory=./data/large-messages,pagingDirectory=./data/paging)
17:08:50,516 WARN  [org.apache.activemq.artemis.core.server] AMQ222007: Security risk! Apache ActiveMQ Artemis is running with the default cluster admin user and default password. Please see the cluster chapter in the ActiveMQ Artemis User Guide for instructions on how to change this.
17:08:50,581 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-server]. Adding protocol support for: CORE
17:08:50,581 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-amqp-protocol]. Adding protocol support for: AMQP
17:08:50,585 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-hornetq-protocol]. Adding protocol support for: HORNETQ
17:08:50,585 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-mqtt-protocol]. Adding protocol support for: MQTT
17:08:50,585 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-openwire-protocol]. Adding protocol support for: OPENWIRE
17:08:50,586 INFO  [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-stomp-protocol]. Adding protocol support for: STOMP
17:08:50,681 INFO  [org.apache.activemq.artemis.core.server] AMQ221003: Deploying queue DLQ
17:08:50,754 INFO  [org.apache.activemq.artemis.core.server] AMQ221003: Deploying queue ExpiryQueue
17:08:50,759 INFO  [org.apache.activemq.artemis.core.server] AMQ221003: Deploying queue TPX
17:08:51,047 INFO  [org.apache.activemq.artemis.core.server] AMQ221020: Started NIO Acceptor at 172.16.201.44:61616 for protocols [CORE,MQTT,AMQP,STOMP,HORNETQ,OPENWIRE]
17:08:51,049 INFO  [org.apache.activemq.artemis.core.server] AMQ221020: Started NIO Acceptor at 172.16.201.44:5445 for protocols [HORNETQ,STOMP]
17:08:51,053 INFO  [org.apache.activemq.artemis.core.server] AMQ221020: Started NIO Acceptor at 172.16.201.44:5672 for protocols [AMQP]
17:08:51,054 INFO  [org.apache.activemq.artemis.core.server] AMQ221020: Started NIO Acceptor at 172.16.201.44:1883 for protocols [MQTT]
17:08:51,058 INFO  [org.apache.activemq.artemis.core.server] AMQ221020: Started NIO Acceptor at 172.16.201.44:61613 for protocols [STOMP]
17:08:51,059 INFO  [org.apache.activemq.artemis.core.server] AMQ221007: Server is now live
17:08:51,059 INFO  [org.apache.activemq.artemis.core.server] AMQ221001: Apache ActiveMQ Artemis Message Broker version 2.0.0.amq-700013-redhat-1 [testamqbroker-master, nodeID=df61d787-f7b2-11e7-aa0b-fa163ed4dc1b] 
17:08:53,058 WARN  [org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler] Sasl can't be initiated after transport has started processing: java.lang.IllegalStateException: Sasl can't be initiated after transport has started processing
		at org.apache.qpid.proton.engine.impl.TransportImpl.sasl(TransportImpl.java:350) [proton-j-0.18.0.redhat-1.jar:]
		at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.createServerSASL(ProtonHandler.java:150) [artemis-amqp-protocol-2.0.0.amq-700013-redhat-1.jar:]
		at org.apache.activemq.artemis.protocol.amqp.proton.AMQPConnectionContext.onAuthInit(AMQPConnectionContext.java:323) [artemis-amqp-protocol-2.0.0.amq-700013-redhat-1.jar:]
		at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.dispatchAuth(ProtonHandler.java:309) [artemis-amqp-protocol-2.0.0.amq-700013-redhat-1.jar:]
		at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.inputBuffer(ProtonHandler.java:204) [artemis-amqp-protocol-2.0.0.amq-700013-redhat-1.jar:]
		at org.apache.activemq.artemis.protocol.amqp.proton.AMQPConnectionContext.inputBuffer(AMQPConnectionContext.java:124) [artemis-amqp-protocol-2.0.0.amq-700013-redhat-1.jar:]
		at org.apache.activemq.artemis.protocol.amqp.broker.ActiveMQProtonRemotingConnection.bufferReceived(ActiveMQProtonRemotingConnection.java:138) [artemis-amqp-protocol-2.0.0.amq-700013-redhat-1.jar:]
		at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:628) [artemis-server-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:69) [artemis-core-client-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:219) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.DefaultChannelPipeline.callHandlerRemoved0(DefaultChannelPipeline.java:631) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:468) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:428) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at org.apache.activemq.artemis.core.protocol.ProtocolHandler$ProtocolDecoder.decode(ProtocolHandler.java:185) [artemis-server-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at org.apache.activemq.artemis.core.protocol.ProtocolHandler$ProtocolDecoder.channelRead(ProtocolHandler.java:128) [artemis-server-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:624) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:559) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:476) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:438) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.9.Final-redhat-2.jar:4.1.9.Final-redhat-2]
		at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]

INFO  | main | Initialized dispatch-hawtio-console plugin
17:08:54,046 INFO  [org.apache.activemq.artemis] AMQ241001: HTTP Server started at http://localhost:8161
17:08:54,047 INFO  [org.apache.activemq.artemis] AMQ241002: Artemis Jolokia REST API available at http://localhost:8161/jolokia
17:09:16,664 WARN  [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Server locator is closed (maybe it was garbage collected): java.lang.IllegalStateException: Server locator is closed (maybe it was garbage collected)
		at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.assertOpen(ServerLocatorImpl.java:1803) [artemis-core-client-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.createSessionFactory(ServerLocatorImpl.java:739) [artemis-core-client-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.connect(ServerLocatorImpl.java:627) [artemis-core-client-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.connect(ServerLocatorImpl.java:609) [artemis-core-client-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.core.server.cluster.ClusterController$ConnectRunnable.run(ClusterController.java:414) [artemis-server-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at org.apache.activemq.artemis.utils.actors.ProcessorBase$ExecutorTask.run(ProcessorBase.java:53) [artemis-commons-2.0.0.amq-700013-redhat-1.jar:2.0.0.amq-700013-redhat-1]
		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_151]
		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_151]
		at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]

INFO  | shutdown-hook | Destroyed dispatch-hawtio-console plugin
17:09:16,944 INFO  [org.apache.activemq.artemis.core.server] AMQ221002: Apache ActiveMQ Artemis Message Broker version 2.0.0.amq-700013-redhat-1 [df61d787-f7b2-11e7-aa0b-fa163ed4dc1b] stopped, uptime 28.757 seconds
[1]+  Exit 143                amq-broker-7.0.3/i0/bin/artemis run

      Attachments

        Activity

          People

            rh-ee-ataylor Andy Taylor
            jdanek@redhat.com Jiri Daněk
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: