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

Incorrect username logging in AMQ601264 events

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Closed
    • Minor
    • Resolution: Fixed
    • 2.30.0
    • 2.31.0
    • None
    • None

    Description

      We have ActiveMQ Artemis with audit logging turned on, and sometimes wrong username is logged when user gets an authorization error (audit log event AMQ601264). I have reproduced this issue when client uses STOMP to connect to the broker. In that case client username is always logged as anonymous, and source IP address seems to be correct.

      We have a lot of other audit log messages where different usernames are logged in single log event, but I cannot attach these logs because it contains sensitive information. I think this problem is not specific to STOMP clients because most our clients use core and openwire. I will try to reproduce it later.

      The problem is not specific to the current version of Artemis.

      Steps to reproduce (for STOMP client):

      1. Create Artemis instance

      artemis create --user admin --password admin --require-login 

      Edit artemis-roles.properties and artemis-users.properties to create some other user with password and non-admin role. For example, add string alice = alice to both files.

      Edit log4j2.properties to enable base audit logging:

      logger.audit_base = INFO, audit_log_file

      To connect to the broker with STOMP I have used python with Stompest library (it has to be installed using pip install stompest).

      Example STOMP producer python code (it does not handle authorization errors):

       

      from stompest.config import StompConfig
      from stompest.protocol import StompSpec
      from stompest.sync import Stomp
      CONFIG = StompConfig("tcp://localhost:61613", login="alice", passcode="alice", version=StompSpec.VERSION_1_0)
      QUEUE = 'test.queue'
      client = Stomp(CONFIG)
      client.connect()
      client.send(QUEUE, 'Test message'.encode())
      client.disconnect()
      

      Run this example code. Check broker audit.log. For example:

       

      2023-08-28 17:39:20,042 [AUDIT](Thread-1 (activemq-netty-threads)) AMQ601267: User alice(alice)@127.0.0.1:56685 is creating a core session on target resource ActiveMQServerImpl::name=0.0.0.0 with parameters: [ac22db0e-45b0-11ee-b333-005056abe8b9, alice, ****, 102400, org.apache.activemq.artemis.core.protocol.stomp.StompConnection@3313e538, true, false, false, false, null, org.apache.activemq.artemis.core.protocol.stomp.StompSession@2fc820ee, true, {}]
      2023-08-28 17:39:20,081 [AUDIT](Thread-1 (activemq-netty-threads)) AMQ601262: User alice(alice)@127.0.0.1:56685 is creating address on target resource: ac22db0e-45b0-11ee-b333-005056abe8b9 with parameters: [Address [name=test.queue, id=0, routingTypes={MULTICAST}, autoCreated=false, paused=false, bindingRemovedTimestamp=-1, swept=false, createdTimestamp=1693233560081], true]
      2023-08-28 17:39:20,116 [AUDIT](Thread-1 (activemq-netty-threads)) AMQ601264: User anonymous@127.0.0.1:56685 gets security check failure, reason = AMQ229032: User: alice does not have permission='CREATE_ADDRESS' on address test.queue
      org.apache.activemq.artemis.api.core.ActiveMQSecurityException: AMQ229032: User: alice does not have permission='CREATE_ADDRESS' on address test.queue
          at org.apache.activemq.artemis.core.security.impl.SecurityStoreImpl.check(SecurityStoreImpl.java:305) [artemis-server-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.security.impl.SecurityStoreImpl.check(SecurityStoreImpl.java:227) [artemis-server-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.securityCheck(ServerSessionImpl.java:503) [artemis-server-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.createAddress(ServerSessionImpl.java:972) [artemis-server-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.createAddress(ServerSessionImpl.java:962) [artemis-server-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.protocol.stomp.StompConnection.autoCreateDestinationIfPossible(StompConnection.java:184) [artemis-stomp-protocol-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.protocol.stomp.VersionedStompFrameHandler.onSend(VersionedStompFrameHandler.java:188) [artemis-stomp-protocol-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.protocol.stomp.VersionedStompFrameHandler.handleFrame(VersionedStompFrameHandler.java:87) [artemis-stomp-protocol-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.protocol.stomp.StompConnection.handleFrame(StompConnection.java:424) [artemis-stomp-protocol-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.protocol.stomp.StompProtocolManager.handleBuffer(StompProtocolManager.java:162) [artemis-stomp-protocol-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.protocol.stomp.StompConnection.bufferReceived(StompConnection.java:307) [artemis-stomp-protocol-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:698) [artemis-server-2.30.0.jar:2.30.0]
          at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73) [artemis-core-client-2.30.0.jar:2.30.0]
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) [netty-transport-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) [netty-common-4.1.94.Final.jar:4.1.94.Final]
          at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.94.Final.jar:4.1.94.Final]
          at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.30.0.jar:?]

       

       

      Attachments

        Issue Links

          Activity

            People

              jbertram Justin Bertram
              aleksandr-milovidov Aleksandr Milovidov
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 40m
                  40m