From af6f58c76aabb0e91ddd8101ae4af0e5006f88e2 Mon Sep 17 00:00:00 2001 From: seawinde Date: Fri, 10 Apr 2026 11:23:25 +0800 Subject: [PATCH] [fix](ldap) Improve LDAP authentication resiliency and diagnostics (#61673) This PR addresses several issues in the FE LDAP authentication path that could lead to login hangs, indefinite blocking, unstable search latency, and poor observability when the LDAP server is slow or unavailable. The main changes are: - Add configurable LDAP timeouts, `ldap_connect_timeout_ms` and `ldap_read_timeout_ms` (both default to 5000 ms), so LDAP bind and search operations do not block indefinitely. - Fix LDAP search connection management by removing the conflicting JNDI built-in pooling configuration and adding `ldap_search_use_pool` to support both pooled and non-pooled search mode. - Improve diagnosability by adding structured performance logs across the LDAP authentication chain, including password resolution, bind, user lookup, group lookup, cache hit/miss, and authentication result. Together, these changes improve FE LDAP authentication stability, make timeout behavior explicit and configurable, reduce the risk of login stalls, and provide better diagnostics for production issues. --- .../org/apache/doris/common/LdapConfig.java | 31 +++++++- .../authenticate/AuthenticatorManager.java | 16 ++++ .../authenticate/ldap/LdapAuthenticator.java | 38 ++++++--- .../mysql/authenticate/ldap/LdapClient.java | 69 +++++++++++++++-- .../mysql/authenticate/ldap/LdapManager.java | 52 ++++++++++++- .../mysql/privilege/UserPropertyMgr.java | 5 ++ .../mysql/authenticate/TestLogAppender.java | 77 +++++++++++++++++++ .../ldap/LdapAuthenticatorTest.java | 28 +++++++ .../authenticate/ldap/LdapClientTest.java | 65 ++++++++++++++++ .../authenticate/ldap/LdapManagerTest.java | 31 ++++++++ 10 files changed, 392 insertions(+), 20 deletions(-) create mode 100644 fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/TestLogAppender.java diff --git a/fe/fe-common/src/main/java/org/apache/doris/common/LdapConfig.java b/fe/fe-common/src/main/java/org/apache/doris/common/LdapConfig.java index 881840696dcde8..be25b5af0a4761 100644 --- a/fe/fe-common/src/main/java/org/apache/doris/common/LdapConfig.java +++ b/fe/fe-common/src/main/java/org/apache/doris/common/LdapConfig.java @@ -87,7 +87,36 @@ public class LdapConfig extends ConfigBase { public static long ldap_cache_timeout_day = 30; /** - * LDAP pool configuration: + * LDAP read timeout in milliseconds. + * Controls the maximum time to wait for an LDAP response after a request is sent. + * Uses JNDI property "com.sun.jndi.ldap.read.timeout". + * Set to 0 for no timeout (not recommended). Default 5000ms. + */ + @ConfigBase.ConfField + public static int ldap_read_timeout_ms = 5000; + + /** + * LDAP connect timeout in milliseconds. + * Controls the maximum time to wait for establishing a TCP connection to the LDAP server. + * Uses JNDI property "com.sun.jndi.ldap.connect.timeout". + * Set to 0 for no timeout (not recommended). Default 5000ms. + */ + @ConfigBase.ConfField + public static int ldap_connect_timeout_ms = 5000; + + /** + * Whether to use connection pooling for LDAP search operations. + * When true (default), uses Spring PoolingContextSource with ldap_pool_* settings. + * When false, each LDAP search creates a fresh connection, avoiding dead connection + * detection cost (testOnBorrow can burn read_timeout discovering stale connections + * killed by firewalls/NAT idle timeout). Recommended to set false if experiencing + * intermittent ~5s LDAP search latency spikes. + */ + @ConfigBase.ConfField + public static boolean ldap_search_use_pool = true; + + /** + * LDAP pool configuration (only effective when ldap_search_use_pool = true): * https://docs.spring.io/spring-ldap/docs/2.3.3.RELEASE/reference/#pool-configuration */ /** diff --git a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/AuthenticatorManager.java b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/AuthenticatorManager.java index 8ba711e6655905..e64970411d2985 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/AuthenticatorManager.java +++ b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/AuthenticatorManager.java @@ -97,14 +97,30 @@ public boolean authenticate(ConnectContext context, MysqlAuthPacket authPacket, MysqlHandshakePacket handshakePacket) throws IOException { Authenticator authenticator = chooseAuthenticator(userName); + boolean debugEnabled = LOG.isDebugEnabled(); + long resolveStart = 0L; + if (debugEnabled) { + LOG.debug("AuthenticatorManager: user={}, authenticator={}", + userName, authenticator.getClass().getSimpleName()); + resolveStart = System.currentTimeMillis(); + } Optional password = authenticator.getPasswordResolver() .resolvePassword(context, channel, serializer, authPacket, handshakePacket); if (!password.isPresent()) { return false; } + if (debugEnabled) { + long resolveElapsed = System.currentTimeMillis() - resolveStart; + LOG.debug("resolvePassword: user={}, elapsed={}ms", userName, resolveElapsed); + resolveStart = System.currentTimeMillis(); + } String remoteIp = context.getMysqlChannel().getRemoteIp(); AuthenticateRequest request = new AuthenticateRequest(userName, password.get(), remoteIp); AuthenticateResponse response = authenticator.authenticate(request); + if (debugEnabled) { + long authenticateElapsed = System.currentTimeMillis() - resolveStart; + LOG.debug("authenticate: user={}, elapsed={}ms", userName, authenticateElapsed); + } if (!response.isSuccess()) { MysqlProto.sendResponsePacket(context); return false; diff --git a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticator.java b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticator.java index cd9cef469d2520..7ec518c3c08c2b 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticator.java +++ b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticator.java @@ -59,6 +59,7 @@ public LdapAuthenticator() { */ @Override public AuthenticateResponse authenticate(AuthenticateRequest request) throws IOException { + long start = System.currentTimeMillis(); if (LOG.isDebugEnabled()) { LOG.debug("user:{} start to ldap authenticate.", request.getUserName()); } @@ -67,7 +68,14 @@ public AuthenticateResponse authenticate(AuthenticateRequest request) throws IOE return AuthenticateResponse.failedResponse; } ClearPassword clearPassword = (ClearPassword) password; - return internalAuthenticate(clearPassword.getPassword(), request.getUserName(), request.getRemoteIp()); + AuthenticateResponse response = internalAuthenticate(clearPassword.getPassword(), + request.getUserName(), request.getRemoteIp()); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapAuthenticator.authenticate: user={}, success={}, elapsed={}ms", + request.getUserName(), response.isSuccess(), elapsed); + } + return response; } @Override @@ -75,11 +83,14 @@ public boolean canDeal(String qualifiedUser) { if (qualifiedUser.equals(Auth.ROOT_USER) || qualifiedUser.equals(Auth.ADMIN_USER)) { return false; } - // Fixme Note: LdapManager should be managed internally within the Ldap plugin - // and not be placed inside the Env class. This ensures that Ldap-related - // logic and dependencies are encapsulated within the plugin, promoting - // better modularity and maintainability. - return Env.getCurrentEnv().getAuth().getLdapManager().doesUserExist(qualifiedUser); + long start = System.currentTimeMillis(); + boolean result = Env.getCurrentEnv().getAuth().getLdapManager().doesUserExist(qualifiedUser); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapAuthenticator.canDeal: user={}, result={}, elapsed={}ms", + qualifiedUser, result, elapsed); + } + return result; } /** @@ -99,12 +110,14 @@ private AuthenticateResponse internalAuthenticate(String password, String qualif // check user password by ldap server. try { if (!Env.getCurrentEnv().getAuth().getLdapManager().checkUserPasswd(qualifiedUser, password)) { - LOG.info("user:{} use check LDAP password failed.", userName); + if (LOG.isDebugEnabled()) { + LOG.debug("internalAuthenticate: user={}, success=false", userName); + } ErrorReport.report(ErrorCode.ERR_ACCESS_DENIED_ERROR, qualifiedUser, remoteIp, usePasswd); return AuthenticateResponse.failedResponse; } } catch (Exception e) { - LOG.error("Check ldap password error.", e); + LOG.warn("internalAuthenticate failed: user={}", userName, e); return AuthenticateResponse.failedResponse; } @@ -115,12 +128,17 @@ private AuthenticateResponse internalAuthenticate(String password, String qualif AuthenticateResponse response = new AuthenticateResponse(true); if (userIdentities.isEmpty()) { response.setUserIdentity(tempUserIdentity); + response.setTemp(true); if (LOG.isDebugEnabled()) { - LOG.debug("User:{} does not exists in doris, login as temporary users.", userName); + LOG.debug("internalAuthenticate: user={}, tempUser=true, identity={}", + userName, tempUserIdentity); } - response.setTemp(true); } else { response.setUserIdentity(userIdentities.get(0)); + if (LOG.isDebugEnabled()) { + LOG.debug("internalAuthenticate: user={}, tempUser=false, identity={}", + userName, userIdentities.get(0)); + } } if (LOG.isDebugEnabled()) { LOG.debug("ldap authentication success: identity:{}", response.getUserIdentity()); diff --git a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapClient.java b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapClient.java index 5d03917f0d36d3..36fa90cd31b40a 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapClient.java +++ b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapClient.java @@ -29,6 +29,7 @@ import lombok.Data; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.springframework.ldap.AuthenticationException; import org.springframework.ldap.core.DirContextOperations; import org.springframework.ldap.core.LdapTemplate; import org.springframework.ldap.core.support.AbstractContextMapper; @@ -39,7 +40,9 @@ import org.springframework.ldap.support.LdapEncoder; import org.springframework.ldap.transaction.compensating.manager.TransactionAwareContextSourceProxy; +import java.util.HashMap; import java.util.List; +import java.util.Map; // This class is used to connect to the LDAP service. public class LdapClient { @@ -60,7 +63,15 @@ private static class ClientInfo { public ClientInfo(String ldapPassword) { this.ldapPassword = ldapPassword; setLdapTemplateNoPool(ldapPassword); - setLdapTemplatePool(ldapPassword); + if (LdapConfig.ldap_search_use_pool) { + setLdapTemplatePool(ldapPassword); + } + } + + // Returns the LdapTemplate for search operations: + // pooled if ldap_search_use_pool=true, non-pooled otherwise. + public LdapTemplate getSearchTemplate() { + return ldapTemplatePool != null ? ldapTemplatePool : ldapTemplateNoPool; } private void setLdapTemplateNoPool(String ldapPassword) { @@ -71,6 +82,7 @@ private void setLdapTemplateNoPool(String ldapPassword) { contextSource.setUrl(url); contextSource.setUserDn(LdapConfig.ldap_admin_name); contextSource.setPassword(ldapPassword); + setLdapTimeoutProperties(contextSource); contextSource.afterPropertiesSet(); ldapTemplateNoPool = new LdapTemplate(contextSource); ldapTemplateNoPool.setIgnorePartialResultException(true); @@ -84,7 +96,7 @@ private void setLdapTemplatePool(String ldapPassword) { contextSource.setUrl(url); contextSource.setUserDn(LdapConfig.ldap_admin_name); contextSource.setPassword(ldapPassword); - contextSource.setPooled(true); + setLdapTimeoutProperties(contextSource); contextSource.afterPropertiesSet(); PoolingContextSource poolingContextSource = new PoolingContextSource(); @@ -109,6 +121,21 @@ public boolean checkUpdate(String ldapPassword) { return this.ldapPassword == null || !this.ldapPassword.equals(ldapPassword); } + private void setLdapTimeoutProperties(LdapContextSource contextSource) { + Map baseEnv = new HashMap<>(); + if (LdapConfig.ldap_read_timeout_ms > 0) { + baseEnv.put("com.sun.jndi.ldap.read.timeout", + String.valueOf(LdapConfig.ldap_read_timeout_ms)); + } + if (LdapConfig.ldap_connect_timeout_ms > 0) { + baseEnv.put("com.sun.jndi.ldap.connect.timeout", + String.valueOf(LdapConfig.ldap_connect_timeout_ms)); + } + if (!baseEnv.isEmpty()) { + contextSource.setBaseEnvironmentProperties(baseEnv); + } + } + } private void init() { @@ -143,19 +170,37 @@ boolean doesUserExist(String userName) { boolean checkPassword(String userName, String password) { init(); + long start = System.currentTimeMillis(); try { clientInfo.getLdapTemplateNoPool().authenticate(org.springframework.ldap.query.LdapQueryBuilder.query() .base(LdapConfig.ldap_user_basedn) .filter(applyLoginFilter(LdapConfig.ldap_user_filter, userName)), password); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapClient.checkPassword: user={}, success=true, elapsed={}ms", + userName, elapsed); + } return true; + } catch (AuthenticationException e) { + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapClient.checkPassword: user={}, success=false, elapsed={}ms, " + + "errorClass={}, errorMessage={}", + userName, elapsed, e.getClass().getSimpleName(), e.getMessage()); + } + return false; } catch (Exception e) { - LOG.info("ldap client checkPassword failed, userName: {}", userName, e); + long elapsed = System.currentTimeMillis() - start; + LOG.warn("LdapClient.checkPassword failed: user={}, elapsed={}ms, " + + "errorClass={}, errorMessage={}", + userName, elapsed, e.getClass().getSimpleName(), e.getMessage(), e); return false; } } // Search group DNs by 'member' attribution. List getGroups(String userName) { + long start = System.currentTimeMillis(); List groups = Lists.newArrayList(); if (LdapConfig.ldap_group_basedn.isEmpty()) { return groups; @@ -190,6 +235,11 @@ List getGroups(String userName) { groups.add(strings[1]); } } + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapClient.getGroups: user={}, groups={}, elapsed={}ms", + userName, groups.size(), elapsed); + } return groups; } @@ -211,18 +261,27 @@ private String getUserDn(String userName) { public List getDn(LdapQuery query) { init(); + long start = System.currentTimeMillis(); try { - return clientInfo.getLdapTemplatePool().search(query, + List result = clientInfo.getSearchTemplate().search(query, new AbstractContextMapper() { protected String doMapFromContext(DirContextOperations ctx) { return ctx.getNameInNamespace(); } }); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapClient.getDn: base={}, elapsed={}ms, results={}", + query.base(), elapsed, result == null ? 0 : result.size()); + } + return result; } catch (Exception e) { + long elapsed = System.currentTimeMillis() - start; String msg = "Failed to retrieve the user's Distinguished Name (DN)," + "This may be due to incorrect LDAP configuration or an unset/incorrect LDAP admin password."; - LOG.error(msg, e); + LOG.warn("LdapClient.getDn failed: base={}, elapsed={}ms, error={}", + query.base(), elapsed, e.getMessage(), e); ErrorReport.report(ErrorCode.ERROR_LDAP_CONFIGURATION_ERR); throw new RuntimeException(msg); } diff --git a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapManager.java b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapManager.java index 5f6003cd6c146c..da4665eb7d37f5 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapManager.java +++ b/fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapManager.java @@ -81,14 +81,28 @@ public LdapUserInfo getUserInfo(String fullName) { if (!checkParam(fullName)) { return null; } + long start = System.currentTimeMillis(); LdapUserInfo ldapUserInfo = getUserInfoFromCache(fullName); if (ldapUserInfo != null && !ldapUserInfo.checkTimeout()) { + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.getUserInfo: user={}, cacheHit=true, elapsed={}ms", + fullName, elapsed); + } return ldapUserInfo; } try { - return getUserInfoAndUpdateCache(fullName); + LdapUserInfo result = getUserInfoAndUpdateCache(fullName); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.getUserInfo: user={}, cacheHit=false, elapsed={}ms", + fullName, elapsed); + } + return result; } catch (DdlException e) { - LOG.warn("getUserInfo for {} failed", fullName, e); + long elapsed = System.currentTimeMillis() - start; + LOG.warn("LdapManager.getUserInfo failed: user={}, elapsed={}ms", + fullName, elapsed, e); return null; } } @@ -97,11 +111,19 @@ public boolean doesUserExist(String fullName) { if (!checkParam(fullName)) { return false; } + long start = System.currentTimeMillis(); LdapUserInfo info = getUserInfo(fullName); - return !Objects.isNull(info) && info.isExists(); + boolean exists = !Objects.isNull(info) && info.isExists(); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.doesUserExist: user={}, exists={}, elapsed={}ms", + fullName, exists, elapsed); + } + return exists; } public boolean checkUserPasswd(String fullName, String passwd) { + long start = System.currentTimeMillis(); String userName = ClusterNamespace.getNameFromFullName(fullName); if (AuthenticateType.getAuthTypeConfig() != AuthenticateType.LDAP || Strings.isNullOrEmpty(userName) || Objects.isNull(passwd)) { @@ -109,13 +131,28 @@ public boolean checkUserPasswd(String fullName, String passwd) { } LdapUserInfo ldapUserInfo = getUserInfo(fullName); if (Objects.isNull(ldapUserInfo) || !ldapUserInfo.isExists()) { + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.checkUserPasswd: user={}, result=user_not_found, elapsed={}ms", + fullName, elapsed); + } return false; } if (ldapUserInfo.isSetPasswd() && ldapUserInfo.getPasswd().equals(passwd)) { + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.checkUserPasswd: user={}, result=cached_passwd_match, elapsed={}ms", + fullName, elapsed); + } return true; } boolean isRightPasswd = ldapClient.checkPassword(userName, passwd); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.checkUserPasswd: user={}, result={}, elapsed={}ms", + fullName, isRightPasswd ? "ldap_auth_ok" : "ldap_auth_fail", elapsed); + } if (!isRightPasswd) { return false; } @@ -132,8 +169,15 @@ public boolean checkUserPasswd(String fullName, String passwd, String remoteIp, } public Set getUserRoles(String fullName) { + long start = System.currentTimeMillis(); LdapUserInfo info = getUserInfo(fullName); - return info == null ? Collections.emptySet() : info.getRoles(); + Set roles = info == null ? Collections.emptySet() : info.getRoles(); + long elapsed = System.currentTimeMillis() - start; + if (LOG.isDebugEnabled()) { + LOG.debug("LdapManager.getUserRoles: user={}, roles={}, elapsed={}ms", + fullName, roles.size(), elapsed); + } + return roles; } private boolean checkParam(String fullName) { diff --git a/fe/fe-core/src/main/java/org/apache/doris/mysql/privilege/UserPropertyMgr.java b/fe/fe-core/src/main/java/org/apache/doris/mysql/privilege/UserPropertyMgr.java index e068182308ed16..4a4c09bacbb69b 100644 --- a/fe/fe-core/src/main/java/org/apache/doris/mysql/privilege/UserPropertyMgr.java +++ b/fe/fe-core/src/main/java/org/apache/doris/mysql/privilege/UserPropertyMgr.java @@ -270,6 +270,11 @@ public long getQueryFreshnessToleranceMs(String qualifiedUser) { * If the authentication type is LDAP and the user exists in LDAP, return DEFAULT_USER_PROPERTY. * If the authentication type is not the default type, return DEFAULT_USER_PROPERTY. * Otherwise, return existProperty. + * + * Note: Previously this method called LdapManager.doesUserExist() to check LDAP, + * but that was redundant: when authentication_type=LDAP (non-default), the fallback + * condition already returns DEFAULT_USER_PROPERTY. The LDAP call caused runtime + * network queries that could hang under Auth read lock, blocking all new connections. */ private UserProperty getPropertyIfNull(String qualifiedUser, UserProperty existProperty) { if (null != existProperty) { diff --git a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/TestLogAppender.java b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/TestLogAppender.java new file mode 100644 index 00000000000000..c88e81b91cee01 --- /dev/null +++ b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/TestLogAppender.java @@ -0,0 +1,77 @@ +// 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.doris.mysql.authenticate; + +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.Logger; +import org.apache.logging.log4j.core.appender.AbstractAppender; +import org.apache.logging.log4j.core.config.Property; +import org.apache.logging.log4j.core.layout.PatternLayout; + +import java.util.List; +import java.util.concurrent.CopyOnWriteArrayList; + +public class TestLogAppender extends AbstractAppender implements AutoCloseable { + private final Logger logger; + private final Level originalLevel; + private final List events = new CopyOnWriteArrayList<>(); + + private TestLogAppender(String name, Logger logger) { + super(name, null, PatternLayout.createDefaultLayout(), false, Property.EMPTY_ARRAY); + this.logger = logger; + this.originalLevel = logger.getLevel(); + } + + public static TestLogAppender attach(Class loggerClass) { + return attach(loggerClass, Level.DEBUG); + } + + public static TestLogAppender attach(Class loggerClass, Level level) { + Logger logger = (Logger) LogManager.getLogger(loggerClass); + TestLogAppender appender = new TestLogAppender( + "TestLogAppender-" + loggerClass.getSimpleName() + "-" + System.nanoTime(), logger); + appender.start(); + logger.addAppender(appender); + logger.setLevel(level); + return appender; + } + + @Override + public void append(LogEvent event) { + events.add(event.toImmutable()); + } + + public boolean contains(Level level, String messageFragment) { + for (LogEvent event : events) { + if (event.getLevel().equals(level) + && event.getMessage().getFormattedMessage().contains(messageFragment)) { + return true; + } + } + return false; + } + + @Override + public void close() { + logger.removeAppender(this); + logger.setLevel(originalLevel); + stop(); + } +} diff --git a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticatorTest.java b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticatorTest.java index 99cbcdb5fad643..33073f1145aede 100644 --- a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticatorTest.java +++ b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticatorTest.java @@ -20,6 +20,7 @@ import org.apache.doris.analysis.UserIdentity; import org.apache.doris.mysql.authenticate.AuthenticateRequest; import org.apache.doris.mysql.authenticate.AuthenticateResponse; +import org.apache.doris.mysql.authenticate.TestLogAppender; import org.apache.doris.mysql.authenticate.password.ClearPassword; import org.apache.doris.mysql.authenticate.password.ClearPasswordResolver; import org.apache.doris.mysql.privilege.Auth; @@ -27,6 +28,7 @@ import com.google.common.collect.Lists; import mockit.Expectations; import mockit.Mocked; +import org.apache.logging.log4j.Level; import org.junit.Assert; import org.junit.Test; @@ -111,6 +113,20 @@ public void testAuthenticateWithWrongPassword() throws IOException { Assert.assertFalse(response.isSuccess()); } + @Test + public void testAuthenticateLogsInfoWithoutThreshold() throws IOException { + setCheckPassword(true); + setGetUserInDoris(true); + try (TestLogAppender appender = TestLogAppender.attach(LdapAuthenticator.class)) { + AuthenticateResponse response = ldapAuthenticator.authenticate(request); + Assert.assertTrue(response.isSuccess()); + Assert.assertTrue(appender.contains(Level.DEBUG, + "LdapAuthenticator.authenticate: user=user, success=true, elapsed=")); + Assert.assertFalse(appender.contains(Level.WARN, + "LdapAuthenticator.authenticate slow: user=user")); + } + } + @Test public void testAuthenticateWithCheckPasswordException() throws IOException { setCheckPasswordException(); @@ -139,6 +155,18 @@ public void testCanDeal() { Assert.assertFalse(ldapAuthenticator.canDeal("ss")); } + @Test + public void testCanDealLogsInfoWithoutThreshold() { + setLdapUserExist(true); + try (TestLogAppender appender = TestLogAppender.attach(LdapAuthenticator.class)) { + Assert.assertTrue(ldapAuthenticator.canDeal("ss")); + Assert.assertTrue(appender.contains(Level.DEBUG, + "LdapAuthenticator.canDeal: user=ss, result=true, elapsed=")); + Assert.assertFalse(appender.contains(Level.WARN, + "LdapAuthenticator.canDeal slow: user=ss")); + } + } + @Test public void testGetPasswordResolver() { Assert.assertTrue(ldapAuthenticator.getPasswordResolver() instanceof ClearPasswordResolver); diff --git a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapClientTest.java b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapClientTest.java index 7790816856f99d..26695c687c7261 100644 --- a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapClientTest.java +++ b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapClientTest.java @@ -20,16 +20,22 @@ import org.apache.doris.common.Config; import org.apache.doris.common.LdapConfig; import org.apache.doris.common.util.NetUtils; +import org.apache.doris.mysql.authenticate.TestLogAppender; import mockit.Expectations; import mockit.Tested; +import org.apache.logging.log4j.Level; import org.junit.After; import org.junit.Assert; import org.junit.Before; import org.junit.Test; +import org.springframework.ldap.core.LdapTemplate; import org.springframework.ldap.query.LdapQuery; import org.springframework.ldap.support.LdapEncoder; +import java.lang.reflect.Constructor; +import java.lang.reflect.Field; +import java.lang.reflect.Method; import java.util.Arrays; import java.util.List; @@ -100,6 +106,45 @@ public void testGetGroups() { Assert.assertEquals(1, ldapClient.getGroups("zhangsan").size()); } + @Test + public void testGetGroupsLogsInfoWithoutThreshold() { + List userDns = Arrays.asList("uid=zhangsan,dc=example,dc=com"); + List groupDns = Arrays.asList("cn=groupName,ou=groups,dc=example,dc=com"); + new Expectations(ldapClient) { + { + ldapClient.getDn((LdapQuery) any); + result = userDns; + result = groupDns; + } + }; + + try (TestLogAppender appender = TestLogAppender.attach(LdapClient.class)) { + Assert.assertEquals(1, ldapClient.getGroups("zhangsan").size()); + Assert.assertTrue(appender.contains(Level.DEBUG, + "LdapClient.getGroups: user=zhangsan, groups=1, elapsed=")); + Assert.assertFalse(appender.contains(Level.WARN, + "LdapClient.getGroups slow: user=zhangsan")); + } + } + + @Test + public void testGetSearchTemplateUsesNoPoolWhenDisabled() throws Exception { + LdapConfig.ldap_search_use_pool = false; + + Object clientInfo = newClientInfo("secret"); + Assert.assertSame(getFieldValue(clientInfo, "ldapTemplateNoPool"), getSearchTemplate(clientInfo)); + Assert.assertNull(getFieldValue(clientInfo, "ldapTemplatePool")); + } + + @Test + public void testGetSearchTemplateUsesPoolWhenEnabled() throws Exception { + LdapConfig.ldap_search_use_pool = true; + + Object clientInfo = newClientInfo("secret"); + Assert.assertNotNull(getFieldValue(clientInfo, "ldapTemplatePool")); + Assert.assertSame(getFieldValue(clientInfo, "ldapTemplatePool"), getSearchTemplate(clientInfo)); + } + @Test public void testSecuredProtocolIsUsed() { //testing default case with not specified property ldap_use_ssl or it is specified as false @@ -151,5 +196,25 @@ public void testLdapFilterEncoding() { @After public void tearDown() { LdapConfig.ldap_use_ssl = false; // restoring default value for other tests + LdapConfig.ldap_search_use_pool = true; + } + + private Object newClientInfo(String ldapPassword) throws Exception { + Class clientInfoClass = Class.forName("org.apache.doris.mysql.authenticate.ldap.LdapClient$ClientInfo"); + Constructor constructor = clientInfoClass.getDeclaredConstructor(String.class); + constructor.setAccessible(true); + return constructor.newInstance(ldapPassword); + } + + private LdapTemplate getSearchTemplate(Object clientInfo) throws Exception { + Method method = clientInfo.getClass().getDeclaredMethod("getSearchTemplate"); + method.setAccessible(true); + return (LdapTemplate) method.invoke(clientInfo); + } + + private Object getFieldValue(Object clientInfo, String fieldName) throws Exception { + Field field = clientInfo.getClass().getDeclaredField(fieldName); + field.setAccessible(true); + return field.get(clientInfo); } } diff --git a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapManagerTest.java b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapManagerTest.java index 8af499bbbe8ec8..70361675054eea 100644 --- a/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapManagerTest.java +++ b/fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapManagerTest.java @@ -18,9 +18,11 @@ package org.apache.doris.mysql.authenticate.ldap; import org.apache.doris.common.Config; +import org.apache.doris.mysql.authenticate.TestLogAppender; import mockit.Expectations; import mockit.Mocked; +import org.apache.logging.log4j.Level; import org.junit.Assert; import org.junit.Before; import org.junit.Test; @@ -85,4 +87,33 @@ public void testCheckUserPasswd() { mockClient(true, false); Assert.assertFalse(ldapManager.checkUserPasswd(USER2, "123")); } + + @Test + public void testCheckUserPasswdCachedPasswdMatchLogsInfoWithoutThreshold() { + LdapManager ldapManager = new LdapManager(); + mockClient(true, true); + Assert.assertTrue(ldapManager.checkUserPasswd(USER1, "123")); + + try (TestLogAppender appender = TestLogAppender.attach(LdapManager.class)) { + Assert.assertTrue(ldapManager.checkUserPasswd(USER1, "123")); + Assert.assertTrue(appender.contains(Level.DEBUG, + "LdapManager.checkUserPasswd: user=user1, result=cached_passwd_match, elapsed=")); + Assert.assertFalse(appender.contains(Level.WARN, + "LdapManager.checkUserPasswd slow: user=user1")); + } + } + + @Test + public void testGetUserInfoLogsInfoWithoutThreshold() { + LdapManager ldapManager = new LdapManager(); + mockClient(true, true); + + try (TestLogAppender appender = TestLogAppender.attach(LdapManager.class)) { + Assert.assertNotNull(ldapManager.getUserInfo(USER1)); + Assert.assertTrue(appender.contains(Level.DEBUG, + "LdapManager.getUserInfo: user=user1, cacheHit=false, elapsed=")); + Assert.assertFalse(appender.contains(Level.WARN, + "LdapManager.getUserInfo slow: user=user1")); + } + } }