ARTEMIS-2974 audit logger can print wrong user info

Using a ThreadLocal for the audit user information works in most cases, but it can fail when dispatching messages to consumers because threads are taken out of a pool to do the dispatching and those threads may not be associated with the proper credentials. This commit fixes that problem with the following changes: - Passes the Subject explicitly when logging audit info during dispatch - Relocates security audit logging from the SecurityManager implementation(s) to the SecurityStore implementation - Associates the Subject with the connection properly with the new security caching
apache · Nov 5, 2020 · ecead9b · ecead9b
1 parent c377801
commit ecead9b
Show file tree

Hide file tree

Showing 8 changed files with 278 additions and 25 deletions.
diff --git a/artemis-commons/src/main/java/org/apache/activemq/artemis/logs/AssertionLoggerHandler.java b/artemis-commons/src/main/java/org/apache/activemq/artemis/logs/AssertionLoggerHandler.java
@@ -19,6 +19,7 @@
 import java.util.Map;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.logging.Level;
+import java.util.regex.Pattern;
 
 import org.jboss.logmanager.ExtHandler;
 import org.jboss.logmanager.ExtLogRecord;
@@ -120,6 +121,25 @@ public static boolean findText(final String... text) {
       return false;
    }
 
+   public static boolean matchText(final String pattern) {
+      Pattern r = Pattern.compile(pattern);
+
+      for (Map.Entry<String, ExtLogRecord> entry : messages.entrySet()) {
+         if (r.matcher(entry.getKey()).matches()) {
+            return true;
+         } else {
+            Throwable throwable = entry.getValue().getThrown();
+            if (throwable != null && throwable.getMessage() != null) {
+               if (r.matcher(throwable.getMessage()).matches()) {
+                  return true;
+               }
+            }
+         }
+      }
+
+      return false;
+   }
+
    public static final void clear() {
       messages.clear();
    }

diff --git a/artemis-commons/src/main/java/org/apache/activemq/artemis/logs/AuditLogger.java b/artemis-commons/src/main/java/org/apache/activemq/artemis/logs/AuditLogger.java
@@ -2428,8 +2428,8 @@ static void coreSendMessage(String user, String messageToString, Object context)
    void logCoreSendMessage(String user, String messageToString, Object context);
 
    //hot path log using a different logger
-   static void coreConsumeMessage(String queue) {
-      MESSAGE_LOGGER.consumeMessage(getCaller(), queue);
+   static void coreConsumeMessage(Subject user, String queue) {
+      MESSAGE_LOGGER.consumeMessage(getCaller(user), queue);
    }
 
    @LogMessage(level = Logger.Level.INFO)

diff --git a/...erver/src/main/java/org/apache/activemq/artemis/core/security/impl/SecurityStoreImpl.java b/...erver/src/main/java/org/apache/activemq/artemis/core/security/impl/SecurityStoreImpl.java
@@ -156,6 +156,7 @@ public String authenticate(final String user,
          boolean userIsValid = false;
          boolean check = true;
 
+         Subject subject = null;
          Pair<Boolean, Subject> cacheEntry = authenticationCache.getIfPresent(createAuthenticationCacheKey(user, password, connection));
          if (cacheEntry != null) {
             if (!cacheEntry.getA()) {
@@ -165,13 +166,13 @@ public String authenticate(final String user,
                // cached authentication succeeded previously so don't check again
                check = false;
                userIsValid = true;
-               validatedUser = getUserFromSubject(cacheEntry.getB());
+               subject = cacheEntry.getB();
+               validatedUser = getUserFromSubject(subject);
             }
          }
-
          if (check) {
             if (securityManager instanceof ActiveMQSecurityManager5) {
-               Subject subject = ((ActiveMQSecurityManager5) securityManager).authenticate(user, password, connection, securityDomain);
+               subject = ((ActiveMQSecurityManager5) securityManager).authenticate(user, password, connection, securityDomain);
                authenticationCache.put(createAuthenticationCacheKey(user, password, connection), new Pair<>(subject != null, subject));
                validatedUser = getUserFromSubject(subject);
             } else if (securityManager instanceof ActiveMQSecurityManager4) {
@@ -204,9 +205,20 @@ public String authenticate(final String user,
 
             ActiveMQServerLogger.LOGGER.securityProblemWhileAuthenticating(e.getMessage());
 
+            if (AuditLogger.isResourceLoggingEnabled()) {
+               AuditLogger.userFailedLoggedInAudit(subject, e.getMessage());
+            }
+
             throw e;
          }
 
+         if (AuditLogger.isAnyLoggingEnabled() && connection != null) {
+            connection.setAuditSubject(subject);
+         }
+         if (AuditLogger.isResourceLoggingEnabled()) {
+            AuditLogger.userSuccesfullyLoggedInAudit(subject);
+         }
+
          return validatedUser;
       }
 

diff --git a/...server/src/main/java/org/apache/activemq/artemis/core/server/impl/ServerConsumerImpl.java b/...server/src/main/java/org/apache/activemq/artemis/core/server/impl/ServerConsumerImpl.java
@@ -487,7 +487,7 @@ public void proceedDeliver(MessageReference reference) throws Exception {
          Message message = reference.getMessage();
 
          if (AuditLogger.isMessageEnabled()) {
-            AuditLogger.coreConsumeMessage(getQueueName().toString());
+            AuditLogger.coreConsumeMessage(session.getRemotingConnection().getAuditSubject(), getQueueName().toString());
          }
          if (server.hasBrokerMessagePlugins()) {
             server.callBrokerMessagePlugins(plugin -> plugin.beforeDeliver(this, reference));

diff --git a/...main/java/org/apache/activemq/artemis/spi/core/security/ActiveMQBasicSecurityManager.java b/...main/java/org/apache/activemq/artemis/spi/core/security/ActiveMQBasicSecurityManager.java
@@ -32,7 +32,6 @@
 import org.apache.activemq.artemis.core.security.User;
 import org.apache.activemq.artemis.core.server.ActiveMQMessageBundle;
 import org.apache.activemq.artemis.core.server.ActiveMQServerLogger;
-import org.apache.activemq.artemis.logs.AuditLogger;
 import org.apache.activemq.artemis.spi.core.protocol.RemotingConnection;
 import org.apache.activemq.artemis.spi.core.security.jaas.RolePrincipal;
 import org.apache.activemq.artemis.spi.core.security.jaas.UserPrincipal;
@@ -82,12 +81,6 @@ public Subject authenticate(final String userToAuthenticate, final String passwo
                   for (String role : getRole(userToAuthenticate).getRoles()) {
                      subject.getPrincipals().add((Principal) SecurityManagerUtil.createGroupPrincipal(role, rolePrincipalClass));
                   }
-                  if (AuditLogger.isAnyLoggingEnabled() && remotingConnection != null) {
-                     remotingConnection.setAuditSubject(subject);
-                  }
-                  if (AuditLogger.isResourceLoggingEnabled()) {
-                     AuditLogger.userSuccesfullyLoggedInAudit(subject);
-                  }
                   return subject;
                }
             }

diff --git a/.../main/java/org/apache/activemq/artemis/spi/core/security/ActiveMQJAASSecurityManager.java b/.../main/java/org/apache/activemq/artemis/spi/core/security/ActiveMQJAASSecurityManager.java
@@ -24,7 +24,6 @@
 import org.apache.activemq.artemis.core.config.impl.SecurityConfiguration;
 import org.apache.activemq.artemis.core.security.CheckType;
 import org.apache.activemq.artemis.core.security.Role;
-import org.apache.activemq.artemis.logs.AuditLogger;
 import org.apache.activemq.artemis.spi.core.protocol.RemotingConnection;
 import org.apache.activemq.artemis.spi.core.security.jaas.JaasCallbackHandler;
 import org.apache.activemq.artemis.spi.core.security.jaas.RolePrincipal;
@@ -137,16 +136,7 @@ private Subject getAuthenticatedSubject(final String user,
          }
          try {
             lc.login();
-            if (AuditLogger.isAnyLoggingEnabled() && remotingConnection != null) {
-               remotingConnection.setAuditSubject(lc.getSubject());
-            }
-            if (AuditLogger.isResourceLoggingEnabled()) {
-               AuditLogger.userSuccesfullyLoggedInAudit(lc.getSubject());
-            }
          } catch (LoginException e) {
-            if (AuditLogger.isResourceLoggingEnabled()) {
-               AuditLogger.userFailedLoggedInAudit(lc.getSubject(), e.getMessage());
-            }
             throw e;
          }
          return lc.getSubject();

diff --git a/tests/config/logging.properties b/tests/config/logging.properties
@@ -17,7 +17,7 @@
 
 # Additional logger names to configure (root logger is always configured)
 # Root logger option
-loggers=org.jboss.logging,org.apache.activemq.artemis.core.server,org.apache.activemq.artemis.utils,org.apache.activemq.artemis.journal,org.apache.activemq.artemis.jms,org.apache.activemq.artemis.ra,org.apache.activemq.artemis.tests.unit,org.apache.activemq.artemis.tests.integration,org.apache.activemq.artemis.jms.tests,org.apache.activemq.cli.test,org.apache.activemq.audit
+loggers=org.jboss.logging,org.apache.activemq.artemis.core.server,org.apache.activemq.artemis.utils,org.apache.activemq.artemis.journal,org.apache.activemq.artemis.jms,org.apache.activemq.artemis.ra,org.apache.activemq.artemis.tests.unit,org.apache.activemq.artemis.tests.integration,org.apache.activemq.artemis.jms.tests,org.apache.activemq.cli.test,org.apache.activemq.audit,org.apache.activemq.audit.message
 
 # Root logger level
 logger.level=INFO
@@ -41,7 +41,7 @@ logger.handlers=CONSOLE,TEST
 
 # to enable audit change the level to INFO
 logger.org.apache.activemq.audit.level=ERROR
-logger.org.apache.activemq.audit.handlers=CONSOLE,FILE
+logger.org.apache.activemq.audit.handlers=CONSOLE,FILE,TEST
 logger.org.apache.activemq.audit.useParentHandlers=false
 
 # Console handler configuration