From 9c0dbf2d362f186e33c2a7e14cece0ba3a773829 Mon Sep 17 00:00:00 2001 From: Ivan Khanas Date: Mon, 12 Oct 2026 10:14:30 +0200 Subject: [PATCH 1/4] ZOOKEEPER-4922: Audit JAAS login, logout and Kerberos ticket renewal Record authentication lifecycle events and retain the authenticated principal across failed renewal attempts. Preserve JAAS results when the audit backend throws runtime or linkage errors. Reject conflicting late audit logger configuration before changing the selected backend. Cover enabled, disabled, failed and concurrent initialization and document the audit configuration order. --- .../main/java/org/apache/zookeeper/Login.java | 131 +++-- .../zookeeper/audit/AuditConstants.java | 3 + .../zookeeper/audit/ZKAuditProvider.java | 68 ++- .../server/quorum/QuorumPeerConfig.java | 3 + ...oginAuditConcurrentInitializationTest.java | 131 +++++ .../zookeeper/LoginAuditDisabledTest.java | 126 +++++ .../LoginAuditInitializationFailureTest.java | 84 +++ .../LoginAuditInitializationTest.java | 95 ++++ .../org/apache/zookeeper/LoginAuditTest.java | 529 ++++++++++++++++++ .../_mdx/admin-ops/monitor-and-audit-logs.mdx | 55 +- 10 files changed, 1155 insertions(+), 70 deletions(-) create mode 100644 zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java create mode 100644 zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java create mode 100644 zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java create mode 100644 zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java create mode 100644 zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java 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..263645d11de 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,72 @@ 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"); + // 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()) { + auditPrincipal = configuredPrincipal; + break; + } + } + 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(); + } + } + 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 +434,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 " @@ -445,21 +492,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 +519,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..b329c0e7245 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,52 @@ 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; + 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; - 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."); + 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; + } + } + if (auditEnabled) { + auditLogger = getAuditLogger(loggerClass); + LOG.info("ZooKeeper audit is enabled."); + } else { + auditLogger = null; + LOG.info("ZooKeeper audit is disabled."); + } } } - 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(); @@ -63,12 +86,12 @@ private static AuditLogger getAuditLogger() { * @return true if audit log is 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)); + AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, znode, acl, createMode, session, ip, result)); } /** @@ -118,8 +141,13 @@ public static void addServerStartFailureAuditLog() { } } - 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()) { + AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, result)); + } } /** 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/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java new file mode 100644 index 00000000000..2e2da3ef895 --- /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(5000); + 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..4fb1c66220b --- /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)) { + assertFalse(ZKAuditProvider.isAuditEnabled()); + ZKAuditProvider.log("user", AuditConstants.OP_LOGIN, Result.SUCCESS); + ZKAuditProvider.log("user", AuditConstants.OP_LOGOUT, Result.FAILURE); + ZKAuditProvider.log("user", AuditConstants.OP_TICKET_RENEWAL, 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..dc56dd6209a --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java @@ -0,0 +1,84 @@ +/* + * 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.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import java.nio.charset.StandardCharsets; +import java.util.Map; +import javax.security.auth.login.AppConfigurationEntry; +import javax.security.auth.login.Configuration; +import javax.security.auth.login.LoginException; +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.auth.DigestLoginModule; +import org.apache.zookeeper.test.LoggerTestTool; +import org.junit.jupiter.api.Test; + +// A failed static initialization leaves the provider unusable for the rest of this JVM. +public class LoginAuditInitializationFailureTest extends ZKTestCase { + + @Test + public void testAuditInitializationFailurePreservesJaasResults() 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")); + String messages = logger.getOutputStream().toString(StandardCharsets.UTF_8); + assertTrue(messages.contains("ExceptionInInitializerError")); + assertTrue(messages.contains("NoClassDefFoundError")); + } finally { + login.logout(); + } + } finally { + Configuration.setConfiguration(previousConfiguration); + System.clearProperty(ZKAuditProvider.AUDIT_ENABLE); + System.clearProperty("zookeeper.audit.impl.class"); + } + } + + public static class FailingAuditLogger implements AuditLogger { + + @Override + public void initialize() { + throw new IllegalStateException("test audit initialization 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..0d566a8b6e8 --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java @@ -0,0 +1,95 @@ +/* + * 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); + assertTrue(ZKAuditProvider.isAuditEnabled()); + assertTrue(TestAuditLogger.initialized); + Login serverLogin = new Login("Server", () -> callbacks -> { }, new ZKConfig()); + try { + assertTrue(logger.getOutputStream().toString(StandardCharsets.UTF_8) + .contains("user=" + Login.SYSTEM_USER + "\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..0ace61ab3c1 --- /dev/null +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java @@ -0,0 +1,529 @@ +/* + * 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.lang.reflect.InvocationTargetException; +import java.lang.reflect.Method; +import java.nio.charset.StandardCharsets; +import java.nio.file.Files; +import java.nio.file.Path; +import java.security.URIParameter; +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.auth.DigestLoginModule; +import org.apache.zookeeper.server.embedded.ZooKeeperServerEmbedded; +import org.apache.zookeeper.test.LoggerTestTool; +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 Configuration previousConfiguration; + private LoggerTestTool logger; + private TestLogin login; + + @TempDir + Path tempDir; + + @BeforeAll + public static void enableAudit() { + System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "true"); + System.setProperty("zookeeper.audit.impl.class", TestAuditLogger.class.getName()); + } + + @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); + TestAuditLogger.failAudit = false; + TestAuditLogger.failLinkage = false; + TestLoginModule.failLogin = false; + TestLoginModule.failLogout = false; + TestLoginModule.includeTicket = true; + TestLoginModule.authenticatedUser = USER; + TestLoginModule.loginFailure = new LoginException("test login failure"); + TestLoginModule.logoutFailure = new LoginException("test logout failure"); + configure(true, false); + } + + @AfterEach + public void tearDown() throws Exception { + try { + TestAuditLogger.failAudit = false; + if (login != null) { + login.shutdown(); + TestLoginModule.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 testFailedLoginUsesConfiguredPrincipalAndPreservesException() { + TestLoginModule.failLogin = true; + LoginException failure = assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); + assertSame(TestLoginModule.loginFailure, failure); + assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); + } + + @Test + public void testFailedLoginUsesPrincipalFromLaterModule() throws Exception { + configureFailingKerberosChain(CONTEXT); + assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); + assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); + } + + @Test + public void testNonStringPrincipalPreservesJaasFailure() throws Exception { + configure(CONTEXT, + 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"); + } + + @Test + public void testFailedLoginUsesOtherFallbackPrincipal() throws Exception { + configureFailingKerberosChain("other"); + assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); + assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testAuditFailureDoesNotInterruptSuccessfulLogin(boolean linkageFailure) throws Exception { + TestAuditLogger.failAudit = true; + TestAuditLogger.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")); + } + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testAuditFailurePreservesFailedLogin(boolean linkageFailure) { + TestAuditLogger.failAudit = true; + TestAuditLogger.failLinkage = linkageFailure; + TestLoginModule.failLogin = true; + assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig()))); + } + + @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(); + TestLoginModule.failLogout = true; + assertSame(TestLoginModule.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); + assertMessages("user=" + USER + "\toperation=logout\tresult=failure"); + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testAuditFailurePreservesFailedLogout(boolean linkageFailure) throws Exception { + login = new TestLogin(new ZKConfig()); + TestAuditLogger.failAudit = true; + TestAuditLogger.failLinkage = linkageFailure; + TestLoginModule.failLogout = true; + assertSame(TestLoginModule.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); + } + + @Test + public void testRenewalAuditsLogoutAndRenewal() throws Exception { + login = new TestLogin(new ZKConfig()); + clearMessages(); + reLogin(); + assertMessages("user=" + USER + "\toperation=logout\tresult=success", + "user=" + USER + "\toperation=ticketRenewal\tresult=success"); + } + + @Test + public void testRenewedPrincipalIsRetainedAcrossFailedRetries() throws Exception { + configure(false, true); + login = new TestLogin(new ZKConfig()); + clearMessages(); + String renewedUser = "renewed@EXAMPLE.COM"; + TestLoginModule.authenticatedUser = renewedUser; + reLogin(); + assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(renewedUser))); + TestLoginModule.failLogin = true; + assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); + assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::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"); + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testAuditFailureDoesNotInterruptRenewal(boolean linkageFailure) throws Exception { + login = new TestLogin(new ZKConfig()); + TestAuditLogger.failAudit = true; + TestAuditLogger.failLinkage = linkageFailure; + reLogin(); + assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(USER))); + assertEquals(1, login.getSubject().getPrivateCredentials(KerberosTicket.class).size()); + } + + @ParameterizedTest + @ValueSource(booleans = {false, true}) + public void testAuditFailurePreservesFailedRenewal(boolean linkageFailure) throws Exception { + login = new TestLogin(new ZKConfig()); + TestAuditLogger.failAudit = true; + TestAuditLogger.failLinkage = linkageFailure; + TestLoginModule.failLogin = true; + assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); + assertTrue(login.getSubject().getPrincipals().isEmpty()); + } + + @Test + public void testFailedRenewalRetainsPrincipalAcrossRetries() throws Exception { + configure(false, false); + login = new TestLogin(new ZKConfig()); + clearMessages(); + TestLoginModule.failLogin = true; + assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); + assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::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(); + TestLoginModule.failLogout = true; + assertSame(TestLoginModule.logoutFailure, assertThrows(LoginException.class, this::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; + reLogin(); + assertMessages(); + } + + @Test + public void testRenewalWithoutKerberosTicketIsNotAudited() throws Exception { + TestLoginModule.includeTicket = false; + login = new TestLogin(new ZKConfig()); + clearMessages(); + 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 { + login = new TestLogin(new ZKConfig()); + clearMessages(); + try (ZooKeeperServerEmbedded server = createEmbeddedServer(TestAuditLogger.class.getName())) { + assertNotNull(server); + ZKAuditProvider.addZKStartStopAuditLog(); + assertMessages("user=" + Login.SYSTEM_USER + "\toperation=serverStart\tresult=success"); + } + } + + 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<>(); + 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 configureFailingKerberosChain(String contextName) throws Exception { + Path jaasFile = tempDir.resolve("jaas.conf"); + Files.writeString(jaasFile, contextName + " {\n" + + TestLoginModule.class.getName() + " required;\n" + + "com.sun.security.auth.module.Krb5LoginModule required\n" + + "principal=\"" + CONFIGURED_USER + "\" useTicketCache=true\n" + + "ticketCache=\"" + tempDir.resolve("missing-cache") + "\"\n" + + "useKeyTab=false doNotPrompt=true;\n};\n"); + Configuration.setConfiguration(Configuration.getInstance("JavaLoginConfig", new URIParameter(jaasFile.toUri()))); + } + + 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 reLogin() throws Exception { + Method method = Login.class.getDeclaredMethod("reLogin"); + method.setAccessible(true); + try { + method.invoke(login); + } catch (InvocationTargetException e) { + if (e.getCause() instanceof LoginException) { + throw (LoginException) e.getCause(); + } + throw e; + } + } + + 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 boolean failAudit; + private static boolean failLinkage; + + @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); + } + } + + // A stub login module exercises JAAS without a KDC. + public static class TestLoginModule implements LoginModule { + + private static boolean failLogin; + private static boolean failLogout; + private static boolean includeTicket; + private static String authenticatedUser; + private static LoginException loginFailure; + private static LoginException logoutFailure; + private Subject subject; + + @Override + public void initialize(Subject subject, CallbackHandler handler, Map sharedState, Map options) { + this.subject = subject; + } + + @Override + public boolean login() throws LoginException { + if (failLogin) { + throw loginFailure; + } + return true; + } + + @Override + public boolean commit() { + KerberosPrincipal client = new KerberosPrincipal(authenticatedUser); + subject.getPrincipals().add(client); + if (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[16], 17, new boolean[32], start, start, new Date(now + 10000), + new Date(now + TimeUnit.HOURS.toMillis(1)), null)); + } + return true; + } + + @Override + public boolean abort() { + return true; + } + + @Override + public boolean logout() throws LoginException { + if (failLogout) { + throw 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..8b68c9bef13 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,36 @@ 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. 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 when available. Otherwise, +ZooKeeper uses the first configured `principal` in the JAAS module chain (including the `other` +fallback), or the OS user if no principal is configured. Renewal failures keep the principal +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. + +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 From 085c73b51bffccdf1085fa4e4750e3140180a2e6 Mon Sep 17 00:00:00 2001 From: Ivan Khanas Date: Thu, 15 Oct 2026 00:41:03 +0200 Subject: [PATCH 2/4] ZOOKEEPER-4922: Correct audit identity and initialization failures Use the DIGEST subject username and configured username fallback without changing legacy getUserName behavior. Retain logger initialization errors and reject server startup before opening server data. Exercise renewal directly through package-private access, isolate JAAS fixture state per test, and clarify the local credential audit scope. --- .../main/java/org/apache/zookeeper/Login.java | 18 +- .../zookeeper/audit/ZKAuditProvider.java | 22 +- .../zookeeper/server/ZooKeeperServerMain.java | 2 + .../server/quorum/QuorumPeerMain.java | 2 + ...oginAuditConcurrentInitializationTest.java | 2 +- .../zookeeper/LoginAuditDisabledTest.java | 3 +- .../LoginAuditInitializationFailureTest.java | 68 +++++- .../LoginAuditInitializationTest.java | 2 +- .../org/apache/zookeeper/LoginAuditTest.java | 218 ++++++++++-------- .../_mdx/admin-ops/monitor-and-audit-logs.mdx | 17 +- 10 files changed, 233 insertions(+), 121 deletions(-) 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 263645d11de..b4eca51dd4a 100644 --- a/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java +++ b/zookeeper-server/src/main/java/org/apache/zookeeper/Login.java @@ -357,13 +357,21 @@ private String readLoginConfiguration(String loginContextName) { 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()) { - auditPrincipal = configuredPrincipal; + 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; } @@ -375,6 +383,12 @@ private String getAuditUser(Subject loginSubject) { 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; } @@ -484,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; } 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 b329c0e7245..7757ff1d4eb 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 @@ -37,6 +37,7 @@ public class ZKAuditProvider { private static class AuditState { private static final boolean auditEnabled; private static final AuditLogger auditLogger; + private static final RuntimeException initializationFailure; static { String loggerClass = null; @@ -47,13 +48,20 @@ private static class AuditState { selectedAuditLoggerClass = loggerClass; } } + AuditLogger logger = null; + RuntimeException failure = null; if (auditEnabled) { - auditLogger = getAuditLogger(loggerClass); - LOG.info("ZooKeeper audit is enabled."); + 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 { - auditLogger = null; LOG.info("ZooKeeper audit is disabled."); } + auditLogger = logger; + initializationFailure = failure; } } @@ -84,14 +92,20 @@ private static AuditLogger getAuditLogger(String auditLoggerClass) { /** * @return true if audit log is enabled + * @throws IllegalStateException if the audit logger could not be initialized */ public static boolean isAuditEnabled() { + if (AuditState.initializationFailure != null) { + throw AuditState.initializationFailure; + } return AuditState.auditEnabled; } public static void log(String user, String operation, String znode, String acl, String createMode, String session, String ip, Result result) { - AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, znode, acl, createMode, session, ip, result)); + if (isAuditEnabled()) { + AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, znode, acl, createMode, session, ip, 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..25ce012bba4 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 opening server resources, including after an earlier client login. + ZKAuditProvider.isAuditEnabled(); LOG.info("Starting server"); FileTxnSnapLog txnLog = null; try { 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..f6aa791c805 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 @@ -143,6 +143,8 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti } public void runFromConfig(QuorumPeerConfig config) throws IOException, AdminServerException { + // Validate auditing before opening server resources, including after an earlier client login. + ZKAuditProvider.isAuditEnabled(); 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 index 2e2da3ef895..06c2e53bc5e 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditConcurrentInitializationTest.java @@ -90,7 +90,7 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { assertEquals(BlockingAuditLogger.class.getName(), System.getProperty("zookeeper.audit.impl.class")); } finally { BlockingAuditLogger.initializeRelease.countDown(); - client.join(5000); + client.join(TimeUnit.SECONDS.toMillis(5)); try { if (clientLogin.get() != null) { clientLogin.get().shutdown(); diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java index 4fb1c66220b..a60f463af9a 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java @@ -87,8 +87,7 @@ public void testDisabledAuditProviderIgnoresEvents() throws Exception { try (LoggerTestTool logger = new LoggerTestTool(Slf4jAuditLogger.class)) { assertFalse(ZKAuditProvider.isAuditEnabled()); ZKAuditProvider.log("user", AuditConstants.OP_LOGIN, Result.SUCCESS); - ZKAuditProvider.log("user", AuditConstants.OP_LOGOUT, Result.FAILURE); - ZKAuditProvider.log("user", AuditConstants.OP_TICKET_RENEWAL, Result.SUCCESS); + ZKAuditProvider.log("user", AuditConstants.OP_LOGIN, null, null, null, null, null, Result.SUCCESS); assertEquals("", logger.getOutputStream().toString(StandardCharsets.UTF_8)); } } diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java index dc56dd6209a..b67420cb1e0 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java @@ -18,26 +18,41 @@ 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.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.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.ServerConfig; +import org.apache.zookeeper.server.ZooKeeperServerMain; import org.apache.zookeeper.server.auth.DigestLoginModule; +import org.apache.zookeeper.server.quorum.QuorumPeerConfig; +import org.apache.zookeeper.server.quorum.QuorumPeerMain; import org.apache.zookeeper.test.LoggerTestTool; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; -// A failed static initialization leaves the provider unusable for the rest of this JVM. public class LoginAuditInitializationFailureTest extends ZKTestCase { + @TempDir + Path tempDir; + @Test - public void testAuditInitializationFailurePreservesJaasResults() throws Exception { + public void testClientAuditFailurePreservesJaasAndFailsServerStartupClearly() throws Exception { Configuration previousConfiguration = Configuration.getConfiguration(); System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "true"); System.setProperty("zookeeper.audit.impl.class", FailingAuditLogger.class.getName()); @@ -56,9 +71,39 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { LoginException failure = assertThrows(LoginException.class, () -> new Login(null, () -> callbacks -> { }, new ZKConfig())); assertTrue(failure.getMessage().contains("loginContext name")); + assertInitializationFailure(assertThrows(IllegalStateException.class, ZKAuditProvider::isAuditEnabled)); + 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))); + assertFalse(Files.exists(tempDir.resolve("version-2"))); + assertEquals(1, FailingAuditLogger.initializations.get()); String messages = logger.getOutputStream().toString(StandardCharsets.UTF_8); - assertTrue(messages.contains("ExceptionInInitializerError")); - assertTrue(messages.contains("NoClassDefFoundError")); + assertTrue(messages.contains(FailingAuditLogger.class.getName())); + assertTrue(messages.contains(FailingAuditLogger.failure.getMessage())); } finally { login.logout(); } @@ -69,11 +114,24 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { } } + 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() { - throw new IllegalStateException("test audit initialization failure"); + initializations.incrementAndGet(); + throw failure; } @Override diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java index 0d566a8b6e8..e2af339fc41 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java @@ -71,7 +71,7 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { Login serverLogin = new Login("Server", () -> callbacks -> { }, new ZKConfig()); try { assertTrue(logger.getOutputStream().toString(StandardCharsets.UTF_8) - .contains("user=" + Login.SYSTEM_USER + "\toperation=login\tresult=success")); + .contains("user=audit-test\toperation=login\tresult=success")); } finally { serverLogin.logout(); } diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java index 0ace61ab3c1..b92a4a75129 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java @@ -23,8 +23,6 @@ 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.lang.reflect.InvocationTargetException; -import java.lang.reflect.Method; import java.nio.charset.StandardCharsets; import java.nio.file.Files; import java.nio.file.Path; @@ -69,9 +67,12 @@ 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; @@ -80,6 +81,7 @@ public class LoginAuditTest extends ZKTestCase { public static void enableAudit() { System.setProperty(ZKAuditProvider.AUDIT_ENABLE, "true"); System.setProperty("zookeeper.audit.impl.class", TestAuditLogger.class.getName()); + assertTrue(ZKAuditProvider.isAuditEnabled()); } @AfterAll @@ -92,24 +94,21 @@ public static void clearAuditProperty() { public void setUp() { previousConfiguration = Configuration.getConfiguration(); logger = new LoggerTestTool(Slf4jAuditLogger.class); - TestAuditLogger.failAudit = false; - TestAuditLogger.failLinkage = false; - TestLoginModule.failLogin = false; - TestLoginModule.failLogout = false; - TestLoginModule.includeTicket = true; - TestLoginModule.authenticatedUser = USER; - TestLoginModule.loginFailure = new LoginException("test login failure"); - TestLoginModule.logoutFailure = new LoginException("test logout failure"); + auditLogger = TestAuditLogger.instance; + auditLogger.failAudit = false; + auditLogger.failLinkage = false; + loginState = new LoginState(); configure(true, false); } @AfterEach public void tearDown() throws Exception { try { - TestAuditLogger.failAudit = false; + auditLogger.failAudit = false; + auditLogger.failLinkage = false; if (login != null) { login.shutdown(); - TestLoginModule.failLogout = false; + loginState.failLogout = false; login.logout(); } } finally { @@ -133,11 +132,48 @@ public void testLoginWithoutConfiguredPrincipal() throws Exception { 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() { - TestLoginModule.failLogin = true; + loginState.failLogin = true; LoginException failure = assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); - assertSame(TestLoginModule.loginFailure, failure); + assertSame(loginState.loginFailure, failure); assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); } @@ -177,8 +213,8 @@ public void testFailedLoginUsesOtherFallbackPrincipal() throws Exception { @ParameterizedTest @ValueSource(booleans = {false, true}) public void testAuditFailureDoesNotInterruptSuccessfulLogin(boolean linkageFailure) throws Exception { - TestAuditLogger.failAudit = true; - TestAuditLogger.failLinkage = linkageFailure; + 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))); @@ -186,13 +222,11 @@ public void testAuditFailureDoesNotInterruptSuccessfulLogin(boolean linkageFailu } } - @ParameterizedTest - @ValueSource(booleans = {false, true}) - public void testAuditFailurePreservesFailedLogin(boolean linkageFailure) { - TestAuditLogger.failAudit = true; - TestAuditLogger.failLinkage = linkageFailure; - TestLoginModule.failLogin = true; - assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig()))); + @Test + public void testAuditFailurePreservesFailedLogin() { + auditLogger.failAudit = true; + loginState.failLogin = true; + assertSame(loginState.loginFailure, assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig()))); } @Test @@ -220,28 +254,17 @@ public void testLogoutIsAuditedOnlyWhenPerformed() throws Exception { public void testFailedLogoutPreservesException() throws Exception { login = new TestLogin(new ZKConfig()); clearMessages(); - TestLoginModule.failLogout = true; - assertSame(TestLoginModule.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); + loginState.failLogout = true; + assertSame(loginState.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); assertMessages("user=" + USER + "\toperation=logout\tresult=failure"); } - @ParameterizedTest - @ValueSource(booleans = {false, true}) - public void testAuditFailurePreservesFailedLogout(boolean linkageFailure) throws Exception { - login = new TestLogin(new ZKConfig()); - TestAuditLogger.failAudit = true; - TestAuditLogger.failLinkage = linkageFailure; - TestLoginModule.failLogout = true; - assertSame(TestLoginModule.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); - } - @Test - public void testRenewalAuditsLogoutAndRenewal() throws Exception { + public void testAuditFailurePreservesFailedLogout() throws Exception { login = new TestLogin(new ZKConfig()); - clearMessages(); - reLogin(); - assertMessages("user=" + USER + "\toperation=logout\tresult=success", - "user=" + USER + "\toperation=ticketRenewal\tresult=success"); + auditLogger.failAudit = true; + loginState.failLogout = true; + assertSame(loginState.logoutFailure, assertThrows(LoginException.class, () -> login.logout())); } @Test @@ -250,12 +273,12 @@ public void testRenewedPrincipalIsRetainedAcrossFailedRetries() throws Exception login = new TestLogin(new ZKConfig()); clearMessages(); String renewedUser = "renewed@EXAMPLE.COM"; - TestLoginModule.authenticatedUser = renewedUser; - reLogin(); + loginState.authenticatedUser = renewedUser; + login.reLogin(); assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(renewedUser))); - TestLoginModule.failLogin = true; - assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); - assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); + 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", @@ -263,25 +286,21 @@ public void testRenewedPrincipalIsRetainedAcrossFailedRetries() throws Exception "user=" + renewedUser + "\toperation=ticketRenewal\tresult=failure"); } - @ParameterizedTest - @ValueSource(booleans = {false, true}) - public void testAuditFailureDoesNotInterruptRenewal(boolean linkageFailure) throws Exception { + @Test + public void testAuditFailureDoesNotInterruptRenewal() throws Exception { login = new TestLogin(new ZKConfig()); - TestAuditLogger.failAudit = true; - TestAuditLogger.failLinkage = linkageFailure; - reLogin(); + auditLogger.failAudit = true; + login.reLogin(); assertTrue(login.getSubject().getPrincipals().contains(new KerberosPrincipal(USER))); assertEquals(1, login.getSubject().getPrivateCredentials(KerberosTicket.class).size()); } - @ParameterizedTest - @ValueSource(booleans = {false, true}) - public void testAuditFailurePreservesFailedRenewal(boolean linkageFailure) throws Exception { + @Test + public void testAuditFailurePreservesFailedRenewal() throws Exception { login = new TestLogin(new ZKConfig()); - TestAuditLogger.failAudit = true; - TestAuditLogger.failLinkage = linkageFailure; - TestLoginModule.failLogin = true; - assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); + auditLogger.failAudit = true; + loginState.failLogin = true; + assertSame(loginState.loginFailure, assertThrows(LoginException.class, login::reLogin)); assertTrue(login.getSubject().getPrincipals().isEmpty()); } @@ -290,9 +309,9 @@ public void testFailedRenewalRetainsPrincipalAcrossRetries() throws Exception { configure(false, false); login = new TestLogin(new ZKConfig()); clearMessages(); - TestLoginModule.failLogin = true; - assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); - assertSame(TestLoginModule.loginFailure, assertThrows(LoginException.class, this::reLogin)); + 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"); @@ -302,8 +321,8 @@ public void testFailedRenewalRetainsPrincipalAcrossRetries() throws Exception { public void testRenewalFailureDuringLogout() throws Exception { login = new TestLogin(new ZKConfig()); clearMessages(); - TestLoginModule.failLogout = true; - assertSame(TestLoginModule.logoutFailure, assertThrows(LoginException.class, this::reLogin)); + loginState.failLogout = true; + assertSame(loginState.logoutFailure, assertThrows(LoginException.class, login::reLogin)); assertMessages("user=" + USER + "\toperation=logout\tresult=failure", "user=" + USER + "\toperation=ticketRenewal\tresult=failure"); } @@ -313,16 +332,16 @@ public void testSkippedRenewalIsNotAudited() throws Exception { login = new TestLogin(new ZKConfig()); clearMessages(); login.allowReLogin = false; - reLogin(); + login.reLogin(); assertMessages(); } @Test public void testRenewalWithoutKerberosTicketIsNotAudited() throws Exception { - TestLoginModule.includeTicket = false; + loginState.includeTicket = false; login = new TestLogin(new ZKConfig()); clearMessages(); - reLogin(); + login.reLogin(); login.shutdown(); assertMessages(); } @@ -360,12 +379,8 @@ public void testEmbeddedServerRejectsDifferentAuditLogger() throws Exception { @Test public void testEmbeddedServerAcceptsSelectedAuditLogger() throws Exception { - login = new TestLogin(new ZKConfig()); - clearMessages(); try (ZooKeeperServerEmbedded server = createEmbeddedServer(TestAuditLogger.class.getName())) { assertNotNull(server); - ZKAuditProvider.addZKStartStopAuditLog(); - assertMessages("user=" + Login.SYSTEM_USER + "\toperation=serverStart\tresult=success"); } } @@ -378,7 +393,8 @@ private ZooKeeperServerEmbedded createEmbeddedServer(String auditLoggerClass) th } private void configure(boolean configuredPrincipal, boolean ticketCache) { - Map options = new HashMap<>(); + Map options = new HashMap<>(); + options.put(LOGIN_STATE_OPTION, loginState); if (configuredPrincipal) { options.put("principal", CONFIGURED_USER); } @@ -410,19 +426,6 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { }); } - private void reLogin() throws Exception { - Method method = Login.class.getDeclaredMethod("reLogin"); - method.setAccessible(true); - try { - method.invoke(login); - } catch (InvocationTargetException e) { - if (e.getCause() instanceof LoginException) { - throw (LoginException) e.getCause(); - } - throw e; - } - } - private void clearMessages() { logger.getOutputStream().reset(); } @@ -457,8 +460,13 @@ protected void sleepBeforeRetryFailedRefresh() { public static class TestAuditLogger extends Slf4jAuditLogger { - private static boolean failAudit; - private static boolean failLinkage; + private static TestAuditLogger instance; + private boolean failAudit; + private boolean failLinkage; + + public TestAuditLogger() { + instance = this; + } @Override public void logAuditEvent(AuditEvent event) { @@ -472,40 +480,50 @@ public void logAuditEvent(AuditEvent event) { } } - // A stub login module exercises JAAS without a KDC. + 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 boolean failLogin; - private static boolean failLogout; - private static boolean includeTicket; - private static String authenticatedUser; - private static LoginException loginFailure; - private static LoginException logoutFailure; + 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 (failLogin) { - throw loginFailure; + if (state.failLogin) { + throw state.loginFailure; } return true; } @Override public boolean commit() { - KerberosPrincipal client = new KerberosPrincipal(authenticatedUser); + KerberosPrincipal client = new KerberosPrincipal(state.authenticatedUser); subject.getPrincipals().add(client); - if (includeTicket) { + 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[16], 17, new boolean[32], start, start, new Date(now + 10000), + 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; @@ -518,8 +536,8 @@ public boolean abort() { @Override public boolean logout() throws LoginException { - if (failLogout) { - throw logoutFailure; + if (state.failLogout) { + throw state.logoutFailure; } subject.getPrincipals().clear(); subject.getPrivateCredentials().clear(); 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 8b68c9bef13..7cee8537c9d 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 @@ -307,14 +307,17 @@ 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. Each event contains `user`, `operation`, -and `result`, without a session ID, IP address, or znode path. To enable client audit logs, set +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 when available. Otherwise, -ZooKeeper uses the first configured `principal` in the JAAS module chain (including the `other` -fallback), or the OS user if no principal is configured. Renewal failures keep the principal -from the last successful login. +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` @@ -323,6 +326,8 @@ 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. 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 From 26e1b7297a0ec0b161df464977961eeeb2eb550d Mon Sep 17 00:00:00 2001 From: Ivan Khanas Date: Fri, 16 Oct 2026 12:37:24 +0200 Subject: [PATCH 3/4] ZOOKEEPER-4922: Handle audit failures during server startup Preserve the startup exit code if auditing fails, and validate the logger before starting autopurge. Consolidate overlapping JAAS tests. --- .../zookeeper/audit/ZKAuditProvider.java | 9 ++- .../zookeeper/server/ZooKeeperServerMain.java | 2 +- .../embedded/ZooKeeperServerEmbeddedImpl.java | 3 + .../server/quorum/QuorumPeerMain.java | 4 +- .../LoginAuditInitializationFailureTest.java | 39 ++++++++++++ .../org/apache/zookeeper/LoginAuditTest.java | 59 +++++++++---------- .../_mdx/admin-ops/monitor-and-audit-logs.mdx | 3 +- 7 files changed, 84 insertions(+), 35 deletions(-) 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 7757ff1d4eb..86caf3e4ed6 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 @@ -148,10 +148,15 @@ 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); } } 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 25ce012bba4..c6c56fa4d75 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,7 +119,7 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti * @throws AdminServerException */ public void runFromConfig(ServerConfig config) throws IOException, AdminServerException { - // Validate auditing before opening server resources, including after an earlier client login. + // Validate auditing before starting metrics, transaction storage, or listeners. ZKAuditProvider.isAuditEnabled(); LOG.info("Starting server"); FileTxnSnapLog txnLog = null; 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..cc8a7fd2374 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.isAuditEnabled(); switch (exitHandler) { case EXIT: ServiceUtils.setSystemExitProcedure(ServiceUtils.SYSTEM_EXIT); 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 f6aa791c805..e33486b8ae7 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.isAuditEnabled(); } // Start and schedule the purge task @@ -143,7 +145,7 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti } public void runFromConfig(QuorumPeerConfig config) throws IOException, AdminServerException { - // Validate auditing before opening server resources, including after an earlier client login. + // Validate auditing before starting metrics, transaction storage, or listeners. ZKAuditProvider.isAuditEnabled(); try { ManagedUtil.registerLog4jMBeans(); diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java index b67420cb1e0..94c4f9a2bd9 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java @@ -23,11 +23,13 @@ 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; @@ -37,12 +39,17 @@ 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; @@ -99,6 +106,25 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { 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); @@ -114,6 +140,19 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { } } + 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; diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java index b92a4a75129..0f6cd8bea0d 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditTest.java @@ -24,9 +24,7 @@ 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.Files; import java.nio.file.Path; -import java.security.URIParameter; import java.util.Arrays; import java.util.Date; import java.util.HashMap; @@ -50,9 +48,13 @@ 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; @@ -177,16 +179,10 @@ public void testFailedLoginUsesConfiguredPrincipalAndPreservesException() { assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); } - @Test - public void testFailedLoginUsesPrincipalFromLaterModule() throws Exception { - configureFailingKerberosChain(CONTEXT); - assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); - assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); - } - - @Test - public void testNonStringPrincipalPreservesJaasFailure() throws Exception { - configure(CONTEXT, + @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)), @@ -203,13 +199,6 @@ public void testNonStringPrincipalPreservesJaasFailure() throws Exception { assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); } - @Test - public void testFailedLoginUsesOtherFallbackPrincipal() throws Exception { - configureFailingKerberosChain("other"); - assertThrows(LoginException.class, () -> new TestLogin(new ZKConfig())); - assertMessages("user=" + CONFIGURED_USER + "\toperation=login\tresult=failure"); - } - @ParameterizedTest @ValueSource(booleans = {false, true}) public void testAuditFailureDoesNotInterruptSuccessfulLogin(boolean linkageFailure) throws Exception { @@ -229,6 +218,27 @@ public void testAuditFailurePreservesFailedLogin() { 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())); @@ -403,17 +413,6 @@ private void configure(boolean configuredPrincipal, boolean ticketCache) { TestLoginModule.class.getName(), AppConfigurationEntry.LoginModuleControlFlag.REQUIRED, options)); } - private void configureFailingKerberosChain(String contextName) throws Exception { - Path jaasFile = tempDir.resolve("jaas.conf"); - Files.writeString(jaasFile, contextName + " {\n" - + TestLoginModule.class.getName() + " required;\n" - + "com.sun.security.auth.module.Krb5LoginModule required\n" - + "principal=\"" + CONFIGURED_USER + "\" useTicketCache=true\n" - + "ticketCache=\"" + tempDir.resolve("missing-cache") + "\"\n" - + "useKeyTab=false doNotPrompt=true;\n};\n"); - Configuration.setConfiguration(Configuration.getInstance("JavaLoginConfig", new URIParameter(jaasFile.toUri()))); - } - private void configure(String contextName, AppConfigurationEntry... entries) { Configuration.setConfiguration(new Configuration() { @Override 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 7cee8537c9d..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 @@ -327,7 +327,8 @@ 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. +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 From df5d7535c6eac6b4849ea7d82b0e940cfbd74f09 Mon Sep 17 00:00:00 2001 From: Ivan Khanas Date: Tue, 20 Oct 2026 09:30:01 +0200 Subject: [PATCH 4/4] ZOOKEEPER-4922: Separate audit validation from the enabled flag --- .../org/apache/zookeeper/audit/ZKAuditProvider.java | 13 +++++++++++-- .../zookeeper/server/ZooKeeperServerMain.java | 2 +- .../embedded/ZooKeeperServerEmbeddedImpl.java | 2 +- .../zookeeper/server/quorum/QuorumPeerMain.java | 4 ++-- .../apache/zookeeper/LoginAuditDisabledTest.java | 1 + .../LoginAuditInitializationFailureTest.java | 3 ++- .../zookeeper/LoginAuditInitializationTest.java | 1 + 7 files changed, 19 insertions(+), 7 deletions(-) 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 86caf3e4ed6..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 @@ -91,19 +91,27 @@ private static AuditLogger getAuditLogger(String auditLoggerClass) { } /** - * @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 boolean isAuditEnabled() { + 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 AuditState.auditEnabled; } public static void log(String user, String operation, String znode, String acl, String createMode, String session, String ip, Result result) { if (isAuditEnabled()) { + checkAuditState(); AuditState.auditLogger.logAuditEvent(createLogEvent(user, operation, znode, acl, createMode, session, ip, result)); } } @@ -165,6 +173,7 @@ public static void addServerStartFailureAuditLog() { */ 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 c6c56fa4d75..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 @@ -120,7 +120,7 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti */ public void runFromConfig(ServerConfig config) throws IOException, AdminServerException { // Validate auditing before starting metrics, transaction storage, or listeners. - ZKAuditProvider.isAuditEnabled(); + 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 cc8a7fd2374..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 @@ -87,7 +87,7 @@ public void start() throws Exception { @Override public void start(long startupTimeout) throws Exception { // Validate before scheduling purge or starting the server thread. - ZKAuditProvider.isAuditEnabled(); + ZKAuditProvider.checkAuditState(); switch (exitHandler) { case EXIT: ServiceUtils.setSystemExitProcedure(ServiceUtils.SYSTEM_EXIT); 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 e33486b8ae7..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 @@ -124,7 +124,7 @@ protected void initializeAndRun(String[] args) throws ConfigException, IOExcepti if (args.length == 1) { config.parse(args[0]); // The purge task can access server data before runFromConfig is called. - ZKAuditProvider.isAuditEnabled(); + ZKAuditProvider.checkAuditState(); } // Start and schedule the purge task @@ -146,7 +146,7 @@ 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.isAuditEnabled(); + ZKAuditProvider.checkAuditState(); try { ManagedUtil.registerLog4jMBeans(); } catch (JMException e) { diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java index a60f463af9a..4bd5f5927c1 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditDisabledTest.java @@ -85,6 +85,7 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { @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); diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java index 94c4f9a2bd9..ef90b09f482 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationFailureTest.java @@ -78,7 +78,8 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { LoginException failure = assertThrows(LoginException.class, () -> new Login(null, () -> callbacks -> { }, new ZKConfig())); assertTrue(failure.getMessage().contains("loginContext name")); - assertInitializationFailure(assertThrows(IllegalStateException.class, ZKAuditProvider::isAuditEnabled)); + 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, diff --git a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java index e2af339fc41..0b73b9ebe5c 100644 --- a/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java +++ b/zookeeper-server/src/test/java/org/apache/zookeeper/LoginAuditInitializationTest.java @@ -66,6 +66,7 @@ public AppConfigurationEntry[] getAppConfigurationEntry(String name) { 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());