Loading...

Type: Bug
Resolution: Done
Priority: Minor
Fix Version/s: AMQ 7.11.2.GA
Affects Version/s: AMQ 7.10.3.GA, AMQ 7.10.4.GA
Component/s: None
Labels:
None

Blocked:
False
Blocked Reason:
None
Ready:
False
Upstream Jira:
https://issues.apache.org/jira/browse/ARTEMIS-4405, https://issues.apache.org/jira/browse/ARTEMIS-4391
Intelligence Requested:
Market:

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

==== 7.10.3/4 observations ====

Scram bug is present- group name is used instead of username

audit.log:
...
AMQ601715: User amq(amq)@192.168.32.2:39516 successfully authenticated
...


artemis-roles.properties:
amq = admin
senders = alice,charlie
...

As a side note: There also seems to be missing an audit log for creation of Address for AMQP protocol, which is present on 7.11.x branch.

expected lines (taken from 7.11.2) 
2023-10-18 09:00:36,631 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601262: User admin(amq)@172.31.0.2:43424 is creating address on target resource: cd822598-6d94-11ee-8125-0242ac1f0002 with parameters: [Address [name=myAddress, id=0, routingTypes={ANYCAST}, autoCreated=false, paused=false, bindingRemovedTimestamp=-1, swept=false, createdTimestamp=1697619636631], true]
2023-10-18 09:00:36,643 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601019: User anonymous@172.31.0.2:43424 is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AddressControlImpl@4598d01f
2023-10-18 09:00:36,745 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601065: User admin(amq)@172.31.0.2:43424 is creating a queue on target resource: ServerSessionImpl() with parameters: [Qu...]]



current with 7.10.3/4
2023-10-18 06:58:24,290 [AUDIT](main) AMQ241004: Artemis Console available at http://0.0.0.0:8161/console
2023-10-18 06:58:24,624 [AUDIT](RMI TCP Connection(4)-172.29.0.1) AMQ601019: User anonymous@172.29.0.1 is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.ActiveMQServerControlImpl@7da10b5b []
2023-10-18 06:58:24,628 [AUDIT](RMI TCP Connection(4)-172.29.0.1) AMQ601023: User anonymous@172.29.0.1 is querying isStarted on target resource: ActiveMQServerImpl::name=artemis-otelia []
2023-10-18 06:58:24,706 [AUDIT](RMI TCP Connection(4)-172.29.0.1) AMQ601019: User anonymous@172.29.0.1 is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.ActiveMQServerControlImpl@7da10b5b []
2023-10-18 06:58:24,708 [AUDIT](RMI TCP Connection(4)-172.29.0.1) AMQ601026: User anonymous@172.29.0.1 is getting version on target resource: ActiveMQServerImpl::name=artemis-otelia []
2023-10-18 06:58:30,979 [AUDIT](Thread-1 (activemq-netty-threads)) AMQ601715: User admin(amq)@172.29.0.2:54234 successfully authenticated
2023-10-18 06:58:31,002 [AUDIT](Thread-1 (activemq-netty-threads)) AMQ601715: User admin(amq)@172.29.0.2:54234 successfully authenticated
2023-10-18 06:58:31,034 [AUDIT](AmqpProvider :(1):[amqp://artemis-otelia:5672]) Open of resource:(JmsConnectionInfo { ID:1b241045-d611-4b8d-908e-055d055f35a1:1, configuredURI = amqp://artemis-otelia:5672, connectedURI = null }) failed: Open failed unexpectedly.
2023-10-18 06:58:31,064 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601715: User admin(amq)@172.29.0.2:54246 successfully authenticated
2023-10-18 06:58:31,073 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601715: User admin(amq)@172.29.0.2:54246 successfully authenticated
2023-10-18 06:58:31,097 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601267: User admin(amq)@172.29.0.2:54246 is creating a core session on target resource ActiveMQServerImpl::name=artemis-otelia [with parameters: [bf326bde-6d83-11ee-ac8f-0242ac1d0002, admin, ****, 102400, org.apache.activemq.artemis.protocol.amqp.broker.ActiveMQProtonRemotingConnection@3d66fe0e, false, false, false, true, null, org.apache.activemq.artemis.protocol.amqp.broker.AMQPSessionCallback@1447610c, true, {}]]
2023-10-18 06:58:31,118 [AUDIT](AmqpProvider :(2):[amqp://artemis-otelia:5672]) Connection ID:136b9cc8-d9e0-49e4-bc36-951972aa13aa:2 connected to server: amqp://artemis-otelia:5672
2023-10-18 06:58:31,138 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601267: User admin(amq)@172.29.0.2:54246 is creating a core session on target resource ActiveMQServerImpl::name=artemis-otelia [with parameters: [bf38d47f-6d83-11ee-ac8f-0242ac1d0002, admin, ****, 102400, org.apache.activemq.artemis.protocol.amqp.broker.ActiveMQProtonRemotingConnection@3d66fe0e, false, false, false, true, null, org.apache.activemq.artemis.protocol.amqp.broker.AMQPSessionCallback@2e50996c, true, {}]]

>>>> missing address creation log here AMQ601262
2023-10-18 06:58:31,303 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601065: User admin(amq)@172.29.0.2:54246 is creating a queue on target resource: ServerSessionImpl() [with parameters: [QueueConfiguration ...]]]
2023-10-18 06:58:31,309 [AUDIT](Thread-2 (activemq-netty-threads)) AMQ601019: User anonymous@172.29.0.2:54246 is getting mbean info on target resource: org.apache.activemq.artemis.core.management.impl.AddressControlImpl@e906144 []

This has been confirmed to be fixed in 7.11.x branch by gtully@redhat.com

==== Information from cloned Jira ====
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:?]

clones

ENTMQBR-8339 Incorrect username logging in AMQ601264 events

Closed

relates to

ENTMQBR-8452 amqp - AuditLogs reports anonymous user instead of logged in on failed security check for consume/produce

Resolved

mentioned in: Page Loading...

Details

Description

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates