Copilot commented on code in PR #61673:
URL: https://github.com/apache/doris/pull/61673#discussion_r2986973659
##########
fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/AuthenticatorManager.java:
##########
@@ -163,6 +167,8 @@ public boolean authenticate(ConnectContext context,
AuthenticateRequest request = primaryRequest.get();
remoteIp = request.getRemoteIp();
AuthenticateResponse primaryResponse =
authenticateWith(primaryAuthenticator, request);
+ long resolveElapsed = System.currentTimeMillis() - resolveStart;
+ LOG.info("[LDAP-AUTH] resolvePassword: user={}, elapsed={}ms",
userName, resolveElapsed);
Review Comment:
`resolveElapsed` is logged as `resolvePassword`, but the timer starts before
`resolveAuthenticateRequest(...)` and stops after `authenticateWith(...)`, so
the measurement includes both password resolution and the authenticator’s
`authenticate()` work. This makes the log misleading for diagnosing where time
is spent. Consider either (1) moving the end timestamp to immediately after
`resolveAuthenticateRequest(...)`, or (2) renaming/splitting the logs into
separate `resolvePassword` and `authenticate` timings.
```suggestion
LOG.info("[LDAP-AUTH] resolveAndAuthenticate: user={},
elapsed={}ms", userName, resolveElapsed);
```
##########
fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapClient.java:
##########
@@ -143,19 +169,26 @@ 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(getUserFilter(LdapConfig.ldap_user_filter,
userName)), password);
+ long elapsed = System.currentTimeMillis() - start;
+ LOG.info("[LDAP-AUTH] LdapClient.checkPassword: user={},
success=true, elapsed={}ms",
+ userName, elapsed);
return true;
} catch (Exception e) {
- LOG.info("ldap client checkPassword failed, userName: {}",
userName, e);
+ long elapsed = System.currentTimeMillis() - start;
+ LOG.warn("[LDAP-AUTH] LdapClient.checkPassword failed: user={},
elapsed={}ms, error={}",
+ userName, elapsed, e.getMessage());
Review Comment:
`LdapClient.checkPassword` logs only `e.getMessage()` on failure and drops
the exception stack trace. That reduces diagnosability (especially for timeouts
vs auth failures) and can hide the actual exception type/cause. Consider
logging the exception itself (pass `e` as the last parameter) and/or include
the exception class in the structured fields.
```suggestion
LOG.warn("[LDAP-AUTH] LdapClient.checkPassword failed: user={},
elapsed={}ms, errorClass={}, errorMessage={}",
userName, elapsed, e.getClass().getName(),
e.getMessage(), e);
```
##########
fe/fe-core/src/main/java/org/apache/doris/mysql/authenticate/ldap/LdapManager.java:
##########
@@ -80,14 +80,24 @@ 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;
+ LOG.info("[LDAP-AUTH] LdapManager.getUserInfo: user={},
cacheHit=true, elapsed={}ms",
+ fullName, elapsed);
return ldapUserInfo;
}
try {
- return getUserInfoAndUpdateCache(fullName);
+ LdapUserInfo result = getUserInfoAndUpdateCache(fullName);
+ long elapsed = System.currentTimeMillis() - start;
+ LOG.info("[LDAP-AUTH] LdapManager.getUserInfo: user={},
cacheHit=false, elapsed={}ms",
+ fullName, elapsed);
+ return result;
Review Comment:
The new `[LDAP-AUTH]` logs in `getUserInfo()` are emitted at INFO on every
call (cache hit and miss). Since `getUserInfo()` is in the
authentication/privilege hot path, this can generate very high log volume and
become a performance/ops burden in busy clusters. Consider gating these
per-request timing logs behind a config flag, sampling, DEBUG level, and/or
only logging when a slow threshold is exceeded (while keeping WARN/ERROR for
failures).
##########
fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapClientTest.java:
##########
@@ -99,6 +100,28 @@ public void testGetGroups() {
Assert.assertEquals(1, ldapClient.getGroups("zhangsan").size());
}
+ @Test
+ public void testGetGroupsLogsInfoWithoutThreshold() {
+ List<String> userDns = Arrays.asList("uid=zhangsan,dc=example,dc=com");
+ List<String> groupDns =
Arrays.asList("cn=groupName,ou=groups,dc=example,dc=com");
+ new Expectations(ldapClient) {
+ {
+ ldapClient.getDn((LdapQuery) any);
+ result = userDns;
+ result = groupDns;
+ }
+ };
+
+ try (LdapAuthenticatorTest.LdapTestLogAppender appender =
+
LdapAuthenticatorTest.LdapTestLogAppender.attach(LdapClient.class)) {
+ Assert.assertEquals(1, ldapClient.getGroups("zhangsan").size());
+ Assert.assertTrue(appender.contains(Level.INFO,
+ "[LDAP-AUTH] LdapClient.getGroups: user=zhangsan,
groups=1, elapsed="));
+ Assert.assertFalse(appender.contains(Level.WARN,
+ "[LDAP-AUTH] LdapClient.getGroups slow: user=zhangsan"));
+ }
Review Comment:
This test uses `LdapAuthenticatorTest.LdapTestLogAppender`, which is a
nested helper inside another test class. That cross-test dependency is fragile
and makes refactors harder. Consider switching to the shared
`org.apache.doris.mysql.authenticate.TestLogAppender` (added in this PR) or
another common test utility class.
##########
fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/TestLogAppender.java:
##########
@@ -0,0 +1,73 @@
+// 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<LogEvent> 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) {
+ Logger logger = (Logger) LogManager.getLogger(loggerClass);
+ TestLogAppender appender = new TestLogAppender(
+ "TestLogAppender-" + loggerClass.getSimpleName() + "-" +
System.nanoTime(), logger);
+ appender.start();
+ logger.addAppender(appender);
+ logger.setLevel(Level.INFO);
+ 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();
+ }
+}
Review Comment:
`TestLogAppender` appears to be unused by the test suite (LDAP tests are
still using `LdapAuthenticatorTest.LdapTestLogAppender` instead). If this is
intended as the shared logging test utility, consider updating tests to use it
and removing the duplicated nested appender; otherwise, consider dropping this
class to avoid dead code.
```suggestion
```
##########
fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapManagerTest.java:
##########
@@ -85,4 +86,35 @@ 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 (LdapAuthenticatorTest.LdapTestLogAppender appender =
+
LdapAuthenticatorTest.LdapTestLogAppender.attach(LdapManager.class)) {
+ Assert.assertTrue(ldapManager.checkUserPasswd(USER1, "123"));
+ Assert.assertTrue(appender.contains(Level.INFO,
+ "[LDAP-AUTH] LdapManager.checkUserPasswd: user=user1,
result=cached_passwd_match, elapsed="));
+ Assert.assertFalse(appender.contains(Level.WARN,
+ "[LDAP-AUTH] LdapManager.checkUserPasswd slow:
user=user1"));
+ }
Review Comment:
This test depends on `LdapAuthenticatorTest.LdapTestLogAppender` (a nested
helper in another test class). That creates brittle cross-test coupling and
makes the helper hard to reuse. Consider using the new shared
`org.apache.doris.mysql.authenticate.TestLogAppender` (or moving the appender
helper into a common test utility) and importing it directly here.
##########
fe/fe-core/src/test/java/org/apache/doris/mysql/authenticate/ldap/LdapAuthenticatorTest.java:
##########
@@ -139,8 +161,64 @@ public void testCanDeal() {
Assert.assertFalse(ldapAuthenticator.canDeal("ss"));
}
+ @Test
+ public void testCanDealLogsInfoWithoutThreshold() {
+ setLdapUserExist(true);
+ try (LdapTestLogAppender appender =
LdapTestLogAppender.attach(LdapAuthenticator.class)) {
+ Assert.assertTrue(ldapAuthenticator.canDeal("ss"));
+ Assert.assertTrue(appender.contains(Level.INFO,
+ "[LDAP-AUTH] LdapAuthenticator.canDeal: user=ss,
result=true, elapsed="));
+ Assert.assertFalse(appender.contains(Level.WARN,
+ "[LDAP-AUTH] LdapAuthenticator.canDeal slow: user=ss"));
+ }
+ }
+
@Test
public void testGetPasswordResolver() {
Assert.assertTrue(ldapAuthenticator.getPasswordResolver() instanceof
ClearPasswordResolver);
}
+
+ static class LdapTestLogAppender extends AbstractAppender implements
AutoCloseable {
+ private final Logger logger;
+ private final Level originalLevel;
+ private final List<LogEvent> events = new CopyOnWriteArrayList<>();
+
+ private LdapTestLogAppender(String name, Logger logger) {
+ super(name, null, PatternLayout.createDefaultLayout(), false,
Property.EMPTY_ARRAY);
+ this.logger = logger;
+ this.originalLevel = logger.getLevel();
+ }
+
+ public static LdapTestLogAppender attach(Class<?> loggerClass) {
+ Logger logger = (Logger) LogManager.getLogger(loggerClass);
+ LdapTestLogAppender appender = new LdapTestLogAppender(
+ "LdapTestLogAppender-" + loggerClass.getSimpleName() + "-"
+ System.nanoTime(), logger);
+ appender.start();
+ logger.addAppender(appender);
+ logger.setLevel(Level.INFO);
+ 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();
+ }
+ }
Review Comment:
`LdapTestLogAppender` duplicates the new shared
`org.apache.doris.mysql.authenticate.TestLogAppender` (same implementation
pattern: attach, capture events, contains, restore level). Keeping two
near-identical appenders increases maintenance cost and encourages test
coupling. Consider deleting this nested helper and switching LDAP tests to the
shared `TestLogAppender` instead.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
