JWT realm logging (#98758)

The current logging for the JWT realm provides considerable amounts of data but in practice 
it is difficult to use for troubleshooting. This change focuses on the debug and trace level logging
to better enable troubleshooting potential issues. The existing logs are spread across dozens of 
log messages and are missing information about which token the log message is referring. 
The general goal is to not remove information but rather consolidate log messages and provide 
better context for troubleshooting. Specifically (in an attempt to not rewrite portions of the code)
this generally means using a string buffer for the trace messages to ensure they are part of the 
same log message and including more information about the JWT itself (but without logging the
full signed JWT).

Both debug and trace level are very verbose. The primary difference is that debug level should
not log stack traces and does not log every attempt at signature validation or all of the JWK 
filtering taking place.

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

@@ -166,7 +166,7 @@ public class JwkSetLoader implements Releasable {
         );
         // Filter JWK(s) vs signature algorithms. Only keep JWKs with a matching alg. Only keep algs with a matching JWK.
         final JwksAlgs jwksAlgsPkc = JwkValidateUtil.filterJwksAndAlgorithms(jwksPkc, allowedJwksAlgsPkc);
-        logger.info(
+        logger.debug(
             "Usable PKC: JWKs=[{}] algorithms=[{}] sha256=[{}]",
             jwksAlgsPkc.jwks().size(),
             String.join(",", jwksAlgsPkc.algs()),

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

@@ -32,32 +32,44 @@ import java.util.Collections;
 import java.util.List;
 import java.util.Set;
 import java.util.function.Predicate;
+import java.util.function.Supplier;
+
+import static org.elasticsearch.core.Strings.format;
 
 /**
  * Utilities for JWK Validation.
  */
 public class JwkValidateUtil {
-    private static final Logger LOGGER = LogManager.getLogger(JwkValidateUtil.class);
+    private static final Logger logger = LogManager.getLogger(JwkValidateUtil.class);
 
     // Static method for unit testing. No need to construct a complete RealmConfig with all settings.
     static JwkSetLoader.JwksAlgs filterJwksAndAlgorithms(final List<JWK> jwks, final List<String> algs) throws SettingsException {
-        LOGGER.trace("JWKs [" + jwks.size() + "] and Algorithms [" + String.join(",", algs) + "] before filters.");
-
-        final Predicate<JWK> keyUsePredicate = j -> ((j.getKeyUse() == null) || (KeyUse.SIGNATURE.equals(j.getKeyUse())));
-        final List<JWK> jwksSig = jwks.stream().filter(keyUsePredicate).toList();
-        LOGGER.trace("JWKs [" + jwksSig.size() + "] after KeyUse [SIGNATURE||null] filter.");
-
-        final Predicate<JWK> keyOpPredicate = j -> ((j.getKeyOperations() == null) || (j.getKeyOperations().contains(KeyOperation.VERIFY)));
-        final List<JWK> jwksVerify = jwksSig.stream().filter(keyOpPredicate).toList();
-        LOGGER.trace("JWKs [" + jwksVerify.size() + " after KeyOperation [VERIFY||null] filter.");
-
-        final List<JWK> jwksFiltered = jwksVerify.stream().filter(j -> (algs.stream().anyMatch(a -> isMatch(j, a)))).toList();
-        LOGGER.trace("JWKs [" + jwksFiltered.size() + "] after Algorithms [" + String.join(",", algs) + "] filter.");
-
-        final List<String> algsFiltered = algs.stream().filter(a -> (jwksFiltered.stream().anyMatch(j -> isMatch(j, a)))).toList();
-        LOGGER.trace("Algorithms [" + String.join(",", algsFiltered) + "] after remaining JWKs [" + jwksFiltered.size() + "] filter.");
-
-        return new JwkSetLoader.JwksAlgs(jwksFiltered, algsFiltered);
+        try (JwtUtil.TraceBuffer tracer = new JwtUtil.TraceBuffer(logger)) {
+            tracer.append("Filtering [{}] JWKs for the following algorithms [{}].", jwks.size(), String.join(",", algs));
+
+            final Predicate<JWK> keyUsePredicate = j -> ((j.getKeyUse() == null) || (KeyUse.SIGNATURE.equals(j.getKeyUse())));
+            final List<JWK> jwksSig = jwks.stream().filter(keyUsePredicate).toList();
+            tracer.append("[{}] remaining JWKs after KeyUse [SIGNATURE] filter.", jwksSig.size());
+
+            final Predicate<JWK> keyOpPredicate = j -> ((j.getKeyOperations() == null)
+                || (j.getKeyOperations().contains(KeyOperation.VERIFY)));
+            final List<JWK> jwksVerify = jwksSig.stream().filter(keyOpPredicate).toList();
+            tracer.append("[{}] remaining JWKs after KeyOperation [VERIFY] filter.", jwksVerify.size());
+
+            final List<JWK> jwksFiltered = jwksVerify.stream().filter(j -> (algs.stream().anyMatch(a -> isMatch(j, a, tracer)))).toList();
+            tracer.append("[{}] remaining JWKs after algorithms name filter.", jwksFiltered.size());
+
+            final List<String> algsFiltered = algs.stream()
+                .filter(a -> (jwksFiltered.stream().anyMatch(j -> isMatch(j, a, tracer))))
+                .toList();
+            tracer.append(
+                "[{}] remaining JWKs after configured algorithms [{}] filter.",
+                jwksFiltered.size(),
+                String.join(",", algsFiltered)
+            );
+
+            return new JwkSetLoader.JwksAlgs(jwksFiltered, algsFiltered);
+        }
     }
 
     /**
@@ -68,14 +80,14 @@ public class JwkValidateUtil {
      * @param algorithm Algorithm string of value HS256, HS384, HS512, RS256, RS384, RS512, PS256, PS384, PS512, ES256, ES384, or ES512.
      * @return True if JWT type and strength match both requirements for the signature algorithm.
      */
-    static boolean isMatch(final JWK jwk, final String algorithm) {
+    static boolean isMatch(final JWK jwk, final String algorithm, JwtUtil.TraceBuffer tracer) {
         try {
             if ((JwtRealmSettings.SUPPORTED_SIGNATURE_ALGORITHMS_HMAC.contains(algorithm)) && (jwk instanceof OctetSequenceKey jwkHmac)) {
                 final int bits = jwkHmac.size();
                 final int min = MACSigner.getMinRequiredSecretLength(JWSAlgorithm.parse(algorithm));
                 final boolean isMatch = bits >= min;
                 if (isMatch == false) {
-                    LOGGER.trace("HMAC JWK [" + bits + "] bits too small for algorithm [" + algorithm + "] minimum [" + min + "].");
+                    tracer.append("HMAC JWK [" + bits + "] bits too small for algorithm [" + algorithm + "] minimum [" + min + "].");
                 }
                 return isMatch;
             } else if ((JwtRealmSettings.SUPPORTED_SIGNATURE_ALGORITHMS_RSA.contains(algorithm)) && (jwk instanceof RSAKey jwkRsa)) {
@@ -83,7 +95,7 @@ public class JwkValidateUtil {
                 final int min = RSAKeyGenerator.MIN_KEY_SIZE_BITS;
                 final boolean isMatch = bits >= min;
                 if (isMatch == false) {
-                    LOGGER.trace("RSA JWK [" + bits + "] bits too small for algorithm [" + algorithm + "] minimum [" + min + "].");
+                    tracer.append("RSA JWK [" + bits + "] bits too small for algorithm [" + algorithm + "] minimum [" + min + "].");
                 }
                 return isMatch;
             } else if ((JwtRealmSettings.SUPPORTED_SIGNATURE_ALGORITHMS_EC.contains(algorithm)) && (jwk instanceof ECKey jwkEc)) {
@@ -91,12 +103,20 @@ public class JwkValidateUtil {
                 final Set<Curve> allowed = Curve.forJWSAlgorithm(JWSAlgorithm.parse(algorithm));
                 final boolean isMatch = allowed.contains(curve);
                 if (isMatch == false) {
-                    LOGGER.trace("EC JWK [" + curve + "] curve not allowed for algorithm [" + algorithm + "] allowed " + allowed + ".");
+                    tracer.append("EC JWK [" + curve + "] curve not allowed for algorithm [" + algorithm + "] allowed " + allowed + ".");
                 }
                 return isMatch;
             }
         } catch (Exception e) {
-            LOGGER.trace("Unexpected exception", e);
+            Supplier<String> message = () -> format(
+                "Unexpected exception while matching JWK with kid [%s] to it's algorithm requirement.",
+                jwk.getKeyID()
+            );
+            if (logger.isTraceEnabled()) {
+                logger.trace(message.get(), e);
+            } else {
+                logger.debug(message.get());
+            }
         }
         return false;
     }

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

@@ -70,8 +70,8 @@ public class JwtAuthenticator implements Releasable {
         final JWTClaimsSet jwtClaimsSet = jwtAuthenticationToken.getJWTClaimsSet();
         final JWSHeader jwsHeader = signedJWT.getHeader();
 
-        if (logger.isDebugEnabled()) {
-            logger.debug(
+        if (logger.isTraceEnabled()) {
+            logger.trace(
                 "Realm [{}] successfully parsed JWT token [{}] with header [{}] and claimSet [{}]",
                 realmConfig.name(),
                 tokenPrincipal,

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

@@ -260,7 +260,12 @@ public class JwtRealm extends Realm implements CachingRealm, Releasable {
             // Authenticate client: If client authc off, fall through. Otherwise, only fall through if secret matched.
             final SecureString clientSecret = jwtAuthenticationToken.getClientAuthenticationSharedSecret();
             try {
-                JwtUtil.validateClientAuthentication(clientAuthenticationType, clientAuthenticationSharedSecret, clientSecret);
+                JwtUtil.validateClientAuthentication(
+                    clientAuthenticationType,
+                    clientAuthenticationSharedSecret,
+                    clientSecret,
+                    tokenPrincipal
+                );
                 logger.trace("Realm [{}] client authentication succeeded for token=[{}].", name(), tokenPrincipal);
             } catch (Exception e) {
                 final String msg = "Realm [" + name() + "] client authentication failed for token=[" + tokenPrincipal + "].";
@@ -283,15 +288,36 @@ public class JwtRealm extends Realm implements CachingRealm, Releasable {
             }
 
             // Validate JWT: Extract JWT and claims set, and validate JWT.
-            jwtAuthenticator.authenticate(
-                jwtAuthenticationToken,
-                ActionListener.wrap(claimsSet -> processValidatedJwt(tokenPrincipal, jwtCacheKey, claimsSet, listener), ex -> {
-                    final String msg = "Realm [" + name() + "] JWT validation failed for token=[" + tokenPrincipal + "].";
-                    logger.debug(msg, ex);
-                    // TODO: No point to continue to another realm if failure is ParseException
-                    listener.onResponse(AuthenticationResult.unsuccessful(msg, ex));
-                })
-            );
+            jwtAuthenticator.authenticate(jwtAuthenticationToken, ActionListener.wrap(claimsSet -> {
+                if (logger.isDebugEnabled()) {
+                    logger.debug(
+                        "Realm [{}] JWT validation success for token=[{}] with header [{}] and claimSet [{}]",
+                        name(),
+                        tokenPrincipal,
+                        jwtAuthenticationToken.getSignedJWT().getHeader(),
+                        jwtAuthenticationToken.getJWTClaimsSet()
+                    );
+                }
+                processValidatedJwt(tokenPrincipal, jwtCacheKey, claimsSet, listener);
+            }, ex -> {
+                final String msg = "Realm ["
+                    + name()
+                    + "] JWT validation failed for token=["
+                    + tokenPrincipal
+                    + "] with header ["
+                    + jwtAuthenticationToken.getSignedJWT().getHeader()
+                    + "] and claimSet ["
+                    + jwtAuthenticationToken.getJWTClaimsSet()
+                    + "]";
+
+                if (logger.isTraceEnabled()) {
+                    logger.trace(msg, ex);
+                } else {
+                    logger.debug(msg + " Cause: " + ex.getMessage()); // only log the stack trace at trace level
+                }
+                // TODO: No point to continue to another realm if failure is ParseException
+                listener.onResponse(AuthenticationResult.unsuccessful(msg, ex));
+            }));
 
         } else {
             assert false : "should not happen";
@@ -373,7 +399,9 @@ public class JwtRealm extends Realm implements CachingRealm, Releasable {
         final ActionListener<AuthenticationResult<User>> logAndCacheListener = ActionListener.wrap(result -> {
             if (result.isAuthenticated()) {
                 final User user = result.getValue();
-                logger.debug(() -> format("Realm [%s] roles [%s] for principal=[%s].", name(), join(",", user.roles()), principal));
+                logger.trace(
+                    () -> format("Realm [%s] roles resolved [%s] for principal=[%s].", name(), join(",", user.roles()), principal)
+                );
                 if (isCacheEnabled()) {
                     try (ReleasableLock ignored = jwtCacheHelper.acquireUpdateLock()) {
                         final long expWallClockMillis = claimsSet.getExpirationTime().getTime() + allowedClockSkew.getMillis();
@@ -459,20 +487,34 @@ public class JwtRealm extends Realm implements CachingRealm, Releasable {
         final FallbackableClaim subClaim = new FallbackableClaim("sub", fallbackClaimNames, jwtClaimsSet);
         final String subject = subClaim.getStringClaimValue();
         if (false == Strings.hasText(subject)) {
-            logger.debug("claim [{}] is missing for building token principal for realm [{}]", subClaim, name());
+            logger.debug(
+                "Can not build token principal for realm [{}] since claim [{}] is missing from claimSet [{}]",
+                name(),
+                subClaim,
+                jwtClaimsSet
+            );
             return null;
         }
 
         final FallbackableClaim audClaim = new FallbackableClaim("aud", fallbackClaimNames, jwtClaimsSet);
         final List<String> audiences = audClaim.getStringListClaimValue();
         if (audiences == null || audiences.isEmpty()) {
-            logger.debug("claim [{}] is missing for building token principal for realm [{}]", audClaim, name());
+            logger.debug(
+                "Can not build token principal for realm [{}] since claim [{}] is missing from claimSet [{}]",
+                name(),
+                subClaim,
+                jwtClaimsSet
+            );
             return null;
         }
 
         final String userPrincipal = claimParserPrincipal.getClaimValue(jwtClaimsSet);
         if (false == Strings.hasText(userPrincipal)) {
-            logger.debug("No user principal can be extracted with [{}] for realm [{}]", claimParserPrincipal, name());
+            logger.debug(
+                "Can not build token principal for realm [{}] since no user principal can be extracted with [{}]",
+                name(),
+                claimParserPrincipal
+            );
             return null;
         }
         return String.join(",", new TreeSet<>(audiences)) + "/" + subject + "/" + userPrincipal;

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

@@ -17,6 +17,7 @@ import com.nimbusds.jose.jwk.ECKey;
 import com.nimbusds.jose.jwk.JWK;
 import com.nimbusds.jose.jwk.OctetSequenceKey;
 import com.nimbusds.jose.jwk.RSAKey;
+import com.nimbusds.jose.util.Base64URL;
 import com.nimbusds.jwt.SignedJWT;
 
 import org.apache.logging.log4j.LogManager;
@@ -39,6 +40,7 @@ import org.elasticsearch.xpack.core.ssl.SSLService;
 
 import java.util.Arrays;
 import java.util.List;
+import java.util.function.Supplier;
 import java.util.stream.Stream;
 
 public interface JwtSignatureValidator extends Releasable {
@@ -274,26 +276,33 @@ public interface JwtSignatureValidator extends Releasable {
                 validateSignature(signedJWT, jwksAlgs.jwks());
                 listener.onResponse(null);
             } catch (Exception primaryException) {
-                logger.debug(
-                    () -> org.elasticsearch.core.Strings.format(
-                        "Signature verification failed for JWT [%s] reloading JWKSet (was: #[%s] JWKs, #[%s] algs, sha256=[%s])",
-                        tokenPrincipal,
-                        jwksAlgs.jwks().size(),
-                        jwksAlgs.algs().size(),
-                        MessageDigests.toHexString(contentAndJwksAlgs.sha256())
-                    ),
-                    primaryException
+                String message = org.elasticsearch.core.Strings.format(
+                    "Signature verification failed for JWT token [%s] against JWK set with sha256=[%s].",
+                    tokenPrincipal,
+                    MessageDigests.toHexString(contentAndJwksAlgs.sha256())
                 );
 
+                if (logger.isTraceEnabled()) {
+                    logger.trace(message, primaryException);
+                } else {
+                    logger.debug(message + " Cause: " + primaryException.getMessage());
+                }
+
+                logger.debug("Attempting to reload JWK set with sha256=[{}]", MessageDigests.toHexString(contentAndJwksAlgs.sha256()));
                 jwkSetLoader.reload(ActionListener.wrap(ignore -> {
                     final JwkSetLoader.ContentAndJwksAlgs maybeUpdatedContentAndJwksAlgs = jwkSetLoader.getContentAndJwksAlgs();
                     if (Arrays.equals(maybeUpdatedContentAndJwksAlgs.sha256(), initialJwksVersion)) {
                         logger.debug(
                             "No change in reloaded JWK set with sha256=[{}] will not retry signature verification",
-                            MessageDigests.toHexString(jwkSetLoader.getContentAndJwksAlgs().sha256())
+                            MessageDigests.toHexString(maybeUpdatedContentAndJwksAlgs.sha256())
                         );
                         listener.onFailure(primaryException);
                         return;
+                    } else {
+                        logger.debug(
+                            "Successful reload of JWK set. Now with sha256=[{}]",
+                            MessageDigests.toHexString(maybeUpdatedContentAndJwksAlgs.sha256())
+                        );
                     }
 
                     // If all PKC JWKs were replaced, all PKC JWT cache entries need to be invalidated.
@@ -342,66 +351,86 @@ public interface JwtSignatureValidator extends Releasable {
      * @throws Exception Error if JWKs fail to validate the Signed JWT.
      */
     default void validateSignature(final SignedJWT jwt, final List<JWK> jwks) throws Exception {
+
         assert jwks != null : "Verify requires a non-null JWK list";
         if (jwks.isEmpty()) {
-            throw new ElasticsearchException("Verify requires a non-empty JWK list");
-        }
-        final String id = jwt.getHeader().getKeyID();
-        final JWSAlgorithm alg = jwt.getHeader().getAlgorithm();
-        logger.trace("JWKs [{}], JWT KID [{}], and JWT Algorithm [{}] before filters.", jwks.size(), id, alg.getName());
-
-        // If JWT has optional kid header, and realm JWKs have optional kid attribute, any mismatches JWT.kid vs JWK.kid can be ignored.
-        // Keep any JWKs if JWK optional kid attribute is missing. Keep all JWKs if JWT optional kid header is missing.
-        final List<JWK> jwksKid = jwks.stream().filter(j -> ((id == null) || (j.getKeyID() == null) || (id.equals(j.getKeyID())))).toList();
-        logger.trace("JWKs [{}] after KID [{}](|null) filter.", jwksKid.size(), id);
-
-        // JWT has mandatory alg header. If realm JWKs have optional alg attribute, any mismatches JWT.alg vs JWK.alg can be ignored.
-        // Keep any JWKs if JWK optional alg attribute is missing.
-        final List<JWK> jwksAlg = jwksKid.stream().filter(j -> (j.getAlgorithm() == null) || (alg.equals(j.getAlgorithm()))).toList();
-        logger.trace("JWKs [{}] after Algorithm [{}](|null) filter.", jwksAlg.size(), alg.getName());
-
-        // PKC Example: Realm has five PKC JWKs RSA-2048, RSA-3072, EC-P256, EC-P384, and EC-P512. JWT alg allows ignoring some.
-        // - If JWT alg is RS256, only RSA-2048 and RSA-3072 are valid for a JWT RS256 signature. Ignore three EC JWKs.
-        // - If JWT alg is ES512, only EC-P512 is valid for a JWT ES512 signature. Ignore four JWKs (two RSA, two EC).
-        // - If JWT alg is ES384, only EC-P384 is valid for a JWT ES384 signature. Ignore four JWKs (two RSA, two EC).
-        // - If JWT alg is ES256, only EC-P256 is valid for a JWT ES256 signature. Ignore four JWKs (two RSA, two EC).
-        //
-        // HMAC Example: Realm has six HMAC JWKs of bit lengths 256, 320, 384, 400, 512, and 1000. JWT alg allows ignoring some.
-        // - If JWT alg is HS256, all are valid for a JWT HS256 signature. Don't ignore any HMAC JWKs.
-        // - If JWT alg is HS384, only 384, 400, 512, and 1000 are valid for a JWT HS384 signature. Ignore two HMAC JWKs.
-        // - If JWT alg is HS512, only 512 and 1000 are valid for a JWT HS512 signature. Ignore four HMAC JWKs.
-        final List<JWK> jwksStrength = jwksAlg.stream().filter(j -> JwkValidateUtil.isMatch(j, alg.getName())).toList();
-        logger.debug("JWKs [{}] after Algorithm [{}] match filter.", jwksStrength.size(), alg);
-
-        // No JWKs passed the kid, alg, and strength checks, so nothing left to use in verifying the JWT signature
-        if (jwksStrength.isEmpty()) {
-            throw new ElasticsearchException("Verify failed because all " + jwks.size() + " provided JWKs were filtered.");
+            throw new ElasticsearchException("Signature verification was not attempted since there are not any JWKs available.");
         }
 
-        for (final JWK jwk : jwksStrength) {
-            if (jwt.verify(createJwsVerifier(jwk))) {
-                logger.trace(
-                    "JWT signature validation succeeded with JWK kty=[{}], jwtAlg=[{}], jwtKid=[{}], use=[{}], ops=[{}]",
-                    jwk.getKeyType(),
-                    jwk.getAlgorithm(),
-                    jwk.getKeyID(),
-                    jwk.getKeyUse(),
-                    jwk.getKeyOperations()
-                );
-                return;
-            } else {
-                logger.trace(
-                    "JWT signature validation failed with JWK kty=[{}], jwtAlg=[{}], jwtKid=[{}], use=[{}], ops={}",
-                    jwk.getKeyType(),
-                    jwk.getAlgorithm(),
-                    jwk.getKeyID(),
-                    jwk.getKeyUse(),
-                    jwk.getKeyOperations() == null ? "[null]" : jwk.getKeyOperations()
+        try (JwtUtil.TraceBuffer tracer = new JwtUtil.TraceBuffer(logger)) {
+            final String id = jwt.getHeader().getKeyID();
+            final JWSAlgorithm alg = jwt.getHeader().getAlgorithm();
+
+            tracer.append("Filtering [{}] possible JWKs to verifying signature for JWT [{}].", jwks.size(), getSafePrintableJWT(jwt));
+
+            // If JWT has optional kid header, and realm JWKs have optional kid attribute, any mismatches JWT.kid vs JWK.kid can be ignored.
+            // Keep any JWKs if JWK optional kid attribute is missing. Keep all JWKs if JWT optional kid header is missing.
+            final List<JWK> jwksKid = jwks.stream()
+                .filter(j -> ((id == null) || (j.getKeyID() == null) || (id.equals(j.getKeyID()))))
+                .toList();
+            tracer.append("[{}] JWKs remain after filtering for KID [{}].", jwksKid.size(), id);
+
+            // JWT has mandatory alg header. If realm JWKs have optional alg attribute, any mismatches JWT.alg vs JWK.alg can be ignored.
+            // Keep any JWKs if JWK optional alg attribute is missing.
+            final List<JWK> jwksAlg = jwksKid.stream().filter(j -> (j.getAlgorithm() == null) || (alg.equals(j.getAlgorithm()))).toList();
+            tracer.append("[{}] algorithms remain after filtering for algorithm name [{}].", jwksAlg.size(), alg.getName());
+
+            // PKC Example: Realm has five PKC JWKs RSA-2048, RSA-3072, EC-P256, EC-P384, and EC-P512. JWT alg allows ignoring some.
+            // - If JWT alg is RS256, only RSA-2048 and RSA-3072 are valid for a JWT RS256 signature. Ignore three EC JWKs.
+            // - If JWT alg is ES512, only EC-P512 is valid for a JWT ES512 signature. Ignore four JWKs (two RSA, two EC).
+            // - If JWT alg is ES384, only EC-P384 is valid for a JWT ES384 signature. Ignore four JWKs (two RSA, two EC).
+            // - If JWT alg is ES256, only EC-P256 is valid for a JWT ES256 signature. Ignore four JWKs (two RSA, two EC).
+            //
+            // HMAC Example: Realm has six HMAC JWKs of bit lengths 256, 320, 384, 400, 512, and 1000. JWT alg allows ignoring some.
+            // - If JWT alg is HS256, all are valid for a JWT HS256 signature. Don't ignore any HMAC JWKs.
+            // - If JWT alg is HS384, only 384, 400, 512, and 1000 are valid for a JWT HS384 signature. Ignore two HMAC JWKs.
+            // - If JWT alg is HS512, only 512 and 1000 are valid for a JWT HS512 signature. Ignore four HMAC JWKs.
+            final List<JWK> jwksConfigured = jwksAlg.stream().filter(j -> JwkValidateUtil.isMatch(j, alg.getName(), tracer)).toList();
+            tracer.append("[{}] JWKs remain after filtering for configured algorithms.", jwksConfigured.size());
+            tracer.flush();
+
+            // No JWKs passed the kid, alg, and strength checks, so nothing left to use in verifying the JWT signature
+            if (jwksConfigured.isEmpty()) {
+                throw new ElasticsearchException(
+                    "Signature verification was not attempted since there are not any JWKs "
+                        + "available after filtering for incompatible keys."
                 );
             }
-        }
 
-        throw new ElasticsearchException("Verify failed using " + jwksStrength.size() + " of " + jwks.size() + " provided JWKs.");
+            int attempt = 0;
+            int maxAttempts = jwksConfigured.size();
+            tracer.append("Attempting to verify signature for JWT [{}] against [{}] possible JWKs.", getSafePrintableJWT(jwt), maxAttempts);
+            for (final JWK jwk : jwksConfigured) {
+                attempt++;
+                if (jwt.verify(createJwsVerifier(jwk))) {
+                    tracer.append(
+                        "Attempt [{}/{}] -> JWT signature verification succeeded with jwk/kid=[{}], jwk/alg=[{}], jwk/kty=[{}], "
+                            + "jwk/use=[{}], jwk/key_ops=[{}]",
+                        attempt,
+                        maxAttempts,
+                        jwk.getKeyID(),
+                        jwk.getAlgorithm(),
+                        jwk.getKeyType(),
+                        jwk.getKeyUse(),
+                        jwk.getKeyOperations()
+                    );
+                    return;
+                } else {
+                    tracer.append(
+                        "Attempt [{}/{}] -> JWT signature verification failed with jwk/kid=[{}], jwk/alg=[{}], jwk/kty=[{}], jwk/use=[{}], "
+                            + "jwk/key_ops=[{}]",
+                        attempt,
+                        maxAttempts,
+                        jwk.getKeyID(),
+                        jwk.getAlgorithm(),
+                        jwk.getKeyType(),
+                        jwk.getKeyUse(),
+                        jwk.getKeyOperations()
+                    );
+                }
+            }
+            throw new ElasticsearchException("JWT [" + getSafePrintableJWT(jwt).get() + "] signature verification failed.");
+        }
     }
 
     default JWSVerifier createJwsVerifier(final JWK jwk) throws JOSEException {
@@ -428,4 +457,16 @@ public interface JwtSignatureValidator extends Releasable {
     interface PkcJwkSetReloadNotifier {
         void reloaded();
     }
+
+    /**
+     * @param jwt The signed JWT
+     * @return A print safe supplier to describe a JWT that redacts the signature. While the signature is not generally sensitive,
+     * we don't want to leak the entire JWT to the log to avoid a possible replay.
+     */
+    private Supplier<String> getSafePrintableJWT(SignedJWT jwt) {
+        Base64URL[] parts = jwt.getParsedParts();
+        assert parts.length == 3;
+        return () -> parts[0].toString() + "." + parts[1].toString() + ".<redacted>";
+    }
+
 }

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

@@ -33,6 +33,7 @@ import org.elasticsearch.ElasticsearchSecurityException;
 import org.elasticsearch.SpecialPermission;
 import org.elasticsearch.action.ActionListener;
 import org.elasticsearch.common.Strings;
+import org.elasticsearch.common.SuppressLoggerChecks;
 import org.elasticsearch.common.hash.MessageDigests;
 import org.elasticsearch.common.settings.SecureString;
 import org.elasticsearch.common.settings.SettingsException;
@@ -54,6 +55,10 @@ import java.security.MessageDigest;
 import java.security.PrivilegedAction;
 import java.security.PrivilegedActionException;
 import java.security.PrivilegedExceptionAction;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.List;
+import java.util.function.Supplier;
 
 import javax.net.ssl.HostnameVerifier;
 import javax.net.ssl.SSLContext;
@@ -137,7 +142,8 @@ public class JwtUtil {
     public static void validateClientAuthentication(
         final JwtRealmSettings.ClientAuthenticationType type,
         final SecureString expectedSecret,
-        final SecureString actualSecret
+        final SecureString actualSecret,
+        final String tokenPrincipal
     ) throws Exception {
         switch (type) {
             case SHARED_SECRET:
@@ -146,14 +152,18 @@ public class JwtUtil {
                 } else if (expectedSecret.equals(actualSecret) == false) {
                     throw new Exception("Rejected client. Authentication type is [" + type + "] and secret did not match.");
                 }
-                LOGGER.trace("Accepted client. Authentication type is [{}] and secret matched.", type);
+                LOGGER.trace("Accepted client for token [{}]. Authentication type is [{}] and secret matched.", tokenPrincipal, type);
                 break;
             case NONE:
             default:
                 if (Strings.hasText(actualSecret)) {
-                    LOGGER.debug("Accepted client. Authentication type [{}]. Secret is present but ignored.", type);
+                    LOGGER.trace(
+                        "Accepted client for token [{}]. Authentication type [{}]. Secret is present but ignored.",
+                        tokenPrincipal,
+                        type
+                    );
                 } else {
-                    LOGGER.trace("Accepted client. Authentication type [{}].", type);
+                    LOGGER.trace("Accepted client for token [{}]. Authentication type [{}].", tokenPrincipal, type);
                 }
                 break;
         }
@@ -338,4 +348,44 @@ public class JwtUtil {
         messageDigest.update(charSequence.toString().getBytes(StandardCharsets.UTF_8));
         return messageDigest.digest();
     }
+
+    /**
+     * Helper class to consolidate multiple trace level statements to a single trace statement with lazy evaluation.
+     * If trace level is not enabled, then no work is performed. This class is not threadsafe and is not intended for a long lifecycle.
+     */
+    public static class TraceBuffer implements AutoCloseable {
+        private final Logger logger;
+        private final List<Object> params = new ArrayList<>();
+        private final StringBuilder builder = new StringBuilder();
+        boolean closed = false;
+
+        public TraceBuffer(Logger logger) {
+            this.logger = logger;
+        }
+
+        public void append(String s, Object... args) {
+            assert closed == false;
+            if (logger.isTraceEnabled()) {
+                builder.append(s).append(" ");
+                List<Object> resolved = Arrays.stream(args).map(x -> (x instanceof Supplier) ? ((Supplier<?>) x).get() : x).toList();
+                params.addAll(resolved);
+            }
+        }
+
+        @SuppressLoggerChecks(reason = "builds the tracer dynamically")
+        public void flush() {
+            assert closed == false;
+            if (logger.isTraceEnabled() && builder.isEmpty() == false) {
+                logger.trace(builder.toString(), params.toArray());
+                params.clear();
+                builder.setLength(0); // does not guarantee contents available for GC, don't overly reuse a single instance of this class
+            }
+        }
+
+        @Override
+        public void close() {
+            flush();
+            closed = true;
+        }
+    }
 }