diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java b/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java index 54974fc0fe0..b4eca51dd4a 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java @@ -37,6 +37,9 @@ import javax.security.auth.login.Configuration; import javax.security.auth.login.LoginContext; import javax.security.auth.login.LoginException; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.AuditEvent.Result; +import org.apache.zookeeper.audit.ZKAuditProvider; import org.apache.zookeeper.client.ZKClientConfig; import org.apache.zookeeper.common.Time; import org.apache.zookeeper.common.ZKConfig; @@ -81,7 +84,8 @@ public class Login { private LoginContext login = null; private String loginContextName = null; - private String principal = null; + private final String principal; + private volatile String auditPrincipal = SYSTEM_USER; // Initialize 'lastLogin' to do a login at first time private long lastLogin = Time.currentElapsedTime() - MIN_TIME_BEFORE_RELOGIN; @@ -106,24 +110,11 @@ public class Login { public Login(final String loginContextName, Supplier callbackHandlerSupplier, final ZKConfig zkConfig) throws LoginException { this.zkConfig = zkConfig; this.callbackHandlerSupplier = callbackHandlerSupplier; + principal = readLoginConfiguration(loginContextName); login = login(loginContextName); this.loginContextName = loginContextName; subject = login.getSubject(); isKrbTicket = !subject.getPrivateCredentials(KerberosTicket.class).isEmpty(); - AppConfigurationEntry[] entries = Configuration.getConfiguration().getAppConfigurationEntry(loginContextName); - for (AppConfigurationEntry entry : entries) { - // there will only be a single entry, so this for() loop will only be iterated through once. - if (entry.getOptions().get("useTicketCache") != null) { - String val = (String) entry.getOptions().get("useTicketCache"); - if (val.equals("true")) { - isUsingTicketCache = true; - } - } - if (entry.getOptions().get("principal") != null) { - principal = (String) entry.getOptions().get("principal"); - } - break; - } if (!isKrbTicket) { // if no TGT, do not bother with ticket management. @@ -228,6 +219,7 @@ public void run() { Shell.execCommand(cmd, kinitArgs); break; } catch (Exception e) { + audit(getAuditUser(subject), AuditConstants.OP_TICKET_RENEWAL, Result.FAILURE); if (retry > 0) { --retry; // sleep for 10 seconds @@ -330,17 +322,86 @@ public String getLoginContextName() { } private synchronized LoginContext login(final String loginContextName) throws LoginException { + try { + if (loginContextName == null) { + throw new LoginException("loginContext name (JAAS file section header) was null. " + + "Please check your java.security.login.auth.config (=" + + System.getProperty("java.security.login.auth.config") + + ") and your " + + getLoginContextMessage()); + } + LoginContext loginContext = new LoginContext(loginContextName, newCallbackHandler()); + loginContext.login(); + // Retain the authenticated identity even if a later logout clears the subject. + auditPrincipal = getAuditUser(loginContext.getSubject()); + audit(auditPrincipal, AuditConstants.OP_LOGIN, Result.SUCCESS); + LOG.info("{} successfully logged in.", loginContextName); + return loginContext; + } catch (LoginException e) { + audit(auditPrincipal, AuditConstants.OP_LOGIN, Result.FAILURE); + throw e; + } + } + + private String readLoginConfiguration(String loginContextName) { if (loginContextName == null) { - throw new LoginException("loginContext name (JAAS file section header) was null. " - + "Please check your java.security.login.auth.config (=" - + System.getProperty("java.security.login.auth.config") - + ") and your " - + getLoginContextMessage()); + return null; + } + // LoginContext falls back to "other" when the named configuration is absent. + Configuration configuration = Configuration.getConfiguration(); + AppConfigurationEntry[] entries = configuration.getAppConfigurationEntry(loginContextName); + if (entries == null) { + entries = configuration.getAppConfigurationEntry("other"); + } + if (entries != null && entries.length > 0) { + AppConfigurationEntry entry = entries[0]; + isUsingTicketCache = "true".equals(entry.getOptions().get("useTicketCache")); + Object principalOption = entry.getOptions().get("principal"); + String configuredUser = null; + // A Kerberos module can follow other modules in the JAAS chain. + for (AppConfigurationEntry configuredEntry : entries) { + Object configuredValue = configuredEntry.getOptions().get("principal"); + if (configuredValue instanceof String configuredPrincipal && !configuredPrincipal.isEmpty()) { + configuredUser = configuredPrincipal; + break; + } + Object username = configuredEntry.getOptions().get("username"); + if (configuredUser == null && username instanceof String && !((String) username).isEmpty()) { + configuredUser = (String) username; + } + } + if (configuredUser != null) { + auditPrincipal = configuredUser; + } + return principalOption instanceof String ? (String) principalOption : null; + } + return null; + } + + private String getAuditUser(Subject loginSubject) { + if (loginSubject != null) { + for (KerberosPrincipal kerberosPrincipal : loginSubject.getPrincipals(KerberosPrincipal.class)) { + return kerberosPrincipal.getName(); + } + // SecurityUtils uses the public credential as the DIGEST-MD5 username. + for (String username : loginSubject.getPublicCredentials(String.class)) { + if (!username.isEmpty()) { + return username; + } + } + } + return auditPrincipal; + } + + private void audit(String user, String operation, Result result) { + try { + // An early client must not freeze audit configuration while auditing is disabled. + if (Boolean.getBoolean(ZKAuditProvider.AUDIT_ENABLE)) { + ZKAuditProvider.log(user, operation, result); + } + } catch (RuntimeException | LinkageError e) { + LOG.error("Unable to audit {} ({}) for {}", operation, result, user, e); } - LoginContext loginContext = new LoginContext(loginContextName, newCallbackHandler()); - loginContext.login(); - LOG.info("{} successfully logged in.", loginContextName); - return loginContext; } private String getLoginContextMessage() { @@ -387,7 +448,7 @@ private synchronized KerberosTicket getTGT() { return null; } - private boolean hasSufficientTimeElapsed() { + private boolean tryBeginReLogin() { long now = Time.currentElapsedTime(); if (now - getLastLogin() < MIN_TIME_BEFORE_RELOGIN) { LOG.warn("Not attempting to re-login since the last re-login was " @@ -437,7 +498,7 @@ public long getLastLogin() { * @throws javax.security.auth.login.LoginException on a failure */ // c.f. HADOOP-6559 - private synchronized void reLogin() throws LoginException { + synchronized void reLogin() throws LoginException { if (!isKrbTicket) { return; } @@ -445,21 +506,24 @@ private synchronized void reLogin() throws LoginException { if (login == null) { throw new LoginException("login must be done first"); } - if (!hasSufficientTimeElapsed()) { + if (!tryBeginReLogin()) { return; } + String user = getAuditUser(subject); LOG.info("Initiating logout for {}", principal); synchronized (Login.class) { - //clear up the kerberos state. But the tokens are not cleared! As per - //the Java kerberos login module code, only the kerberos credentials - //are cleared - logout(); - //login and also update the subject field of this instance to - //have the new credentials (pass it to the LoginContext constructor) - login = new LoginContext(loginContextName, getSubject()); - LOG.info("Initiating re-login for {}", principal); - login.login(); - setLogin(login); + try { + logout(); + login = new LoginContext(loginContextName, getSubject()); + LOG.info("Initiating re-login for {}", principal); + login.login(); + setLogin(login); + auditPrincipal = getAuditUser(login.getSubject()); + audit(auditPrincipal, AuditConstants.OP_TICKET_RENEWAL, Result.SUCCESS); + } catch (LoginException e) { + audit(user, AuditConstants.OP_TICKET_RENEWAL, Result.FAILURE); + throw e; + } } } @@ -469,7 +533,14 @@ protected synchronized void logout() throws LoginException { // are not logged in. Since Java 9 this could result in an NPE. // See ZOOKEEPER-4477 for more details. if (subject != null && !subject.getPrincipals().isEmpty()) { - login.logout(); + String user = getAuditUser(subject); + try { + login.logout(); + audit(user, AuditConstants.OP_LOGOUT, Result.SUCCESS); + } catch (LoginException e) { + audit(user, AuditConstants.OP_LOGOUT, Result.FAILURE); + throw e; + } } } diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/audit/AuditConstants.java b/zookeeper-server/src/main/java/org/apache/zookeeper/audit/AuditConstants.java index 22fd8567abe..2ae2bf30e7f 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/audit/AuditConstants.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/audit/AuditConstants.java @@ -24,6 +24,9 @@ private AuditConstants() { static final String OP_START = "serverStart"; static final String OP_STOP = "serverStop"; + public static final String OP_LOGIN = "login"; + public static final String OP_LOGOUT = "logout"; + public static final String OP_TICKET_RENEWAL = "ticketRenewal"; public static final String OP_CREATE = "create"; public static final String OP_DELETE = "delete"; public static final String OP_SETDATA = "setData"; diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/audit/ZKAuditProvider.java b/zookeeper-server/src/main/java/org/apache/zookeeper/audit/ZKAuditProvider.java index 864d2366c97..f33dc133f41 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/audit/ZKAuditProvider.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/audit/ZKAuditProvider.java @@ -25,29 +25,60 @@ import org.slf4j.LoggerFactory; public class ZKAuditProvider { - static final String AUDIT_ENABLE = "zookeeper.audit.enable"; + /** + * System property that enables audit logging. + */ + public static final String AUDIT_ENABLE = "zookeeper.audit.enable"; static final String AUDIT_IMPL_CLASS = "zookeeper.audit.impl.class"; private static final Logger LOG = LoggerFactory.getLogger(ZKAuditProvider.class); - // By default audit logging is disabled - private static boolean auditEnabled; - private static AuditLogger auditLogger; - - static { - auditEnabled = Boolean.getBoolean(AUDIT_ENABLE); - if (auditEnabled) { - //initialise only when audit logging is enabled - auditLogger = getAuditLogger(); - LOG.info("ZooKeeper audit is enabled."); - } else { - LOG.info("ZooKeeper audit is disabled."); + private static String selectedAuditLoggerClass; + + // Parsing server configuration must not initialize the audit logger. + private static class AuditState { + private static final boolean auditEnabled; + private static final AuditLogger auditLogger; + private static final RuntimeException initializationFailure; + + static { + String loggerClass = null; + synchronized (ZKAuditProvider.class) { + auditEnabled = Boolean.getBoolean(AUDIT_ENABLE); + if (auditEnabled) { + loggerClass = System.getProperty(AUDIT_IMPL_CLASS, Slf4jAuditLogger.class.getName()); + selectedAuditLoggerClass = loggerClass; + } + } + AuditLogger logger = null; + RuntimeException failure = null; + if (auditEnabled) { + try { + logger = getAuditLogger(loggerClass); + LOG.info("ZooKeeper audit is enabled."); + } catch (RuntimeException | LinkageError e) { + failure = new IllegalStateException("Couldn't initialize audit logger " + loggerClass, e); + } + } else { + LOG.info("ZooKeeper audit is disabled."); + } + auditLogger = logger; + initializationFailure = failure; } } - private static AuditLogger getAuditLogger() { - String auditLoggerClass = System.getProperty(AUDIT_IMPL_CLASS); - if (auditLoggerClass == null) { - auditLoggerClass = Slf4jAuditLogger.class.getName(); + /** + * Configures the audit logger class without initializing the logger. + * + * @throws IllegalArgumentException if another audit logger class has already been selected + */ + public static synchronized void configureAuditLogger(String loggerClass) { + if (selectedAuditLoggerClass != null && !selectedAuditLoggerClass.equals(loggerClass)) { + throw new IllegalArgumentException("Audit logger is already selected as " + selectedAuditLoggerClass + + "; cannot configure " + loggerClass + ". Set " + AUDIT_IMPL_CLASS + " before using the audit provider."); } + System.setProperty(AUDIT_IMPL_CLASS, loggerClass); + } + + private static AuditLogger getAuditLogger(String auditLoggerClass) { try { Constructor clientCxnConstructor = Class.forName(auditLoggerClass) .getDeclaredConstructor(); @@ -60,15 +91,29 @@ private static AuditLogger getAuditLogger() { } /** - * @return true if audit log is enabled + * Initializes the audit state and reports any logger initialization failure. + * + * @throws IllegalStateException if the audit logger could not be initialized + */ + public static void checkAuditState() { + if (AuditState.initializationFailure != null) { + throw AuditState.initializationFailure; + } + } + + /** + * @return true if audit logging is configured as enabled */ public static boolean isAuditEnabled() { - return auditEnabled; + return AuditState.auditEnabled; } public static void log(String user, String operation, String znode, String acl, String createMode, String session, String ip, Result result) { - auditLogger.logAuditEvent(createLogEvent(user, operation, znode, acl, createMode, session, ip, result)); + if (isAuditEnabled()) { + checkAuditState(); + AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, znode, acl, createMode, session, ip, result)); + } } /** @@ -111,15 +156,26 @@ public static void addZKStartStopAuditLog() { /** * Add audit log for server start fail. + * Audit errors must not prevent the server from exiting with its intended code. */ public static void addServerStartFailureAuditLog() { - if (isAuditEnabled()) { - log(ZKAuditProvider.getZKUser(), AuditConstants.OP_START, Result.FAILURE); + try { + if (isAuditEnabled()) { + log(ZKAuditProvider.getZKUser(), AuditConstants.OP_START, Result.FAILURE); + } + } catch (RuntimeException | LinkageError e) { + LOG.error("Unable to audit server startup failure", e); } } - private static void log(String user, String operation, Result result) { - auditLogger.logAuditEvent(createLogEvent(user, operation, result)); + /** + * Logs an operation without session, IP, or znode fields when auditing is enabled. + */ + public static void log(String user, String operation, Result result) { + if (isAuditEnabled()) { + checkAuditState(); + AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, result)); + } } /** diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServerMain.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServerMain.java index 0545827c893..1de9244be91 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServerMain.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServerMain.java @@ -119,6 +119,8 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti * @throws AdminServerException */ public void runFromConfig(ServerConfig config) throws IOException, AdminServerException { + // Validate auditing before starting metrics, transaction storage, or listeners. + ZKAuditProvider.checkAuditState(); LOG.info("Starting server"); FileTxnSnapLog txnLog = null; try { diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/embedded/ZooKeeperServerEmbeddedImpl.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/embedded/ZooKeeperServerEmbeddedImpl.java index 14e7cbbb7e9..ddcacd489a3 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/embedded/ZooKeeperServerEmbeddedImpl.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/embedded/ZooKeeperServerEmbeddedImpl.java @@ -10,6 +10,7 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; import javax.security.sasl.SaslException; +import org.apache.zookeeper.audit.ZKAuditProvider; import org.apache.zookeeper.server.DatadirCleanupManager; import org.apache.zookeeper.server.ExitCode; import org.apache.zookeeper.server.ServerConfig; @@ -85,6 +86,8 @@ public void start() throws Exception { @Override public void start(long startupTimeout) throws Exception { + // Validate before scheduling purge or starting the server thread. + ZKAuditProvider.checkAuditState(); switch (exitHandler) { case EXIT: ServiceUtils.setSystemExitProcedure(ServiceUtils.SYSTEM_EXIT); diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java index eb034527c2a..0636334e63a 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerConfig.java @@ -38,6 +38,7 @@ import java.util.Map.Entry; import java.util.Properties; import org.apache.yetus.audience.InterfaceAudience; +import org.apache.zookeeper.audit.ZKAuditProvider; import org.apache.zookeeper.common.AtomicFileWritingIdiom; import org.apache.zookeeper.common.AtomicFileWritingIdiom.OutputStreamStatement; import org.apache.zookeeper.common.AtomicFileWritingIdiom.WriterStatement; @@ -379,6 +380,8 @@ public void parseProperties(Properties zkProp) throws IOException, ConfigExcepti multiAddressReachabilityCheckEnabled = parseBoolean(key, value); } else if (key.equals("oraclePath")) { oraclePath = value; + } else if (key.equals("audit.impl.class")) { + ZKAuditProvider.configureAuditLogger(value); } else { System.setProperty("zookeeper." + key, value); } diff --git a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerMain.java b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerMain.java index 3fb3d6bf313..e1f32cf3239 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerMain.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/QuorumPeerMain.java @@ -123,6 +123,8 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti QuorumPeerConfig config = new QuorumPeerConfig(); if (args.length == 1) { config.parse(args[0]); + // The purge task can access server data before runFromConfig is called. + ZKAuditProvider.checkAuditState(); } // Start and schedule the purge task @@ -143,6 +145,8 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti } public void runFromConfig(QuorumPeerConfig config) throws IOException, AdminServerException { + // Validate auditing before starting metrics, transaction storage, or listeners. + ZKAuditProvider.checkAuditState(); try { ManagedUtil.registerLog4jMBeans(); } catch (JMException e) { diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java new file mode 100644 index 00000000000..06c2e53bc5e --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java @@ -0,0 +1,131 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.zookeeper; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import java.nio.file.Path; +import java.util.Map; +import java.util.Properties; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicReference; +import javax.security.auth.login.AppConfigurationEntry; +import javax.security.auth.login.Configuration; +import org.apache.zookeeper.audit.AuditEvent; +import org.apache.zookeeper.audit.AuditLogger; +import org.apache.zookeeper.audit.Slf4jAuditLogger; +import org.apache.zookeeper.audit.ZKAuditProvider; +import org.apache.zookeeper.common.ConfigException; +import org.apache.zookeeper.common.ZKConfig; +import org.apache.zookeeper.server.auth.DigestLoginModule; +import org.apache.zookeeper.server.embedded.ZooKeeperServerEmbedded; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; + +// Surefire runs this class in a fresh JVM so audit initialization can be blocked. +public class LoginAuditConcurrentInitializationTest extends ZKTestCase { + + @TempDir + Path tempDir; + + @Test + public void testConfigurationRejectsConflictWhileAuditLoggerInitializes() throws Exception { + Configuration previousConfiguration = Configuration.getConfiguration(); + System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "true"); + System.setProperty("zookeeper.audit.impl.class", BlockingAuditLogger.class.getName()); + AtomicReference clientLogin = new AtomicReference<>(); + AtomicReference clientFailure = new AtomicReference<>(); + Configuration.setConfiguration(new Configuration() { + @Override + public AppConfigurationEntry[] getAppConfigurationEntry(String name) { + return new AppConfigurationEntry[]{new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "audit-test", "password", "test-password"))}; + } + }); + Thread client = new Thread(() -> { + try { + clientLogin.set(new Login("Client", () -> callbacks -> { }, new ZKConfig())); + } catch (Throwable e) { + clientFailure.set(e); + } + }); + try { + client.start(); + assertTrue(BlockingAuditLogger.initializeEntered.await(5, TimeUnit.SECONDS)); + Properties config = new Properties(); + config.setProperty("audit.enable", "true"); + config.setProperty("audit.impl.class", Slf4jAuditLogger.class.getName()); + config.setProperty("tickTime", "2000"); + ConfigException failure = assertThrows(ConfigException.class, () -> { + try (ZooKeeperServerEmbedded server = ZooKeeperServerEmbedded.builder() + .baseDir(tempDir).configuration(config).build()) { + assertNotNull(server); + } + }); + assertTrue(failure.getCause() instanceof IllegalArgumentException); + assertTrue(failure.getCause().getMessage().contains(BlockingAuditLogger.class.getName())); + assertTrue(failure.getCause().getMessage().contains(Slf4jAuditLogger.class.getName())); + assertEquals(BlockingAuditLogger.class.getName(), System.getProperty("zookeeper.audit.impl.class")); + } finally { + BlockingAuditLogger.initializeRelease.countDown(); + client.join(TimeUnit.SECONDS.toMillis(5)); + try { + if (clientLogin.get() != null) { + clientLogin.get().shutdown(); + clientLogin.get().logout(); + } + } finally { + Configuration.setConfiguration(previousConfiguration); + System.clearProperty(ZKAuditProvider.AUDIT_ENABLE); + System.clearProperty("zookeeper.audit.impl.class"); + } + } + assertFalse(client.isAlive()); + assertNull(clientFailure.get()); + assertNotNull(clientLogin.get()); + assertTrue(clientLogin.get().getSubject().getPublicCredentials().contains("audit-test")); + } + + public static class BlockingAuditLogger implements AuditLogger { + + private static final CountDownLatch initializeEntered = new CountDownLatch(1); + private static final CountDownLatch initializeRelease = new CountDownLatch(1); + + @Override + public void initialize() { + initializeEntered.countDown(); + try { + assertTrue(initializeRelease.await(10, TimeUnit.SECONDS), "Audit initialization timed out"); + } catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new IllegalStateException(e); + } + } + + @Override + public void logAuditEvent(AuditEvent event) { + } + } +} diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java new file mode 100644 index 00000000000..4bd5f5927c1 --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java @@ -0,0 +1,126 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.zookeeper; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import java.nio.charset.StandardCharsets; +import java.nio.file.Path; +import java.util.Map; +import javax.security.auth.login.AppConfigurationEntry; +import javax.security.auth.login.Configuration; +import javax.security.auth.login.LoginContext; +import javax.security.auth.login.LoginException; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.AuditEvent.Result; +import org.apache.zookeeper.audit.Slf4jAuditLogger; +import org.apache.zookeeper.audit.ZKAuditProvider; +import org.apache.zookeeper.common.ZKConfig; +import org.apache.zookeeper.server.auth.DigestLoginModule; +import org.apache.zookeeper.test.LoggerTestTool; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; + +// Surefire runs this class in a separate JVM: audit configuration is initialized once. +public class LoginAuditDisabledTest extends ZKTestCase { + + @TempDir + Path tempDir; + + @BeforeAll + public static void disableAudit() { + System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "false"); + } + + @AfterAll + public static void clearAuditProperty() { + System.clearProperty(ZKAuditProvider.AUDIT_ENABLE); + } + + @Test + public void testDisabledAuditDoesNotAffectLogin() throws Exception { + Configuration previousConfiguration = Configuration.getConfiguration(); + try (LoggerTestTool logger = new LoggerTestTool(Slf4jAuditLogger.class)) { + Configuration.setConfiguration(new Configuration() { + @Override + public AppConfigurationEntry[] getAppConfigurationEntry(String name) { + return new AppConfigurationEntry[]{new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "audit-test", "password", "test-password"))}; + } + }); + assertFalse(ZKAuditProvider.isAuditEnabled()); + Login login = new Login("Client", () -> callbacks -> { }, new ZKConfig()); + try { + login.logout(); + } finally { + login.shutdown(); + } + assertThrows(LoginException.class, () -> new Login(null, () -> callbacks -> { }, new ZKConfig())); + assertEquals("", logger.getOutputStream().toString(StandardCharsets.UTF_8)); + } finally { + Configuration.setConfiguration(previousConfiguration); + } + } + + @Test + public void testDisabledAuditProviderIgnoresEvents() throws Exception { + try (LoggerTestTool logger = new LoggerTestTool(Slf4jAuditLogger.class)) { + ZKAuditProvider.checkAuditState(); + assertFalse(ZKAuditProvider.isAuditEnabled()); + ZKAuditProvider.log("user", AuditConstants.OP_LOGIN, Result.SUCCESS); + ZKAuditProvider.log("user", AuditConstants.OP_LOGIN, null, null, null, null, null, Result.SUCCESS); + assertEquals("", logger.getOutputStream().toString(StandardCharsets.UTF_8)); + } + } + + @Test + public void testNonStringPrincipalPreservesJaasFailureWhenAuditDisabled() throws Exception { + Configuration previousConfiguration = Configuration.getConfiguration(); + try (LoggerTestTool logger = new LoggerTestTool(Slf4jAuditLogger.class)) { + Configuration.setConfiguration(new Configuration() { + @Override + public AppConfigurationEntry[] getAppConfigurationEntry(String name) { + return new AppConfigurationEntry[]{ + new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "audit-test", "password", "test-password", "principal", 42)), + new AppConfigurationEntry( + "com.sun.security.auth.module.Krb5LoginModule", + AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("principal", "client@EXAMPLE.COM", "useTicketCache", "true", + "ticketCache", tempDir.resolve("missing-cache").toString(), + "useKeyTab", "false", "doNotPrompt", "true"))}; + } + }); + LoginContext jaasLogin = new LoginContext("Client", callbacks -> { }); + LoginException expected = assertThrows(LoginException.class, jaasLogin::login); + LoginException actual = assertThrows( + LoginException.class, () -> new Login("Client", () -> callbacks -> { }, new ZKConfig())); + assertEquals(expected.getClass(), actual.getClass()); + assertEquals(expected.getMessage(), actual.getMessage()); + assertEquals("", logger.getOutputStream().toString(StandardCharsets.UTF_8)); + } finally { + Configuration.setConfiguration(previousConfiguration); + } + } +} diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java new file mode 100644 index 00000000000..ef90b09f482 --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java @@ -0,0 +1,182 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.zookeeper; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import java.io.Writer; +import java.nio.charset.StandardCharsets; +import java.nio.file.Files; +import java.nio.file.Path; +import java.util.Map; +import java.util.Properties; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; +import javax.security.auth.login.AppConfigurationEntry; +import javax.security.auth.login.Configuration; +import javax.security.auth.login.LoginException; +import org.apache.zookeeper.audit.AuditConstants; +import org.apache.zookeeper.audit.AuditEvent; +import org.apache.zookeeper.audit.AuditLogger; +import org.apache.zookeeper.audit.ZKAuditProvider; +import org.apache.zookeeper.common.ZKConfig; +import org.apache.zookeeper.server.DatadirCleanupManager; +import org.apache.zookeeper.server.ExitCode; +import org.apache.zookeeper.server.ServerConfig; +import org.apache.zookeeper.server.ZooKeeperServerMain; +import org.apache.zookeeper.server.auth.DigestLoginModule; +import org.apache.zookeeper.server.embedded.ExitHandler; +import org.apache.zookeeper.server.embedded.ZooKeeperServerEmbedded; +import org.apache.zookeeper.server.quorum.QuorumPeerConfig; +import org.apache.zookeeper.server.quorum.QuorumPeerMain; +import org.apache.zookeeper.test.LoggerTestTool; +import org.apache.zookeeper.util.ServiceUtils; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; + +public class LoginAuditInitializationFailureTest extends ZKTestCase { + + @TempDir + Path tempDir; + + @Test + public void testClientAuditFailurePreservesJaasAndFailsServerStartupClearly() throws Exception { + Configuration previousConfiguration = Configuration.getConfiguration(); + System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "true"); + System.setProperty("zookeeper.audit.impl.class", FailingAuditLogger.class.getName()); + try (LoggerTestTool logger = new LoggerTestTool(Login.class)) { + Configuration.setConfiguration(new Configuration() { + @Override + public AppConfigurationEntry[] getAppConfigurationEntry(String name) { + return new AppConfigurationEntry[]{new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "audit-test", "password", "test-password"))}; + } + }); + Login login = new Login("Client", () -> callbacks -> { }, new ZKConfig()); + try { + assertTrue(login.getSubject().getPublicCredentials().contains("audit-test")); + LoginException failure = assertThrows(LoginException.class, + () -> new Login(null, () -> callbacks -> { }, new ZKConfig())); + assertTrue(failure.getMessage().contains("loginContext name")); + assertTrue(ZKAuditProvider.isAuditEnabled()); + assertInitializationFailure(assertThrows(IllegalStateException.class, ZKAuditProvider::checkAuditState)); + assertInitializationFailure(assertThrows(IllegalStateException.class, + () -> ZKAuditProvider.log("audit-test", AuditConstants.OP_LOGIN, AuditEvent.Result.SUCCESS))); + assertInitializationFailure(assertThrows(IllegalStateException.class, + () -> ZKAuditProvider.log("audit-test", AuditConstants.OP_LOGIN, + null, null, null, null, null, AuditEvent.Result.SUCCESS))); + + Properties properties = new Properties(); + properties.setProperty("dataDir", tempDir.toString()); + properties.setProperty("tickTime", "2000"); + properties.setProperty("clientPort", "0"); + QuorumPeerConfig quorumConfig = new QuorumPeerConfig(); + quorumConfig.parseProperties(properties); + ServerConfig standaloneConfig = new ServerConfig(); + standaloneConfig.readFrom(quorumConfig); + assertInitializationFailure(assertThrows(IllegalStateException.class, + () -> new ZooKeeperServerMain().runFromConfig(standaloneConfig))); + + Files.writeString(tempDir.resolve("myid"), "1"); + properties.setProperty("initLimit", "5"); + properties.setProperty("syncLimit", "2"); + properties.setProperty("server.1", "127.0.0.1:2888:3888"); + properties.setProperty("server.2", "127.0.0.1:2889:3889"); + QuorumPeerConfig distributedConfig = new QuorumPeerConfig(); + distributedConfig.parseProperties(properties); + assertTrue(distributedConfig.isDistributed()); + assertInitializationFailure(assertThrows(IllegalStateException.class, + () -> new QuorumPeerMain().runFromConfig(distributedConfig))); + try (LoggerTestTool purgeLogger = new LoggerTestTool(DatadirCleanupManager.class)) { + String[] args = {tempDir.resolve("missing.cfg").toString()}; + assertStartupExitCode(() -> ZooKeeperServerMain.main(args), ExitCode.INVALID_INVOCATION); + assertStartupExitCode(() -> QuorumPeerMain.main(args), ExitCode.INVALID_INVOCATION); + properties.setProperty("autopurge.purgeInterval", "1"); + Path configFile = tempDir.resolve("zoo.cfg"); + try (Writer writer = Files.newBufferedWriter(configFile)) { + properties.store(writer, null); + } + assertStartupExitCode(() -> QuorumPeerMain.main(new String[]{configFile.toString()}), + ExitCode.UNEXPECTED_ERROR); + assertEquals("", purgeLogger.getOutputStream().toString(StandardCharsets.UTF_8)); + try (ZooKeeperServerEmbedded server = ZooKeeperServerEmbedded.builder() + .baseDir(tempDir).configuration(properties).exitHandler(ExitHandler.LOG_ONLY).build()) { + assertInitializationFailure(assertThrows(IllegalStateException.class, + () -> server.start(TimeUnit.SECONDS.toMillis(5)))); + } + assertEquals("", purgeLogger.getOutputStream().toString(StandardCharsets.UTF_8)); + } + assertFalse(Files.exists(tempDir.resolve("version-2"))); + assertEquals(1, FailingAuditLogger.initializations.get()); + String messages = logger.getOutputStream().toString(StandardCharsets.UTF_8); + assertTrue(messages.contains(FailingAuditLogger.class.getName())); + assertTrue(messages.contains(FailingAuditLogger.failure.getMessage())); + } finally { + login.logout(); + } + } finally { + Configuration.setConfiguration(previousConfiguration); + System.clearProperty(ZKAuditProvider.AUDIT_ENABLE); + System.clearProperty("zookeeper.audit.impl.class"); + } + } + + private void assertStartupExitCode(Runnable startup, ExitCode expectedExitCode) { + RuntimeException exit = new RuntimeException("test system exit"); + ServiceUtils.setSystemExitProcedure(code -> { + assertEquals(expectedExitCode.getValue(), code); + throw exit; + }); + try { + assertSame(exit, assertThrows(RuntimeException.class, startup::run)); + } finally { + ServiceUtils.setSystemExitProcedure(ServiceUtils.LOG_ONLY); + } + } + + private void assertInitializationFailure(IllegalStateException failure) { + assertTrue(failure.getMessage().contains(FailingAuditLogger.class.getName())); + Throwable cause = failure; + while (cause.getCause() != null) { + cause = cause.getCause(); + } + assertSame(FailingAuditLogger.failure, cause); + } + + public static class FailingAuditLogger implements AuditLogger { + + private static final AtomicInteger initializations = new AtomicInteger(); + private static final IllegalStateException failure = new IllegalStateException("test audit initialization failure"); + + @Override + public void initialize() { + initializations.incrementAndGet(); + throw failure; + } + + @Override + public void logAuditEvent(AuditEvent event) { + throw new AssertionError("the uninitialized logger must not be used"); + } + } +} diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java new file mode 100644 index 00000000000..0b73b9ebe5c --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java @@ -0,0 +1,96 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.zookeeper; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; +import java.nio.charset.StandardCharsets; +import java.nio.file.Path; +import java.util.Map; +import java.util.Properties; +import javax.security.auth.login.AppConfigurationEntry; +import javax.security.auth.login.Configuration; +import org.apache.zookeeper.audit.Slf4jAuditLogger; +import org.apache.zookeeper.audit.ZKAuditProvider; +import org.apache.zookeeper.common.ZKConfig; +import org.apache.zookeeper.server.auth.DigestLoginModule; +import org.apache.zookeeper.server.embedded.ZooKeeperServerEmbedded; +import org.apache.zookeeper.test.LoggerTestTool; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; + +// Surefire runs each class in a fresh JVM because the audit provider initializes once. +public class LoginAuditInitializationTest extends ZKTestCase { + + @TempDir + Path tempDir; + + @Test + public void testClientLoginBeforeEmbeddedServerDoesNotDisableAudit() throws Exception { + Configuration previousConfiguration = Configuration.getConfiguration(); + System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "false"); + try (LoggerTestTool logger = new LoggerTestTool(Slf4jAuditLogger.class)) { + Configuration.setConfiguration(new Configuration() { + @Override + public AppConfigurationEntry[] getAppConfigurationEntry(String name) { + return new AppConfigurationEntry[]{new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "audit-test", "password", "test-password"))}; + } + }); + Login clientLogin = new Login("Client", () -> callbacks -> { }, new ZKConfig()); + clientLogin.logout(); + assertEquals("", logger.getOutputStream().toString(StandardCharsets.UTF_8)); + + Properties config = new Properties(); + config.setProperty("audit.enable", "true"); + config.setProperty("audit.impl.class", TestAuditLogger.class.getName()); + config.setProperty("tickTime", "2000"); + try (ZooKeeperServerEmbedded server = ZooKeeperServerEmbedded.builder() + .baseDir(tempDir).configuration(config).build()) { + assertFalse(TestAuditLogger.initialized); + ZKAuditProvider.checkAuditState(); + assertTrue(ZKAuditProvider.isAuditEnabled()); + assertTrue(TestAuditLogger.initialized); + Login serverLogin = new Login("Server", () -> callbacks -> { }, new ZKConfig()); + try { + assertTrue(logger.getOutputStream().toString(StandardCharsets.UTF_8) + .contains("user=audit-test\toperation=login\tresult=success")); + } finally { + serverLogin.logout(); + } + } + } finally { + Configuration.setConfiguration(previousConfiguration); + System.clearProperty(ZKAuditProvider.AUDIT_ENABLE); + System.clearProperty("zookeeper.audit.impl.class"); + } + } + + public static class TestAuditLogger extends Slf4jAuditLogger { + + private static boolean initialized; + + @Override + public void initialize() { + initialized = true; + } + } +} diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java new file mode 100644 index 00000000000..0f6cd8bea0d --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java @@ -0,0 +1,546 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.apache.zookeeper; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import java.nio.charset.StandardCharsets; +import java.nio.file.Path; +import java.util.Arrays; +import java.util.Date; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.Properties; +import java.util.concurrent.TimeUnit; +import java.util.stream.Collectors; +import javax.security.auth.Subject; +import javax.security.auth.callback.CallbackHandler; +import javax.security.auth.kerberos.KerberosPrincipal; +import javax.security.auth.kerberos.KerberosTicket; +import javax.security.auth.login.AppConfigurationEntry; +import javax.security.auth.login.Configuration; +import javax.security.auth.login.LoginContext; +import javax.security.auth.login.LoginException; +import javax.security.auth.spi.LoginModule; +import org.apache.zookeeper.audit.AuditEvent; +import org.apache.zookeeper.audit.Slf4jAuditLogger; +import org.apache.zookeeper.audit.ZKAuditProvider; +import org.apache.zookeeper.common.ConfigException; +import org.apache.zookeeper.common.Time; +import org.apache.zookeeper.common.ZKConfig; +import org.apache.zookeeper.server.ExitCode; +import org.apache.zookeeper.server.ZooKeeperServerMain; +import org.apache.zookeeper.server.auth.DigestLoginModule; +import org.apache.zookeeper.server.embedded.ZooKeeperServerEmbedded; +import org.apache.zookeeper.server.quorum.QuorumPeerMain; +import org.apache.zookeeper.test.LoggerTestTool; +import org.apache.zookeeper.util.ServiceUtils; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.ValueSource; + +public class LoginAuditTest extends ZKTestCase { + + private static final String CONTEXT = "AuditTest"; + private static final String USER = "client@EXAMPLE.COM"; + private static final String CONFIGURED_USER = "configured@EXAMPLE.COM"; + private static final String LOGIN_STATE_OPTION = "testState"; + private Configuration previousConfiguration; + private LoggerTestTool logger; + private TestLogin login; + private LoginState loginState; + private TestAuditLogger auditLogger; + + @TempDir + Path tempDir; + + @BeforeAll + public static void enableAudit() { + System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "true"); + System.setProperty("zookeeper.audit.impl.class", TestAuditLogger.class.getName()); + assertTrue(ZKAuditProvider.isAuditEnabled()); + } + + @AfterAll + public static void clearAuditProperty() { + System.clearProperty(ZKAuditProvider.AUDIT_ENABLE); + System.clearProperty("zookeeper.audit.impl.class"); + } + + @BeforeEach + public void setUp() { + previousConfiguration = Configuration.getConfiguration(); + logger = new LoggerTestTool(Slf4jAuditLogger.class); + auditLogger = TestAuditLogger.instance; + auditLogger.failAudit = false; + auditLogger.failLinkage = false; + loginState = new LoginState(); + configure(true, false); + } + + @AfterEach + public void tearDown() throws Exception { + try { + auditLogger.failAudit = false; + auditLogger.failLinkage = false; + if (login != null) { + login.shutdown(); + loginState.failLogout = false; + login.logout(); + } + } finally { + Configuration.setConfiguration(previousConfiguration); + logger.close(); + } + } + + @Test + public void testLoginUsesAuthenticatedPrincipal() throws Exception { + login = new TestLogin(new ZKConfig()); + assertEquals(CONFIGURED_USER, login.getUserName()); + assertMessages("user=" + USER + "\toperation=login\tresult=success"); + } + + @Test + public void testLoginWithoutConfiguredPrincipal() throws Exception { + configure(false, false); + login = new TestLogin(new ZKConfig()); + assertEquals(Login.SYSTEM_USER, login.getUserName()); + assertMessages("user=" + USER + "\toperation=login\tresult=success"); + } + + @Test + public void testDigestLoginUsesSubjectUsername() throws Exception { + configure(CONTEXT, new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "digest\n\t-client", "password", "private-test-password", "principal", CONFIGURED_USER))); + login = new TestLogin(new ZKConfig()); + assertEquals(CONFIGURED_USER, login.getUserName()); + assertMessages("user=digest-client\toperation=login\tresult=success"); + } + + @ParameterizedTest + @ValueSource(strings = {CONTEXT, "other"}) + public void testFailedDigestLoginUsesConfiguredUsername(String contextName) throws Exception { + configure(contextName, new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "digest-client", "password", 42))); + LoginContext jaasLogin = new LoginContext(CONTEXT, callbacks -> { }); + LoginException expected = assertThrows(LoginException.class, jaasLogin::login); + LoginException actual = assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); + assertEquals(expected.getClass(), actual.getClass()); + assertTrue(actual.getMessage().contains("ClassCastException")); + assertMessages("user=digest-client\toperation=login\tresult=failure"); + } + + @Test + public void testKerberosPrincipalTakesPrecedenceOverDigestUsername() throws Exception { + configure(CONTEXT, + new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "digest-client", "password", "test-password")), + new AppConfigurationEntry( + TestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("principal", CONFIGURED_USER))); + login = new TestLogin(new ZKConfig()); + assertMessages("user=" + USER + "\toperation=login\tresult=success"); + } + + @Test + public void testFailedLoginUsesConfiguredPrincipalAndPreservesException() { + loginState.failLogin = true; + LoginException failure = assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); + assertSame(loginState.loginFailure, failure); + assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); + } + + @ParameterizedTest + @ValueSource(strings = {CONTEXT, "other"}) + public void testNonStringPrincipalPreservesJaasFailure(String contextName) throws Exception { + configure(contextName, + new AppConfigurationEntry( + DigestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("username", "audit-test", "password", "test-password", "principal", 42)), + new AppConfigurationEntry( + "com.sun.security.auth.module.Krb5LoginModule", AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, + Map.of("principal", CONFIGURED_USER, "useTicketCache", "true", + "ticketCache", tempDir.resolve("missing-cache").toString(), + "useKeyTab", "false", "doNotPrompt", "true"))); + LoginContext jaasLogin = new LoginContext(CONTEXT, callbacks -> { }); + LoginException expected = assertThrows(LoginException.class, jaasLogin::login); + LoginException actual = assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); + assertEquals(expected.getClass(), actual.getClass()); + assertEquals(expected.getMessage(), actual.getMessage()); + assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testAuditFailureDoesNotInterruptSuccessfulLogin(boolean linkageFailure) throws Exception { + auditLogger.failAudit = true; + auditLogger.failLinkage = linkageFailure; + try (LoggerTestTool loginLogger = new LoggerTestTool(Login.class)) { + login = new TestLogin(new ZKConfig()); + assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(USER))); + assertTrue(loginLogger.getOutputStream().toString(StandardCharsets.UTF_8).contains("Unable to audit login")); + } + } + + @Test + public void testAuditFailurePreservesFailedLogin() { + auditLogger.failAudit = true; + loginState.failLogin = true; + assertSame(loginState.loginFailure, assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig()))); + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testStartupAuditFailurePreservesExitCode(boolean linkageFailure) throws Exception { + auditLogger.failAudit = true; + auditLogger.failLinkage = linkageFailure; + RuntimeException exit = new RuntimeException("test system exit"); + ServiceUtils.setSystemExitProcedure(code -> { + assertEquals(ExitCode.INVALID_INVOCATION.getValue(), code); + throw exit; + }); + try (LoggerTestTool providerLogger = new LoggerTestTool(ZKAuditProvider.class)) { + String[] args = {tempDir.resolve("missing.cfg").toString()}; + assertSame(exit, assertThrows(RuntimeException.class, () -> ZooKeeperServerMain.main(args))); + assertSame(exit, assertThrows(RuntimeException.class, () -> QuorumPeerMain.main(args))); + assertTrue(providerLogger.getOutputStream().toString(StandardCharsets.UTF_8) + .contains("Unable to audit server startup failure")); + } finally { + ServiceUtils.setSystemExitProcedure(ServiceUtils.LOG_ONLY); + } + } + + @Test + public void testMissingLoginContextIsAudited() { + assertThrows(LoginException.class, () -> new Login("Missing", () -> callbacks -> { }, new ZKConfig())); + assertMessages("user=" + Login.SYSTEM_USER + "\toperation=login\tresult=failure"); + } + + @Test + public void testNullLoginContextIsAudited() { + assertThrows(LoginException.class, () -> new Login(null, () -> callbacks -> { }, new ZKConfig())); + assertMessages("user=" + Login.SYSTEM_USER + "\toperation=login\tresult=failure"); + } + + @Test + public void testLogoutIsAuditedOnlyWhenPerformed() throws Exception { + login = new TestLogin(new ZKConfig()); + clearMessages(); + login.logout(); + login.logout(); + assertMessages("user=" + USER + "\toperation=logout\tresult=success"); + } + + @Test + public void testFailedLogoutPreservesException() throws Exception { + login = new TestLogin(new ZKConfig()); + clearMessages(); + loginState.failLogout = true; + assertSame(loginState.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); + assertMessages("user=" + USER + "\toperation=logout\tresult=failure"); + } + + @Test + public void testAuditFailurePreservesFailedLogout() throws Exception { + login = new TestLogin(new ZKConfig()); + auditLogger.failAudit = true; + loginState.failLogout = true; + assertSame(loginState.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); + } + + @Test + public void testRenewedPrincipalIsRetainedAcrossFailedRetries() throws Exception { + configure(false, true); + login = new TestLogin(new ZKConfig()); + clearMessages(); + String renewedUser = "renewed@EXAMPLE.COM"; + loginState.authenticatedUser = renewedUser; + login.reLogin(); + assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(renewedUser))); + loginState.failLogin = true; + assertSame(loginState.loginFailure, assertThrows(LoginException.class, login::reLogin)); + assertSame(loginState.loginFailure, assertThrows(LoginException.class, login::reLogin)); + assertMessages("user=" + USER + "\toperation=logout\tresult=success", + "user=" + renewedUser + "\toperation=ticketRenewal\tresult=success", + "user=" + renewedUser + "\toperation=logout\tresult=success", + "user=" + renewedUser + "\toperation=ticketRenewal\tresult=failure", + "user=" + renewedUser + "\toperation=ticketRenewal\tresult=failure"); + } + + @Test + public void testAuditFailureDoesNotInterruptRenewal() throws Exception { + login = new TestLogin(new ZKConfig()); + auditLogger.failAudit = true; + login.reLogin(); + assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(USER))); + assertEquals(1, login.getSubject().getPrivateCredentials(KerberosTicket.class).size()); + } + + @Test + public void testAuditFailurePreservesFailedRenewal() throws Exception { + login = new TestLogin(new ZKConfig()); + auditLogger.failAudit = true; + loginState.failLogin = true; + assertSame(loginState.loginFailure, assertThrows(LoginException.class, login::reLogin)); + assertTrue(login.getSubject().getPrincipals().isEmpty()); + } + + @Test + public void testFailedRenewalRetainsPrincipalAcrossRetries() throws Exception { + configure(false, false); + login = new TestLogin(new ZKConfig()); + clearMessages(); + loginState.failLogin = true; + assertSame(loginState.loginFailure, assertThrows(LoginException.class, login::reLogin)); + assertSame(loginState.loginFailure, assertThrows(LoginException.class, login::reLogin)); + assertMessages("user=" + USER + "\toperation=logout\tresult=success", + "user=" + USER + "\toperation=ticketRenewal\tresult=failure", + "user=" + USER + "\toperation=ticketRenewal\tresult=failure"); + } + + @Test + public void testRenewalFailureDuringLogout() throws Exception { + login = new TestLogin(new ZKConfig()); + clearMessages(); + loginState.failLogout = true; + assertSame(loginState.logoutFailure, assertThrows(LoginException.class, login::reLogin)); + assertMessages("user=" + USER + "\toperation=logout\tresult=failure", + "user=" + USER + "\toperation=ticketRenewal\tresult=failure"); + } + + @Test + public void testSkippedRenewalIsNotAudited() throws Exception { + login = new TestLogin(new ZKConfig()); + clearMessages(); + login.allowReLogin = false; + login.reLogin(); + assertMessages(); + } + + @Test + public void testRenewalWithoutKerberosTicketIsNotAudited() throws Exception { + loginState.includeTicket = false; + login = new TestLogin(new ZKConfig()); + clearMessages(); + login.reLogin(); + login.shutdown(); + assertMessages(); + } + + @Test + public void testTicketCacheRefreshFailuresAreAudited() throws Exception { + configure(false, true); + ZKConfig config = new ZKConfig(); + config.setProperty(ZKConfig.KINIT_COMMAND, tempDir.resolve("missing-kinit").toString()); + login = new TestLogin(config); + clearMessages(); + login.startThreadIfNeeded(); + waitFor("ticket cache refresh failures were not audited", () -> messages().size() == 2, 5); + login.shutdown(); + assertMessages("user=" + USER + "\toperation=ticketRenewal\tresult=failure", + "user=" + USER + "\toperation=ticketRenewal\tresult=failure"); + } + + @Test + public void testEmbeddedServerRejectsDifferentAuditLogger() throws Exception { + login = new TestLogin(new ZKConfig()); + ConfigException failure = assertThrows(ConfigException.class, () -> { + try (ZooKeeperServerEmbedded server = createEmbeddedServer(Slf4jAuditLogger.class.getName())) { + assertNotNull(server); + } + }); + assertTrue(failure.getCause() instanceof IllegalArgumentException); + assertTrue(failure.getCause().getMessage().contains(TestAuditLogger.class.getName())); + assertTrue(failure.getCause().getMessage().contains(Slf4jAuditLogger.class.getName())); + assertEquals(TestAuditLogger.class.getName(), System.getProperty("zookeeper.audit.impl.class")); + clearMessages(); + login.logout(); + assertMessages("user=" + USER + "\toperation=logout\tresult=success"); + } + + @Test + public void testEmbeddedServerAcceptsSelectedAuditLogger() throws Exception { + try (ZooKeeperServerEmbedded server = createEmbeddedServer(TestAuditLogger.class.getName())) { + assertNotNull(server); + } + } + + private ZooKeeperServerEmbedded createEmbeddedServer(String auditLoggerClass) throws Exception { + Properties config = new Properties(); + config.setProperty("audit.enable", "true"); + config.setProperty("audit.impl.class", auditLoggerClass); + config.setProperty("tickTime", "2000"); + return ZooKeeperServerEmbedded.builder().baseDir(tempDir).configuration(config).build(); + } + + private void configure(boolean configuredPrincipal, boolean ticketCache) { + Map options = new HashMap<>(); + options.put(LOGIN_STATE_OPTION, loginState); + if (configuredPrincipal) { + options.put("principal", CONFIGURED_USER); + } + options.put("useTicketCache", Boolean.toString(ticketCache)); + configure(CONTEXT, new AppConfigurationEntry( + TestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, options)); + } + + private void configure(String contextName, AppConfigurationEntry... entries) { + Configuration.setConfiguration(new Configuration() { + @Override + public AppConfigurationEntry[] getAppConfigurationEntry(String name) { + if (!contextName.equals(name)) { + return null; + } + return entries; + } + }); + } + + private void clearMessages() { + logger.getOutputStream().reset(); + } + + private List messages() { + return logger.getOutputStream().toString(StandardCharsets.UTF_8).lines() + .map(line -> line.substring(line.indexOf("user="))) + .collect(Collectors.toList()); + } + + private void assertMessages(String... expected) { + assertEquals(Arrays.asList(expected), messages()); + } + + private static class TestLogin extends Login { + + private boolean allowReLogin = true; + + TestLogin(ZKConfig config) throws LoginException { + super(CONTEXT, () -> callbacks -> { }, config); + } + + @Override + public long getLastLogin() { + return allowReLogin ? Time.currentElapsedTime() - TimeUnit.HOURS.toMillis(1) : Time.currentElapsedTime(); + } + + @Override + protected void sleepBeforeRetryFailedRefresh() { + } + } + + public static class TestAuditLogger extends Slf4jAuditLogger { + + private static TestAuditLogger instance; + private boolean failAudit; + private boolean failLinkage; + + public TestAuditLogger() { + instance = this; + } + + @Override + public void logAuditEvent(AuditEvent event) { + if (failAudit) { + if (failLinkage) { + throw new NoSuchMethodError("test audit backend linkage failure"); + } + throw new IllegalStateException("test audit backend failure"); + } + super.logAuditEvent(event); + } + } + + private static class LoginState { + + private boolean failLogin; + private boolean failLogout; + private boolean includeTicket = true; + private String authenticatedUser = USER; + private final LoginException loginFailure = new LoginException("test login failure"); + private final LoginException logoutFailure = new LoginException("test logout failure"); + } + + // Exercises JAAS without a KDC. + public static class TestLoginModule implements LoginModule { + + private static final int AES128_KEY_TYPE = 17; + private static final int AES128_KEY_BYTES = 16; + private LoginState state; + private Subject subject; + + @Override + public void initialize(Subject subject, CallbackHandler handler, Map sharedState, Map options) { + this.subject = subject; + Object configuredState = options.get(LOGIN_STATE_OPTION); + state = configuredState instanceof LoginState ? (LoginState) configuredState : new LoginState(); + } + + @Override + public boolean login() throws LoginException { + if (state.failLogin) { + throw state.loginFailure; + } + return true; + } + + @Override + public boolean commit() { + KerberosPrincipal client = new KerberosPrincipal(state.authenticatedUser); + subject.getPrincipals().add(client); + if (state.includeTicket) { + long now = System.currentTimeMillis(); + Date start = new Date(now - TimeUnit.HOURS.toMillis(1)); + subject.getPrivateCredentials().add(new KerberosTicket( + new byte[]{1}, client, new KerberosPrincipal("krbtgt/EXAMPLE.COM@EXAMPLE.COM"), + new byte[AES128_KEY_BYTES], AES128_KEY_TYPE, null, + start, start, new Date(now + TimeUnit.SECONDS.toMillis(10)), + new Date(now + TimeUnit.HOURS.toMillis(1)), null)); + } + return true; + } + + @Override + public boolean abort() { + return true; + } + + @Override + public boolean logout() throws LoginException { + if (state.failLogout) { + throw state.logoutFailure; + } + subject.getPrincipals().clear(); + subject.getPrivateCredentials().clear(); + return true; + } + } +} diff --git a/zookeeper-website/app/pages/_docs/docs/_mdx/admin-ops/monitor-and-audit-logs.mdx b/zookeeper-website/app/pages/_docs/docs/_mdx/admin-ops/monitor-and-audit-logs.mdx index c5481ecd986..802f462bf13 100644 --- a/zookeeper-website/app/pages/_docs/docs/_mdx/admin-ops/monitor-and-audit-logs.mdx +++ b/zookeeper-website/app/pages/_docs/docs/_mdx/admin-ops/monitor-and-audit-logs.mdx @@ -265,24 +265,23 @@ See the [Four Letter Words section](/admin-ops/administrators-guide/commands) in ## Audit Logs Apache ZooKeeper supports audit logging from version 3.6.0. By default audit logs are disabled. -To enable them, set `audit.enable=true` in `conf/zoo.cfg`. Audit logs are not written on every -ZooKeeper server — they are written only on the servers to which a client is connected, as -illustrated below. +To enable them, set `audit.enable=true` in `conf/zoo.cfg`. Audit logs for client znode operations +are written only on the servers to which a client is connected, as illustrated below. ![Audit Logs](/docs-images/zkAuditLogs.jpg) The audit log captures detailed information for audited operations, written as `key=value` pairs: -| Key | Value | -| ------------ | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `session` | Client session ID. | -| `user` | Comma-separated list of users associated with the client session. See [Who is taken as user in audit logs?](#who-is-taken-as-user-in-audit-logs) | -| `ip` | Client IP address. | -| `operation` | The audited operation. Possible values: `serverStart`, `serverStop`, `create`, `delete`, `setData`, `setAcl`, `multiOperation`, `reconfig`, `ephemeralZNodeDeleteOnSessionClose`. | -| `znode` | Path of the znode. | -| `znode type` | Type of the znode (only for `create` operations). | -| `acl` | String representation of the znode ACL, e.g. `cdrwa` (create, delete, read, write, admin). Only logged for `setAcl`. | -| `result` | Outcome of the operation: `success`, `failure`, or `invoked`. The `invoked` result is used for `serverStop` because the stop is logged before the server has confirmed it actually stopped. | +| Key | Value | +| ------------ | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `session` | Client session ID. | +| `user` | User associated with the operation. Client znode operations list all authenticated identities, separated by commas. See [Who is taken as user in audit logs?](#who-is-taken-as-user-in-audit-logs) | +| `ip` | Client IP address. | +| `operation` | The audited operation. Possible values: `serverStart`, `serverStop`, `login`, `logout`, `ticketRenewal`, `create`, `delete`, `setData`, `setAcl`, `multiOperation`, `reconfig`, `ephemeralZNodeDeleteOnSessionClose`. | +| `znode` | Path of the znode. | +| `znode type` | Type of the znode (only for `create` operations). | +| `acl` | String representation of the znode ACL, e.g. `cdrwa` (create, delete, read, write, admin). Only logged for `setAcl`. | +| `result` | Outcome of the operation: `success`, `failure`, or `invoked`. The `invoked` result is used for `serverStop` because the stop is logged before the server has confirmed it actually stopped. | Sample audit logs for all operations, where the client connected from `192.168.1.2`, client principal is `zkcli@HADOOP.COM`, and server principal is `zookeeper/192.168.1.3@HADOOP.COM`: @@ -307,6 +306,42 @@ session=0x19344730000 user=192.168.1.2,zkcli@HADOOP.COM ip=192.168.1.2 ope user=zookeeper/192.168.1.3 operation=serverStop result=invoked ``` +**New in 3.10.0:** ZooKeeper also logs JAAS `login`, `logout`, and Kerberos `ticketRenewal` +events on clients and servers, including quorum members. These events describe the local +process's JAAS credentials. They do not record incoming client or quorum learner SASL +authentication failures. For DIGEST-MD5, a successful JAAS login loads the credentials; +SASL authentication happens later. Each event contains `user`, `operation`, and `result`, +without a session ID, IP address, or znode path. To enable client audit logs, set +`-Dzookeeper.audit.enable=true` and configure the audit logger in the client JVM. + +The `user` field uses the authenticated Kerberos principal or the DIGEST-MD5 username from the +JAAS subject. If neither is available, ZooKeeper uses the first configured `principal` in the +JAAS module chain (including the `other` fallback), then the configured `username`, then the +OS user. Renewal failures keep the identity from the last successful login. + +Each failed cache refresh command or JAAS re-login records a `ticketRenewal` failure event. +A successful re-login records `success`; skipped attempts produce no event. The `logout` +event also covers the logout performed during Kerberos re-login and does not indicate a client +disconnection. Stopping only the refresh thread does not log a logout. + +If the audit logger throws `RuntimeException` or `LinkageError` during a JAAS operation, +ZooKeeper writes the error to the regular log. These errors do not change the JAAS result. +ZooKeeper retains logger initialization failures and reports the original cause on subsequent +audit calls and server startup. When recording a failed server start, these audit errors do not +change the server's exit code. + +Each JVM uses one audit logger. For a custom logger, set `zookeeper.audit.impl.class` to its fully +qualified class name before the audit provider is first used. An audited client login can select +the logger before an embedded server reads its configuration. A later server configuration +that requests a different logger class fails; configuring the same class again is allowed. + +``` +user=zkcli@HADOOP.COM operation=login result=success +user=zkcli@HADOOP.COM operation=logout result=success +user=zkcli@HADOOP.COM operation=ticketRenewal result=success +user=zkcli@HADOOP.COM operation=ticketRenewal result=failure +``` + ### Audit Log Configuration Audit logging is performed using Logback. The following is the default logback configuration