diff --git a/docs/changelog/137941.yaml b/docs/changelog/137941.yaml new file mode 100644 index 0000000000000..a051b08d8ce4e --- /dev/null +++ b/docs/changelog/137941.yaml @@ -0,0 +1,5 @@ +pr: 137941 +summary: Additional DEBUG logging on authc failures +area: Authentication +type: enhancement +issues: [] diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/Authenticator.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/Authenticator.java index 6433cfacc77bb..ae393a348468e 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/Authenticator.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/Authenticator.java @@ -23,6 +23,7 @@ import java.io.IOException; import java.util.ArrayList; import java.util.List; +import java.util.stream.Collectors; /** * The Authenticator interface represents an authentication mechanism or a group of similar authentication mechanisms. @@ -241,5 +242,17 @@ public void addUnsuccessfulMessageToMetadata(final ElasticsearchSecurityExceptio ese.addMetadata("es.additional_unsuccessful_credentials", getUnsuccessfulMessages()); } } + + @Override + public String toString() { + return Strings.format( + "%s{tokens=%s, messages=%s}", + getClass().getSimpleName(), + this.authenticationTokens.stream() + .map(t -> t.getClass().getSimpleName() + ":" + t.principal()) + .collect(Collectors.joining(",", "[", "]")), + this.unsuccessfulMessages + ); + } } } diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticatorChain.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticatorChain.java index a87225c9f7682..b8d607edf7a3b 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticatorChain.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticatorChain.java @@ -13,6 +13,7 @@ import org.elasticsearch.action.ActionListener; import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.util.concurrent.ThreadContext; +import org.elasticsearch.core.Strings; import org.elasticsearch.node.Node; import org.elasticsearch.xpack.core.common.IteratingActionListener; import org.elasticsearch.xpack.core.security.authc.Authentication; @@ -83,11 +84,16 @@ void authenticate(Authenticator.Context context, ActionListener assert false == context.getDefaultOrderedRealmList().isEmpty() : "realm list must not be empty"; // Check whether authentication is an operator user and mark the threadContext if necessary // before returning the authentication object - final ActionListener listener = originalListener.map(authentication -> { + final ActionListener listener = ActionListener.wrap(authentication -> { assert authentication != null; operatorPrivilegesService.maybeMarkOperatorUser(authentication, context.getThreadContext()); - return authentication; + logger.trace(() -> Strings.format("Authentication for [%s]", authentication)); + originalListener.onResponse(authentication); + }, ex -> { + logger.debug(() -> Strings.format("Authentication for context [%s] failed", context), ex); + originalListener.onFailure(ex); }); + // If a token is directly provided in the context, authenticate with it if (context.getMostRecentAuthenticationToken() != null) { doAuthenticate(context, listener); diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChain.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChain.java index 10a4a82c216fa..f4d6ded5716ab 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChain.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChain.java @@ -96,6 +96,14 @@ private BiConsumer format( + "Authentication of token [%s] was terminated: %s (caused by: %s)", + token.principal(), + response.getMessage(), + ex + ) + ); if (ex == null) { iteratingListener.onFailure(context.getRequest().authenticationFailed(token)); } else { diff --git a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/AuthenticatorChainTests.java b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/AuthenticatorChainTests.java index 87bafcd2da01f..04a13161c7d3e 100644 --- a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/AuthenticatorChainTests.java +++ b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/AuthenticatorChainTests.java @@ -40,6 +40,7 @@ import java.io.IOException; import java.util.Collections; import java.util.List; +import java.util.regex.Pattern; import static org.elasticsearch.test.ActionListenerUtils.anyActionListener; import static org.hamcrest.Matchers.containsString; @@ -321,7 +322,9 @@ public void testAuthenticateFallbackAndAnonymous() throws IOException { } public void testContextWithDirectWrongTokenFailsAuthn() { - final Authenticator.Context context = createAuthenticatorContext(mock(AuthenticationToken.class)); + final AuthenticationToken token = mock(AuthenticationToken.class); + when(token.principal()).thenReturn("MOCK_USER"); + final Authenticator.Context context = createAuthenticatorContext(token); doCallRealMethod().when(serviceAccountAuthenticator).authenticate(eq(context), anyActionListener()); doCallRealMethod().when(oAuth2TokenAuthenticator).authenticate(eq(context), anyActionListener()); doCallRealMethod().when(apiKeyAuthenticator).authenticate(eq(context), anyActionListener()); @@ -335,6 +338,20 @@ public void testContextWithDirectWrongTokenFailsAuthn() { return null; }).when(realmsAuthenticator).authenticate(eq(context), any()); final PlainActionFuture future = new PlainActionFuture<>(); + + Loggers.setLevel(LogManager.getLogger(AuthenticatorChain.class), Level.DEBUG); + final MockLog mockLog = MockLog.capture(AuthenticatorChain.class); + mockLog.addExpectation( + new MockLog.PatternSeenEventExpectation( + "debug-failure", + AuthenticatorChain.class.getName(), + Level.DEBUG, + Pattern.quote("Authentication for context [Context{tokens=[") + + "AuthenticationToken\\$.*:MOCK_USER" + + Pattern.quote("], messages=[]}] failed") + ) + ); + authenticatorChain.authenticate(context, future); final ElasticsearchSecurityException e = expectThrows(ElasticsearchSecurityException.class, future::actionGet); assertThat(e.getMessage(), containsString("failed to authenticate")); @@ -345,6 +362,8 @@ public void testContextWithDirectWrongTokenFailsAuthn() { verify(realmsAuthenticator, never()).extractCredentials(any()); verifyNoMoreInteractions(authenticationContextSerializer); verifyNoMoreInteractions(operatorPrivilegesService); + mockLog.assertAllExpectationsMatched(); + // OR 2. realms fail the token doAnswer(invocationOnMock -> { @SuppressWarnings("unchecked") diff --git a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChainTests.java b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChainTests.java index 16bf0f43c0d8e..8c32356a54e60 100644 --- a/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChainTests.java +++ b/x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/PluggableAuthenticatorChainTests.java @@ -6,11 +6,18 @@ */ package org.elasticsearch.xpack.security.authc; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; +import org.elasticsearch.ElasticsearchSecurityException; import org.elasticsearch.action.ActionListener; +import org.elasticsearch.action.support.PlainActionFuture; +import org.elasticsearch.common.logging.Loggers; import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.util.concurrent.ThreadContext; import org.elasticsearch.core.Nullable; +import org.elasticsearch.rest.RestStatus; import org.elasticsearch.test.ESTestCase; +import org.elasticsearch.test.MockLog; import org.elasticsearch.xpack.core.security.authc.Authentication; import org.elasticsearch.xpack.core.security.authc.AuthenticationResult; import org.elasticsearch.xpack.core.security.authc.AuthenticationTestHelper; @@ -18,11 +25,13 @@ import org.elasticsearch.xpack.core.security.authc.CustomAuthenticator; import org.elasticsearch.xpack.core.security.user.User; import org.junit.Before; +import org.mockito.Mockito; import java.util.List; import java.util.concurrent.CountDownLatch; import java.util.concurrent.atomic.AtomicReference; +import static org.elasticsearch.test.TestMatchers.throwableWithMessage; import static org.hamcrest.Matchers.equalTo; import static org.hamcrest.Matchers.notNullValue; @@ -87,13 +96,15 @@ public String getValue() { public class TokenAAuthenticator implements CustomAuthenticator { private final String id; + private boolean succeed; public TokenAAuthenticator() { - id = "1"; + this("1", true); } - public TokenAAuthenticator(String id) { + public TokenAAuthenticator(String id, boolean succeed) { this.id = id; + this.succeed = succeed; } @Override @@ -109,9 +120,13 @@ public boolean supports(AuthenticationToken token) { @Override public void authenticate(@Nullable AuthenticationToken token, ActionListener> listener) { if (token instanceof TestTokenA testToken) { - User user = new User("token-a-auth-user-" + id + "-" + testToken.getValue()); - Authentication auth = AuthenticationTestHelper.builder().user(user).build(false); - listener.onResponse(AuthenticationResult.success(auth)); + if (succeed) { + User user = new User("token-a-auth-user-" + id + "-" + testToken.getValue()); + Authentication auth = AuthenticationTestHelper.builder().user(user).build(false); + listener.onResponse(AuthenticationResult.success(auth)); + } else { + listener.onResponse(AuthenticationResult.terminate("token-a-fail-" + id + "-" + testToken.getValue())); + } } else { listener.onResponse(AuthenticationResult.notHandled()); } @@ -243,7 +258,7 @@ public void onFailure(Exception e) { public void testAuthenticateWhenTokenSupportedByBothAuthenticatorsInChain() throws Exception { PluggableAuthenticatorChain chain = new PluggableAuthenticatorChain( - List.of(new TokenAAuthenticator("foo"), new TokenAAuthenticator("bar")) + List.of(new TokenAAuthenticator("foo", true), new TokenAAuthenticator("bar", true)) ); TestTokenA testToken = new TestTokenA("test-value"); @@ -286,7 +301,7 @@ public void onFailure(Exception e) { public void testAuthenticateWhenTokenSupportedByNoAuthenticatorsInChain() throws Exception { PluggableAuthenticatorChain chain = new PluggableAuthenticatorChain( - List.of(new TokenAAuthenticator("foo"), new TokenAAuthenticator("bar")) + List.of(new TokenAAuthenticator("foo", true), new TokenAAuthenticator("bar", true)) ); AuthenticationToken unknownToken = new AuthenticationToken() { @Override @@ -338,7 +353,37 @@ public void onFailure(Exception e) { assertThat(result.getStatus(), equalTo(AuthenticationResult.Status.CONTINUE)); } + public void testAuthenticationTermination() throws Exception { + final PluggableAuthenticatorChain chain = new PluggableAuthenticatorChain(List.of(new TokenAAuthenticator("terminate", false))); + final TestTokenA token = new TestTokenA("err"); + final Authenticator.Context context = createContext(); + context.addAuthenticationToken(token); + + Loggers.setLevel(LogManager.getLogger(PluggableAuthenticatorChain.class), Level.DEBUG); + try (MockLog mockLog = MockLog.capture(PluggableAuthenticatorChain.class)) { + mockLog.addExpectation( + new MockLog.SeenEventExpectation( + "debug-auth-failure", + PluggableAuthenticatorChain.class.getName(), + Level.DEBUG, + "Authentication of token [user-err] was terminated: token-a-fail-terminate-err (caused by: null)" + ) + ); + + final PlainActionFuture> future = new PlainActionFuture<>(); + chain.authenticate(context, future); + mockLog.assertAllExpectationsMatched(); + + final ElasticsearchSecurityException ex = expectThrows(ElasticsearchSecurityException.class, () -> future.actionGet()); + assertThat(ex, throwableWithMessage("mock-request-failure")); + assertThat(ex.status(), equalTo(RestStatus.UNAUTHORIZED)); + } + } + private Authenticator.Context createContext() { - return new Authenticator.Context(threadContext, null, null, true, null); + final var request = Mockito.mock(AuthenticationService.AuditableRequest.class); + Mockito.when(request.authenticationFailed(Mockito.any(AuthenticationToken.class))) + .thenAnswer(inv -> new ElasticsearchSecurityException("mock-request-failure", RestStatus.UNAUTHORIZED)); + return new Authenticator.Context(threadContext, request, null, true, null); } }