Expose realms authentication metrics (#104200)

This PR adds metrics for recording successful and failed
authentications for individual realms. Exposed metrics are:

- `es.security.authc.realms.success.total`
- `es.security.authc.realms.failures.total`
- `es.security.authc.realms.time`

Each of the metric is exposed at node level and includes additional information with these attributes:

- `es.security.realm_type` - can be one of: `jwt`, `saml`, `oidc`, `active_directory`, `ldap`, `pki`, `kerberos`...
- `es.security.realm_name`
- `es.security.realm_authc_failure_reason`

docs/changelog/104200.yaml

@@ -0,0 +1,5 @@
+pr: 104200
+summary: Expose realms authentication metrics
+area: Authentication
+type: enhancement
+issues: []

x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/AuthenticationService.java

@@ -114,7 +114,7 @@ public class AuthenticationService {
             new ServiceAccountAuthenticator(serviceAccountService, nodeName, meterRegistry),
             new OAuth2TokenAuthenticator(tokenService, meterRegistry),
             new ApiKeyAuthenticator(apiKeyService, nodeName, meterRegistry),
-            new RealmsAuthenticator(numInvalidation, lastSuccessfulAuthCache)
+            new RealmsAuthenticator(numInvalidation, lastSuccessfulAuthCache, meterRegistry)
         );
     }
 

x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/RealmsAuthenticator.java

@@ -17,6 +17,7 @@ import org.elasticsearch.common.cache.Cache;
 import org.elasticsearch.common.util.concurrent.ThreadContext;
 import org.elasticsearch.core.Tuple;
 import org.elasticsearch.rest.RestStatus;
+import org.elasticsearch.telemetry.metric.MeterRegistry;
 import org.elasticsearch.xpack.core.common.IteratingActionListener;
 import org.elasticsearch.xpack.core.security.authc.Authentication;
 import org.elasticsearch.xpack.core.security.authc.AuthenticationResult;
@@ -25,9 +26,13 @@ import org.elasticsearch.xpack.core.security.authc.AuthenticationToken;
 import org.elasticsearch.xpack.core.security.authc.Realm;
 import org.elasticsearch.xpack.core.security.user.User;
 import org.elasticsearch.xpack.security.authc.support.RealmUserLookup;
+import org.elasticsearch.xpack.security.metric.InstrumentedSecurityActionListener;
+import org.elasticsearch.xpack.security.metric.SecurityMetricType;
+import org.elasticsearch.xpack.security.metric.SecurityMetrics;
 
 import java.util.ArrayList;
 import java.util.Collections;
+import java.util.HashMap;
 import java.util.LinkedHashMap;
 import java.util.List;
 import java.util.Map;
@@ -35,19 +40,40 @@ import java.util.Objects;
 import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.atomic.AtomicReference;
 import java.util.function.BiConsumer;
+import java.util.function.LongSupplier;
 
 import static org.elasticsearch.core.Strings.format;
 
 public class RealmsAuthenticator implements Authenticator {
 
+    public static final String ATTRIBUTE_REALM_NAME = "es.security.realm_name";
+    public static final String ATTRIBUTE_REALM_TYPE = "es.security.realm_type";
+    public static final String ATTRIBUTE_REALM_AUTHC_FAILURE_REASON = "es.security.realm_authc_failure_reason";
+
     private static final Logger logger = LogManager.getLogger(RealmsAuthenticator.class);
 
     private final AtomicLong numInvalidation;
     private final Cache<String, Realm> lastSuccessfulAuthCache;
+    private final SecurityMetrics<Realm> authenticationMetrics;
+
+    public RealmsAuthenticator(AtomicLong numInvalidation, Cache<String, Realm> lastSuccessfulAuthCache, MeterRegistry meterRegistry) {
+        this(numInvalidation, lastSuccessfulAuthCache, meterRegistry, System::nanoTime);
+    }
 
-    public RealmsAuthenticator(AtomicLong numInvalidation, Cache<String, Realm> lastSuccessfulAuthCache) {
+    RealmsAuthenticator(
+        AtomicLong numInvalidation,
+        Cache<String, Realm> lastSuccessfulAuthCache,
+        MeterRegistry meterRegistry,
+        LongSupplier nanoTimeSupplier
+    ) {
         this.numInvalidation = numInvalidation;
         this.lastSuccessfulAuthCache = lastSuccessfulAuthCache;
+        this.authenticationMetrics = new SecurityMetrics<>(
+            SecurityMetricType.AUTHC_REALMS,
+            meterRegistry,
+            this::buildMetricAttributes,
+            nanoTimeSupplier
+        );
     }
 
     @Override
@@ -141,66 +167,69 @@ public class RealmsAuthenticator implements Authenticator {
                     realm,
                     authenticationToken.getClass().getName()
                 );
-                realm.authenticate(authenticationToken, ActionListener.wrap(result -> {
-                    assert result != null : "Realm " + realm + " produced a null authentication result";
-                    logger.debug(
-                        "Authentication of [{}] using realm [{}] with token [{}] was [{}]",
-                        authenticationToken.principal(),
-                        realm,
-                        authenticationToken.getClass().getSimpleName(),
-                        result
-                    );
-                    if (result.getStatus() == AuthenticationResult.Status.SUCCESS) {
-                        // user was authenticated, populate the authenticated by information
-                        authenticatedByRef.set(realm);
-                        authenticationResultRef.set(result);
-                        if (lastSuccessfulAuthCache != null && startInvalidation == numInvalidation.get()) {
-                            lastSuccessfulAuthCache.put(authenticationToken.principal(), realm);
-                        }
-                        userListener.onResponse(result.getValue());
-                    } else {
-                        // the user was not authenticated, call this so we can audit the correct event
-                        context.getRequest().realmAuthenticationFailed(authenticationToken, realm.name());
-                        if (result.getStatus() == AuthenticationResult.Status.TERMINATE) {
-                            final var resultException = result.getException();
-                            if (resultException != null) {
-                                logger.info(
-                                    () -> format(
-                                        "Authentication of [%s] was terminated by realm [%s] - %s",
+                realm.authenticate(
+                    authenticationToken,
+                    InstrumentedSecurityActionListener.wrapForAuthc(authenticationMetrics, realm, ActionListener.wrap(result -> {
+                        assert result != null : "Realm " + realm + " produced a null authentication result";
+                        logger.debug(
+                            "Authentication of [{}] using realm [{}] with token [{}] was [{}]",
+                            authenticationToken.principal(),
+                            realm,
+                            authenticationToken.getClass().getSimpleName(),
+                            result
+                        );
+                        if (result.getStatus() == AuthenticationResult.Status.SUCCESS) {
+                            // user was authenticated, populate the authenticated by information
+                            authenticatedByRef.set(realm);
+                            authenticationResultRef.set(result);
+                            if (lastSuccessfulAuthCache != null && startInvalidation == numInvalidation.get()) {
+                                lastSuccessfulAuthCache.put(authenticationToken.principal(), realm);
+                            }
+                            userListener.onResponse(result.getValue());
+                        } else {
+                            // the user was not authenticated, call this so we can audit the correct event
+                            context.getRequest().realmAuthenticationFailed(authenticationToken, realm.name());
+                            if (result.getStatus() == AuthenticationResult.Status.TERMINATE) {
+                                final var resultException = result.getException();
+                                if (resultException != null) {
+                                    logger.info(
+                                        () -> format(
+                                            "Authentication of [%s] was terminated by realm [%s] - %s",
+                                            authenticationToken.principal(),
+                                            realm.name(),
+                                            result.getMessage()
+                                        ),
+                                        resultException
+                                    );
+                                    userListener.onFailure(resultException);
+                                } else {
+                                    logger.info(
+                                        "Authentication of [{}] was terminated by realm [{}] - {}",
                                         authenticationToken.principal(),
                                         realm.name(),
                                         result.getMessage()
-                                    ),
-                                    resultException
-                                );
-                                userListener.onFailure(resultException);
+                                    );
+                                    userListener.onFailure(AuthenticationTerminatedSuccessfullyException.INSTANCE);
+                                }
                             } else {
-                                logger.info(
-                                    "Authentication of [{}] was terminated by realm [{}] - {}",
-                                    authenticationToken.principal(),
-                                    realm.name(),
-                                    result.getMessage()
-                                );
-                                userListener.onFailure(AuthenticationTerminatedSuccessfullyException.INSTANCE);
-                            }
-                        } else {
-                            if (result.getMessage() != null) {
-                                messages.put(realm, new Tuple<>(result.getMessage(), result.getException()));
+                                if (result.getMessage() != null) {
+                                    messages.put(realm, new Tuple<>(result.getMessage(), result.getException()));
+                                }
+                                userListener.onResponse(null);
                             }
-                            userListener.onResponse(null);
                         }
-                    }
-                }, (ex) -> {
-                    logger.warn(
-                        () -> format(
-                            "An error occurred while attempting to authenticate [%s] against realm [%s]",
-                            authenticationToken.principal(),
-                            realm.name()
-                        ),
-                        ex
-                    );
-                    userListener.onFailure(ex);
-                }));
+                    }, (ex) -> {
+                        logger.warn(
+                            () -> format(
+                                "An error occurred while attempting to authenticate [%s] against realm [%s]",
+                                authenticationToken.principal(),
+                                realm.name()
+                            ),
+                            ex
+                        );
+                        userListener.onFailure(ex);
+                    }))
+                );
             } else {
                 userListener.onResponse(null);
             }
@@ -362,4 +391,14 @@ public class RealmsAuthenticator implements Authenticator {
             return this;
         }
     }
+
+    private Map<String, Object> buildMetricAttributes(Realm realm, String failureReason) {
+        final Map<String, Object> attributes = new HashMap<>(failureReason != null ? 3 : 2);
+        attributes.put(ATTRIBUTE_REALM_NAME, realm.name());
+        attributes.put(ATTRIBUTE_REALM_TYPE, realm.type());
+        if (failureReason != null) {
+            attributes.put(ATTRIBUTE_REALM_AUTHC_FAILURE_REASON, failureReason);
+        }
+        return attributes;
+    }
 }

x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/metric/SecurityMetricType.java

@@ -49,6 +49,13 @@ public enum SecurityMetricType {
         )
     ),
 
+    AUTHC_REALMS(
+        SecurityMetricGroup.AUTHC,
+        new SecurityMetricInfo("es.security.authc.realms.success.total", "Number of successful realm authentications.", "count"),
+        new SecurityMetricInfo("es.security.authc.realms.failures.total", "Number of failed realm authentications.", "count"),
+        new SecurityMetricInfo("es.security.authc.realms.time", "Time it took (in nanoseconds) to execute realm authentication.", "ns")
+    ),
+
     ;
 
     private final SecurityMetricGroup group;

x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/AuthenticationServiceTests.java

@@ -575,7 +575,8 @@ public class AuthenticationServiceTests extends ESTestCase {
         }, this::logAndFail));
 
         verify(auditTrail).authenticationFailed(reqId.get(), firstRealm.name(), token, "_action", transportRequest);
-        verify(firstRealm, times(2)).name(); // used above one time
+        verify(firstRealm, times(4)).name(); // used above one time plus two times for authc result and time metrics
+        verify(firstRealm, times(2)).type(); // used two times to collect authc result and time metrics
         verify(secondRealm, times(2)).realmRef(); // also used in license tracking
         verify(firstRealm, times(2)).token(threadContext);
         verify(secondRealm, times(2)).token(threadContext);
@@ -583,6 +584,8 @@ public class AuthenticationServiceTests extends ESTestCase {
         verify(secondRealm, times(2)).supports(token);
         verify(firstRealm).authenticate(eq(token), anyActionListener());
         verify(secondRealm, times(2)).authenticate(eq(token), anyActionListener());
+        verify(secondRealm, times(4)).name(); // called two times for every authenticate call to collect authc result and time metrics
+        verify(secondRealm, times(4)).type(); // called two times for every authenticate call to collect authc result and time metrics
         verifyNoMoreInteractions(auditTrail, firstRealm, secondRealm);
 
         // Now assume some change in the backend system so that 2nd realm no longer has the user, but the 1st realm does.
@@ -711,7 +714,8 @@ public class AuthenticationServiceTests extends ESTestCase {
             verify(operatorPrivilegesService).maybeMarkOperatorUser(eq(result), eq(threadContext));
         }, this::logAndFail));
         verify(auditTrail, times(2)).authenticationFailed(reqId.get(), firstRealm.name(), token, "_action", transportRequest);
-        verify(firstRealm, times(3)).name(); // used above one time
+        verify(firstRealm, times(7)).name(); // used above one time plus two times for every call to collect success and time metrics
+        verify(firstRealm, times(4)).type(); // used two times for every call to collect authc result and time metrics
         verify(secondRealm, times(2)).realmRef();
         verify(firstRealm, times(2)).token(threadContext);
         verify(secondRealm, times(2)).token(threadContext);
@@ -719,6 +723,8 @@ public class AuthenticationServiceTests extends ESTestCase {
         verify(secondRealm, times(2)).supports(token);
         verify(firstRealm, times(2)).authenticate(eq(token), anyActionListener());
         verify(secondRealm, times(2)).authenticate(eq(token), anyActionListener());
+        verify(secondRealm, times(4)).name(); // called two times for every authenticate call to collect authc result and time metrics
+        verify(secondRealm, times(4)).type(); // called two times for every authenticate call to collect authc result and time metrics
         verifyNoMoreInteractions(auditTrail, firstRealm, secondRealm);
     }
 

x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/RealmsAuthenticatorTests.java

@@ -18,7 +18,7 @@ import org.elasticsearch.common.logging.Loggers;
 import org.elasticsearch.common.settings.Settings;
 import org.elasticsearch.common.util.concurrent.ThreadContext;
 import org.elasticsearch.core.Tuple;
-import org.elasticsearch.test.ESTestCase;
+import org.elasticsearch.telemetry.TestTelemetryPlugin;
 import org.elasticsearch.test.MockLogAppender;
 import org.elasticsearch.xpack.core.security.authc.Authentication;
 import org.elasticsearch.xpack.core.security.authc.AuthenticationResult;
@@ -28,24 +28,28 @@ import org.elasticsearch.xpack.core.security.authc.AuthenticationToken;
 import org.elasticsearch.xpack.core.security.authc.Realm;
 import org.elasticsearch.xpack.core.security.authc.RealmDomain;
 import org.elasticsearch.xpack.core.security.user.User;
+import org.elasticsearch.xpack.security.metric.SecurityMetricType;
 import org.junit.Before;
 
 import java.util.List;
+import java.util.Map;
 import java.util.Set;
 import java.util.concurrent.atomic.AtomicLong;
 
 import static org.hamcrest.Matchers.equalTo;
 import static org.hamcrest.Matchers.is;
 import static org.hamcrest.Matchers.nullValue;
+import static org.hamcrest.Matchers.sameInstance;
 import static org.mockito.ArgumentMatchers.any;
 import static org.mockito.ArgumentMatchers.anyString;
 import static org.mockito.ArgumentMatchers.eq;
+import static org.mockito.ArgumentMatchers.same;
 import static org.mockito.Mockito.doAnswer;
 import static org.mockito.Mockito.doThrow;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.when;
 
-public class RealmsAuthenticatorTests extends ESTestCase {
+public class RealmsAuthenticatorTests extends AbstractAuthenticatorTests {
 
     private ThreadContext threadContext;
     private Realms realms;
@@ -63,6 +67,8 @@ public class RealmsAuthenticatorTests extends ESTestCase {
     private Cache<String, Realm> lastSuccessfulAuthCache;
     private String nodeName;
     private RealmsAuthenticator realmsAuthenticator;
+    private TestTelemetryPlugin telemetryPlugin;
+    private TestNanoTimeSupplier nanoTimeSupplier;
 
     @SuppressWarnings("unchecked")
     @Before
@@ -101,7 +107,14 @@ public class RealmsAuthenticatorTests extends ESTestCase {
 
         numInvalidation = new AtomicLong();
         lastSuccessfulAuthCache = mock(Cache.class);
-        realmsAuthenticator = new RealmsAuthenticator(numInvalidation, lastSuccessfulAuthCache);
+        telemetryPlugin = new TestTelemetryPlugin();
+        nanoTimeSupplier = new TestNanoTimeSupplier(randomLongBetween(0, 100));
+        realmsAuthenticator = new RealmsAuthenticator(
+            numInvalidation,
+            lastSuccessfulAuthCache,
+            telemetryPlugin.getTelemetryProvider(Settings.EMPTY).getMeterRegistry(),
+            nanoTimeSupplier
+        );
     }
 
     public void testExtractCredentials() {
@@ -258,6 +271,107 @@ public class RealmsAuthenticatorTests extends ESTestCase {
         assertThat(expectThrows(ElasticsearchSecurityException.class, future::actionGet), is(e));
     }
 
+    public void testRecodingSuccessfulAuthenticationMetrics() {
+        when(lastSuccessfulAuthCache.get(username)).thenReturn(randomFrom(realm1, realm2, null));
+        final Realm successfulRealm = randomFrom(realm1, realm2);
+        when(successfulRealm.supports(authenticationToken)).thenReturn(true);
+        final long successfulExecutionTimeInNanos = randomLongBetween(0, 500);
+        doAnswer(invocationOnMock -> {
+            nanoTimeSupplier.advanceTime(successfulExecutionTimeInNanos);
+            @SuppressWarnings("unchecked")
+            final ActionListener<AuthenticationResult<User>> listener = (ActionListener<AuthenticationResult<User>>) invocationOnMock
+                .getArguments()[1];
+            listener.onResponse(AuthenticationResult.success(user));
+            return null;
+        }).when(successfulRealm).authenticate(eq(authenticationToken), any());
+
+        final Authenticator.Context context = createAuthenticatorContext();
+        context.addAuthenticationToken(authenticationToken);
+
+        final PlainActionFuture<AuthenticationResult<Authentication>> future = new PlainActionFuture<>();
+        realmsAuthenticator.authenticate(context, future);
+        final AuthenticationResult<Authentication> result = future.actionGet();
+        assertThat(result.getStatus(), is(AuthenticationResult.Status.SUCCESS));
+
+        assertSingleSuccessAuthMetric(
+            telemetryPlugin,
+            SecurityMetricType.AUTHC_REALMS,
+            Map.ofEntries(
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_NAME, successfulRealm.name()),
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_TYPE, successfulRealm.type())
+            )
+        );
+
+        assertZeroFailedAuthMetrics(telemetryPlugin, SecurityMetricType.AUTHC_REALMS);
+
+        assertAuthenticationTimeMetric(
+            telemetryPlugin,
+            SecurityMetricType.AUTHC_REALMS,
+            successfulExecutionTimeInNanos,
+            Map.ofEntries(
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_NAME, successfulRealm.name()),
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_TYPE, successfulRealm.type())
+            )
+        );
+    }
+
+    public void testRecordingFailedAuthenticationMetric() {
+        when(lastSuccessfulAuthCache.get(username)).thenReturn(randomFrom(realm1, realm2, null));
+
+        final Realm unsuccessfulRealm;
+        if (randomBoolean()) {
+            when(realm1.supports(authenticationToken)).thenReturn(false);
+            unsuccessfulRealm = realm2;
+        } else {
+            when(realm2.supports(authenticationToken)).thenReturn(false);
+            unsuccessfulRealm = realm1;
+        }
+
+        when(unsuccessfulRealm.supports(authenticationToken)).thenReturn(true);
+        final long unsuccessfulExecutionTimeInNanos = randomLongBetween(0, 500);
+        doAnswer(invocationOnMock -> {
+            nanoTimeSupplier.advanceTime(unsuccessfulExecutionTimeInNanos);
+            @SuppressWarnings("unchecked")
+            final ActionListener<AuthenticationResult<User>> listener = (ActionListener<AuthenticationResult<User>>) invocationOnMock
+                .getArguments()[1];
+                listener.onResponse(AuthenticationResult.unsuccessful("unsuccessful realms authentication", null));
+            return null;
+        }).when(unsuccessfulRealm).authenticate(eq(authenticationToken), any());
+
+        final Authenticator.Context context = createAuthenticatorContext();
+        final ElasticsearchSecurityException exception = new ElasticsearchSecurityException("realms authentication failed");
+        when(request.authenticationFailed(same(authenticationToken))).thenReturn(exception);
+        context.addAuthenticationToken(authenticationToken);
+
+        final PlainActionFuture<AuthenticationResult<Authentication>> future = new PlainActionFuture<>();
+        realmsAuthenticator.authenticate(context, future);
+        var e =  expectThrows(ElasticsearchSecurityException.class, () -> future.actionGet());
+        assertThat(e, sameInstance(exception));
+
+        assertSingleFailedAuthMetric(
+            telemetryPlugin,
+            SecurityMetricType.AUTHC_REALMS,
+            Map.ofEntries(
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_NAME, unsuccessfulRealm.name()),
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_TYPE, unsuccessfulRealm.type()),
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_AUTHC_FAILURE_REASON, "unsuccessful realms authentication")
+            )
+        );
+
+        assertZeroSuccessAuthMetrics(telemetryPlugin, SecurityMetricType.AUTHC_REALMS);
+
+        assertAuthenticationTimeMetric(
+            telemetryPlugin,
+            SecurityMetricType.AUTHC_REALMS,
+            unsuccessfulExecutionTimeInNanos,
+            Map.ofEntries(
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_NAME, unsuccessfulRealm.name()),
+                Map.entry(RealmsAuthenticator.ATTRIBUTE_REALM_TYPE, unsuccessfulRealm.type())
+            )
+        );
+
+    }
+
     private void configureRealmAuthResponse(Realm realm, AuthenticationResult<User> authenticationResult) {
         doAnswer(invocationOnMock -> {
             @SuppressWarnings("unchecked")

x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/jwt/JwtTokenExtractionTests.java

@@ -11,6 +11,7 @@ import org.elasticsearch.common.cache.Cache;
 import org.elasticsearch.common.settings.SecureString;
 import org.elasticsearch.common.settings.Settings;
 import org.elasticsearch.common.util.concurrent.ThreadContext;
+import org.elasticsearch.telemetry.metric.MeterRegistry;
 import org.elasticsearch.test.ESTestCase;
 import org.elasticsearch.xpack.core.security.authc.AuthenticationToken;
 import org.elasticsearch.xpack.core.security.authc.Realm;
@@ -54,7 +55,11 @@ public class JwtTokenExtractionTests extends ESTestCase {
         Realms realms = mock(Realms.class);
         // mock realm sits in-between
         when(realms.getActiveRealms()).thenReturn(List.of(jwtRealm1, mockRealm, jwtRealm2));
-        RealmsAuthenticator realmsAuthenticator = new RealmsAuthenticator(mock(AtomicLong.class), (Cache<String, Realm>) mock(Cache.class));
+        RealmsAuthenticator realmsAuthenticator = new RealmsAuthenticator(
+            mock(AtomicLong.class),
+            (Cache<String, Realm>) mock(Cache.class),
+            MeterRegistry.NOOP
+        );
         final Authenticator.Context context = new Authenticator.Context(
             threadContext,
             mock(AuthenticationService.AuditableRequest.class),