Expand debug logging for authentication / realms (elastic/x-pack-elasticsearch#641)

Users currently have difficulty diagnosing authentication failures.
Some logging messages mislead them, and in other cases there are unexpected behaviours that are not logged at all.
These additional DEBUG log messages and change some existing messages in an attempt to alleviate that problem.

Original commit: elastic/x-pack-elasticsearch@c6ea98b038
This commit is contained in:
Tim Vernum 2017-04-10 21:21:40 +10:00 committed by GitHub
parent ef4de13ca4
commit 18835fe4df
7 changed files with 28 additions and 10 deletions

View File

@ -241,7 +241,12 @@ public class AuthenticationService extends AbstractComponent {
authenticatedBy = new RealmRef(realm.name(), realm.type(), nodeName);
}
userListener.onResponse(user);
}, userListener::onFailure));
}, (ex) -> {
logger.warn(new ParameterizedMessage(
"An unexpected error occurred while attempting to authenticate [{}] against realm [{}]",
authenticationToken.principal(), realm.name()), ex);
userListener.onFailure(ex);
}));
} else {
userListener.onResponse(null);
}

View File

@ -5,7 +5,6 @@
*/
package org.elasticsearch.xpack.security.authc.file;
import java.util.HashSet;
import java.util.Map;
import java.util.Set;

View File

@ -80,7 +80,14 @@ public class FileUserPasswdStore {
public boolean verifyPassword(String username, SecuredString password) {
char[] hash = users.get(username);
return hash != null && hasher.verify(password, hash);
if (hash == null) {
return false;
}
if (hasher.verify(password, hash) == false) {
logger.debug("User [{}] exists in file but authentication failed", username);
return false;
}
return true;
}
public boolean userExists(String username) {

View File

@ -58,6 +58,7 @@ public class LdapSessionFactory extends SessionFactory {
throw new IllegalArgumentException("missing required LDAP setting ["
+ RealmSettings.getFullSettingKey(config, USER_DN_TEMPLATES_SETTING) + "]");
}
logger.info("Realm [{}] is in user-dn-template mode: [{}]", config.name(), userDnTemplates);
groupResolver = groupResolver(settings);
}

View File

@ -99,6 +99,8 @@ class LdapUserSearchSessionFactory extends SessionFactory {
} else {
connectionPool = null;
}
logger.info("Realm [{}] is in user-search mode - base_dn=[{}], attribute=[{}]",
config.name(), userSearchBaseDn, userAttribute);
}
static LDAPConnectionPool createConnectionPool(RealmConfig config, ServerSet serverSet, TimeValue timeout, Logger logger)

View File

@ -89,24 +89,26 @@ public abstract class CachingUsernamePasswordRealm extends UsernamePasswordRealm
UserWithHash userWithHash = cache.get(token.principal());
if (userWithHash == null) {
if (logger.isDebugEnabled()) {
logger.debug("user not found in cache, proceeding with normal authentication");
logger.debug("user [{}] not found in cache for realm [{}], proceeding with normal authentication",
token.principal(), name());
}
doAuthenticateAndCache(token, ActionListener.wrap((user) -> {
if (user != null) {
logger.debug("authenticated user [{}], with roles [{}]", token.principal(), user.roles());
logger.debug("realm [{}] authenticated user [{}], with roles [{}]", name(), token.principal(), user.roles());
}
listener.onResponse(user);
}, listener::onFailure));
} else if (userWithHash.hasHash()) {
if (userWithHash.verify(token.credentials())) {
logger.debug("authenticated user [{}], with roles [{}]", token.principal(), userWithHash.user.roles());
logger.debug("realm [{}] authenticated user [{}], with roles [{}]", name(), token.principal(),
userWithHash.user.roles());
listener.onResponse(userWithHash.user);
} else {
cache.invalidate(token.principal());
doAuthenticateAndCache(token, ActionListener.wrap((user) -> {
if (user != null) {
logger.debug("cached user's password changed. authenticated user [{}], with roles [{}]", token.principal(),
user.roles());
logger.debug("cached user's password changed. realm [{}] authenticated user [{}], with roles [{}]",
name(), token.principal(), user.roles());
}
listener.onResponse(user);
}, listener::onFailure));
@ -115,8 +117,8 @@ public abstract class CachingUsernamePasswordRealm extends UsernamePasswordRealm
cache.invalidate(token.principal());
doAuthenticateAndCache(token, ActionListener.wrap((user) -> {
if (user != null) {
logger.debug("cached user came from a lookup and could not be used for authentication. authenticated user [{}]" +
" with roles [{}]", token.principal(), user.roles());
logger.debug("cached user came from a lookup and could not be used for authentication. " +
"realm [{}] authenticated user [{}] with roles [{}]", name(), token.principal(), user.roles());
}
listener.onResponse(user);
}, listener::onFailure));

View File

@ -107,6 +107,8 @@ public class DnRoleMapper {
logger.trace("reading realm [{}/{}] role mappings file [{}]...", realmType, realmName, path.toAbsolutePath());
if (!Files.exists(path)) {
logger.warn("Role mapping file [{}] for realm [{}] does not exist. Role mapping will be skipped.",
path.toAbsolutePath(), realmName);
return emptyMap();
}