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

MQTT client sending wrong password will hang indefinitely, broker logs Error disconnecting client: null

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 2.3.0
    • Fix Version/s: 2.4.0
    • Component/s: MQTT
    • Labels:
      None
    • Environment:

      Description

      MQTT client sending wrong password will hang indefinitely, broker logs Error disconnecting client: null

      If I disable anonymous login on broker and my MQTT client provides invalid credentials, then the broker is not able to kick the client and close connection. The Error disconnecting client: null is printed twice, then broker prints

      21:59:29,758 DEBUG [org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl] RemotingServiceImpl::removing connection ID e08f927f
      

      but still the client is stuck in connection.connect(); method.

      See the attached test case for a reproducer.

      [Thread-1 (activemq-netty-threads)] 22:23:33,072 DEBUG [org.apache.activemq.artemis.core.protocol.mqtt] SESSION CREATED: 7aea3e70-3f7d-493b-94c1-a108d275e01b
      [Thread-1 (activemq-netty-threads)] 22:23:33,097 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.InVMLoginModule] abort
      [Thread-1 (activemq-netty-threads)] 22:23:33,097 DEBUG [org.apache.activemq.artemis.spi.core.security.ActiveMQJAASSecurityManager] Couldn't validate user: javax.security.auth.login.FailedLoginException: Password does not match
      	at org.apache.activemq.artemis.spi.core.security.jaas.InVMLoginModule.login(InVMLoginModule.java:92) [:]
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_141]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_141]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_141]
      	at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_141]
      	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755) [rt.jar:1.8.0_141]
      	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195) [rt.jar:1.8.0_141]
      	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682) [rt.jar:1.8.0_141]
      	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680) [rt.jar:1.8.0_141]
      	at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.8.0_141]
      	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680) [rt.jar:1.8.0_141]
      	at javax.security.auth.login.LoginContext.login(LoginContext.java:587) [rt.jar:1.8.0_141]
      	at org.apache.activemq.artemis.spi.core.security.ActiveMQJAASSecurityManager.getAuthenticatedSubject(ActiveMQJAASSecurityManager.java:186) [:]
      	at org.apache.activemq.artemis.spi.core.security.ActiveMQJAASSecurityManager.validateUser(ActiveMQJAASSecurityManager.java:93) [:]
      	at org.apache.activemq.artemis.core.security.impl.SecurityStoreImpl.authenticate(SecurityStoreImpl.java:130) [:]
      	at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.createSession(ActiveMQServerImpl.java:1434) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTConnectionManager.createServerSession(MQTTConnectionManager.java:117) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTConnectionManager.connect(MQTTConnectionManager.java:84) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTProtocolHandler.handleConnect(MQTTProtocolHandler.java:161) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTProtocolHandler.channelRead(MQTTProtocolHandler.java:107) [:]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:236) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:494) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at org.apache.activemq.artemis.core.protocol.ProtocolHandler$ProtocolDecoder.channelRead(ProtocolHandler.java:128) [:]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1342) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:934) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:979) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:307) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_141]
      
      [Thread-1 (activemq-netty-threads)] 22:23:33,116 DEBUG [org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] Couldn't find any bindings for address=activemq.notifications on message=CoreMessage[messageID=0,durable=true,userID=null,priority=0, timestamp=0,expiration=0, durable=true, address=activemq.notifications,properties=TypedProperties[_AMQ_NotifType=SECURITY_AUTHENTICATION_VIOLATION,_AMQ_NotifTimestamp=1504729413109]]@907108390
      [Thread-1 (activemq-netty-threads)] 22:23:33,116 DEBUG [org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] Message CoreMessage[messageID=0,durable=true,userID=null,priority=0, timestamp=0,expiration=0, durable=true, address=activemq.notifications,properties=TypedProperties[_AMQ_NotifType=SECURITY_AUTHENTICATION_VIOLATION,_AMQ_NotifTimestamp=1504729413109]]@907108390 is not going anywhere as it didn't have a binding on address:activemq.notifications
      [Thread-1 (activemq-netty-threads)] 22:23:33,134 DEBUG [org.apache.activemq.artemis.core.protocol.mqtt] Error processing Control Packet, Disconnecting Client: ActiveMQSecurityException[errorType=SECURITY_EXCEPTION message=AMQ119031: Unable to validate user from /127.0.0.1:58466. Username: user; SSL certificate subject DN: unavailable]
      	at org.apache.activemq.artemis.core.security.impl.SecurityStoreImpl.authenticate(SecurityStoreImpl.java:152) [:]
      	at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.createSession(ActiveMQServerImpl.java:1434) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTConnectionManager.createServerSession(MQTTConnectionManager.java:117) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTConnectionManager.connect(MQTTConnectionManager.java:84) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTProtocolHandler.handleConnect(MQTTProtocolHandler.java:161) [:]
      	at org.apache.activemq.artemis.core.protocol.mqtt.MQTTProtocolHandler.channelRead(MQTTProtocolHandler.java:107) [:]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:236) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:494) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:428) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at org.apache.activemq.artemis.core.protocol.ProtocolHandler$ProtocolDecoder.channelRead(ProtocolHandler.java:128) [:]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1342) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:934) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:979) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:307) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.14.Final.jar:4.1.14.Final]
      	at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_141]
      
      [Thread-1 (activemq-netty-threads)] 22:23:33,134 ERROR [org.apache.activemq.artemis.core.protocol.mqtt] Error disconnecting client: null
      

        Attachments

          Activity

            People

            • Assignee:
              jbertram Justin Bertram
              Reporter:
              jdanek Jiri Daněk
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: