From 18835fe4df967b0230665e29cc26cf59990c6635 Mon Sep 17 00:00:00 2001 From: Tim Vernum Date: Mon, 10 Apr 2017 21:21:40 +1000 Subject: [PATCH] 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@c6ea98b038c1d0ca2b2ae4eae93497fcb848ff0b --- .../security/authc/AuthenticationService.java | 7 ++++++- .../xpack/security/authc/file/FileRealm.java | 1 - .../security/authc/file/FileUserPasswdStore.java | 9 ++++++++- .../security/authc/ldap/LdapSessionFactory.java | 1 + .../authc/ldap/LdapUserSearchSessionFactory.java | 2 ++ .../support/CachingUsernamePasswordRealm.java | 16 +++++++++------- .../security/authc/support/DnRoleMapper.java | 2 ++ 7 files changed, 28 insertions(+), 10 deletions(-) diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticationService.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticationService.java index 767b3088776..f623330f9ce 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticationService.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticationService.java @@ -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); } diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileRealm.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileRealm.java index 24664cf9af1..3a8332fbb0c 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileRealm.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileRealm.java @@ -5,7 +5,6 @@ */ package org.elasticsearch.xpack.security.authc.file; -import java.util.HashSet; import java.util.Map; import java.util.Set; diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileUserPasswdStore.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileUserPasswdStore.java index d3e3b60a56f..27aa06c9e73 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileUserPasswdStore.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/file/FileUserPasswdStore.java @@ -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) { diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapSessionFactory.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapSessionFactory.java index 8868590afdd..4b831333999 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapSessionFactory.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapSessionFactory.java @@ -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); } diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapUserSearchSessionFactory.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapUserSearchSessionFactory.java index b532ac0faa9..4c9cd693ee0 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapUserSearchSessionFactory.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/ldap/LdapUserSearchSessionFactory.java @@ -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) diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/CachingUsernamePasswordRealm.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/CachingUsernamePasswordRealm.java index 5704c74c590..330ee0679a0 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/CachingUsernamePasswordRealm.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/CachingUsernamePasswordRealm.java @@ -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)); diff --git a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/DnRoleMapper.java b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/DnRoleMapper.java index f99ca534221..39b054f0526 100644 --- a/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/DnRoleMapper.java +++ b/plugin/src/main/java/org/elasticsearch/xpack/security/authc/support/DnRoleMapper.java @@ -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(); }