feat(oauth2): opt-in claim-dump diagnostics for OIDC login failures (#6456)

# Description of Changes ## What & why Customers using ADFS (or any generic OIDC provider that doesn't emit `email`) hit `Attribute value for 'email' cannot be null` during OAuth2 login with no visibility into what claims the provider actually sent. The only available remedy was guessing at `security.oauth2.useAsUsername` until something worked. This PR adds a new opt-in `security.oauth2.debugLogging` flag (default `false`). When enabled, `CustomOAuth2UserService` logs: - All ID token claims (sorted, with values) - All UserInfo endpoint claims (if any) - The merged attribute key set Spring exposes to `getAttribute()` - The value the configured `useAsUsername` actually resolved to - A **`Hint:`** line listing the claim keys present in the token that map to a valid `UsernameAttribute` enum value — i.e. exactly what the operator could put in `useAsUsername` to make login work Logged at `INFO` on the success path and `ERROR` on failure (inside the existing `catch (IllegalArgumentException)` block that throws `OAuth2AuthenticationException`). The block is wrapped with a `[OAUTH2 DEBUG] ... [/OAUTH2 DEBUG]` banner and ends with a PII warning so operators don't leave it on in production. Default off → zero observable change for anyone not actively troubleshooting. ## Files changed | File | Why | |---|---| | `app/common/.../ApplicationProperties.java` | New `debugLogging` field on the `OAUTH2` config class with javadoc warning about PII | | `app/core/src/main/resources/settings.yml.template` | Documents `oauth2.debugLogging` so it appears on next startup | | `app/proprietary/.../security/service/CustomOAuth2UserService.java` | Emits the claim dump + suggestion hint when the flag is on | | `app/proprietary/.../security/service/CustomOAuth2UserServiceDebugLoggingTest.java` (new) | Unit test: mocks the OIDC delegate, asserts off-path is silent and on-path emits the dump with the right Hint contents | ## End-to-end verification Ran the bundled `testing/compose/docker-compose-keycloak-oauth.yml` Keycloak realm, configured `security.oauth2.useAsUsername: mail` (Keycloak emits `email`, not `mail`) and `provider: demarest` (matches the original customer bug report). Triggered the OAuth flow at `http://localhost:8080/oauth2/authorization/demarest` and confirmed: - The ERROR-level dump fires with the full 19-claim ID token decoded - `-- Value at 'mail' : <NULL — this is why login fails>` correctly identifies the missing claim - `-- Hint:` correctly suggests `[email, family_name, given_name, preferred_username]` (the four keys present that map to valid `UsernameAttribute` values) - Auth still fails with the original `OAuth2AuthenticationException` — no change to control flow, just added diagnostic logging Unit test (`CustomOAuth2UserServiceDebugLoggingTest`) covers both branches. ## Reviewer notes - **No new public APIs.** The flag is config-only; no servlet endpoints exposed. - **PII is logged when the flag is on.** This is the whole point — operators need to see the claims to fix their config — but it's gated, defaults off, and the dump self-documents with a `WARNING: ... Set security.oauth2.debugLogging=false once troubleshooting is complete.` footer. - **Why log everything, not just sub/email?** Because the operator doesn't know in advance which claim they actually want. ADFS uses `upn` in some configs and `preferred_username` in others; Azure AD uses `oid`; the customer here had neither. Dumping the full set is the only way to make the diagnostic self-service. - **Out of scope for this PR (follow-ups):** - The `UsernameAttribute` enum doesn't include `upn` / `unique_name` (common ADFS claims). If the customer's token only has `upn`, the Hint will be empty even though the operator can see `upn` in the dump. Worth a separate PR to extend the enum. - The known-provider validator in `Provider.java` (rejects e.g. `useAsUsername: mail` for `provider: keycloak` at startup) bypasses our diagnostic for those provider names. ADFS customers using `provider: <name>` fall into the `default` branch so are not affected — but it's a sharp edge worth documenting. --- ## Checklist ### General - [x] I have read the [Contribution Guidelines](https://github.com/Stirling-Tools/Stirling-PDF/blob/main/CONTRIBUTING.md) - [x] I have read the [Stirling-PDF Developer Guide](https://github.com/Stirling-Tools/Stirling-PDF/blob/main/DeveloperGuide.md) (if applicable) - [ ] I have read the [How to add new languages to Stirling-PDF](https://github.com/Stirling-Tools/Stirling-PDF/blob/main/devGuide/HowToAddNewLanguage.md) (if applicable) — N/A, backend-only change - [x] I have performed a self-review of my own code - [x] My changes generate no new warnings ### Documentation - [ ] Doc-repo update (if functionality has heavily changed) — diagnostic flag is self-documenting via the `settings.yml.template` comment and the in-log warning; happy to add a doc-repo entry if reviewers want one - [ ] Translation tags — N/A ### UI Changes (if applicable) - [ ] N/A — backend-only ### Testing (if applicable) - [x] Unit test added (`CustomOAuth2UserServiceDebugLoggingTest`) covering on/off paths and Hint correctness - [x] End-to-end verified locally against bundled Keycloak compose with intentionally misconfigured `useAsUsername` - [x] Full `:proprietary:test` suite passes
2026-07-16 11:23:10 +02:00 · 2026-05-27 13:01:51 +00:00
parent d42b779644
commit 43b67d213d
4 changed files with 403 additions and 4 deletions
@@ -0,0 +1,221 @@
+package stirling.software.proprietary.security.service;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.junit.jupiter.api.Assertions.assertThrows;
+import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.Mockito.lenient;
+import static org.mockito.Mockito.when;
+
+import java.lang.reflect.Field;
+import java.time.Instant;
+import java.util.Collections;
+import java.util.HashMap;
+import java.util.LinkedHashMap;
+import java.util.List;
+import java.util.Map;
+
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
+import org.mockito.Mock;
+import org.mockito.junit.jupiter.MockitoExtension;
+import org.slf4j.LoggerFactory;
+import org.springframework.security.oauth2.client.oidc.userinfo.OidcUserRequest;
+import org.springframework.security.oauth2.client.oidc.userinfo.OidcUserService;
+import org.springframework.security.oauth2.client.registration.ClientRegistration;
+import org.springframework.security.oauth2.core.AuthorizationGrantType;
+import org.springframework.security.oauth2.core.OAuth2AuthenticationException;
+import org.springframework.security.oauth2.core.oidc.IdTokenClaimNames;
+import org.springframework.security.oauth2.core.oidc.OidcIdToken;
+import org.springframework.security.oauth2.core.oidc.user.DefaultOidcUser;
+
+import stirling.software.common.model.ApplicationProperties;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.read.ListAppender;
+
+/**
+ * Verifies the opt-in OAuth2/OIDC claim-dump diagnostic logging added to {@link
+ * CustomOAuth2UserService} for troubleshooting provider misconfiguration (e.g. ADFS not emitting an
+ * {@code email} claim).
+ */
+@ExtendWith(MockitoExtension.class)
+class CustomOAuth2UserServiceDebugLoggingTest {
+
+    @Mock private UserService userService;
+    @Mock private LoginAttemptService loginAttemptService;
+    @Mock private OidcUserRequest userRequest;
+
+    private ListAppender<ILoggingEvent> appender;
+    private Logger serviceLogger;
+
+    @BeforeEach
+    void attachLogCapture() {
+        serviceLogger = (Logger) LoggerFactory.getLogger(CustomOAuth2UserService.class);
+        appender = new ListAppender<>();
+        appender.start();
+        serviceLogger.addAppender(appender);
+        // Make sure INFO-level dumps reach the appender even if the default config is WARN+.
+        serviceLogger.setLevel(Level.DEBUG);
+    }
+
+    @AfterEach
+    void detachLogCapture() {
+        serviceLogger.detachAppender(appender);
+        appender.stop();
+    }
+
+    @Test
+    void whenDebugLoggingOff_failureProducesNoClaimDump() throws Exception {
+        ApplicationProperties.Security.OAUTH2 props = oauthProps("email", false);
+        CustomOAuth2UserService service =
+                new CustomOAuth2UserService(props, userService, loginAttemptService);
+        // Provider gave us claims, but no "email" — same shape as the ADFS bug report.
+        Map<String, Object> claims = baseClaims();
+        claims.put("upn", "[email protected]");
+        replaceDelegateWithStub(service, claims);
+        lenient()
+                .when(userRequest.getIdToken())
+                .thenReturn(new OidcIdToken("token", Instant.now(), Instant.MAX, claims));
+        lenient().when(userRequest.getClientRegistration()).thenReturn(stubRegistration());
+
+        assertThrows(OAuth2AuthenticationException.class, () -> service.loadUser(userRequest));
+
+        assertThat(appender.list)
+                .as("no debug dump should appear when debugLogging=false")
+                .noneMatch(e -> e.getFormattedMessage().contains("[OAUTH2 DEBUG]"));
+    }
+
+    @Test
+    void whenDebugLoggingOn_failureDumpsClaimsAndSuggestsAlternative() throws Exception {
+        ApplicationProperties.Security.OAUTH2 props = oauthProps("email", true);
+        CustomOAuth2UserService service =
+                new CustomOAuth2UserService(props, userService, loginAttemptService);
+        Map<String, Object> claims = adfsStyleClaims();
+        // ADFS-style: no `email`, but `preferred_username` IS a valid UsernameAttribute value.
+        claims.put("preferred_username", "[email protected]");
+        // `upn` is NOT in UsernameAttribute, so it must NOT appear in the suggestion hint.
+        claims.put("upn", "[email protected]");
+        replaceDelegateWithStub(service, claims);
+        lenient()
+                .when(userRequest.getIdToken())
+                .thenReturn(new OidcIdToken("token", Instant.now(), Instant.MAX, claims));
+        lenient().when(userRequest.getClientRegistration()).thenReturn(stubRegistration());
+
+        assertThrows(OAuth2AuthenticationException.class, () -> service.loadUser(userRequest));
+
+        List<ILoggingEvent> dumps =
+                appender.list.stream()
+                        .filter(e -> e.getFormattedMessage().contains("[OAUTH2 DEBUG]"))
+                        .toList();
+        assertThat(dumps).as("expected at least one debug-dump log line").isNotEmpty();
+
+        String combined =
+                String.join("\n", dumps.stream().map(ILoggingEvent::getFormattedMessage).toList());
+        assertThat(combined)
+                .contains("Provider registrationId : demarest")
+                .contains("Configured useAsUsername: email")
+                .contains("preferred_username")
+                .contains("upn = [email protected]")
+                .contains("<NULL — this is why login fails>");
+        // The hint must include 'preferred_username' (a valid UsernameAttribute value present
+        // in the claims) and MUST NOT include 'upn' (not in the UsernameAttribute enum).
+        String hintLine =
+                combined.lines()
+                        .filter(l -> l.contains("Hint:"))
+                        .findFirst()
+                        .orElseThrow(() -> new AssertionError("no Hint: line in dump"));
+        assertThat(hintLine).contains("preferred_username").doesNotContain("upn");
+    }
+
+    @Test
+    void invalidUseAsUsername_isWrappedAsOAuth2AuthenticationException() {
+        // Regression: an earlier draft moved UsernameAttribute.valueOf(...) outside the try/catch,
+        // so a typo'd or null useAsUsername leaked as a raw IllegalArgumentException instead of
+        // being wrapped, breaking Spring's authentication exception handling. This test pins the
+        // post-fix behaviour: valueOf() failures stay inside the guarded section.
+        ApplicationProperties.Security.OAUTH2 props = oauthProps("not_a_real_attribute", true);
+        CustomOAuth2UserService service =
+                new CustomOAuth2UserService(props, userService, loginAttemptService);
+        lenient().when(userRequest.getClientRegistration()).thenReturn(stubRegistration());
+        // No need to stub the OIDC delegate — control flow shouldn't reach it.
+
+        OAuth2AuthenticationException thrown =
+                assertThrows(
+                        OAuth2AuthenticationException.class, () -> service.loadUser(userRequest));
+        assertThat(thrown.getCause()).isInstanceOf(IllegalArgumentException.class);
+        // We deliberately do NOT emit the claim dump in this case (we have no resolved
+        // usernameAttributeKey to compare against, and the IllegalArgumentException message
+        // already explains the misconfiguration).
+        assertThat(appender.list)
+                .as("no claim dump when useAsUsername itself is invalid")
+                .noneMatch(e -> e.getFormattedMessage().contains("[OAUTH2 DEBUG]"));
+    }
+
+    // ---------- helpers ----------
+
+    private static ApplicationProperties.Security.OAUTH2 oauthProps(
+            String useAsUsername, boolean debugLogging) {
+        ApplicationProperties.Security.OAUTH2 p = new ApplicationProperties.Security.OAUTH2();
+        p.setEnabled(true);
+        p.setUseAsUsername(useAsUsername);
+        p.setDebugLogging(debugLogging);
+        return p;
+    }
+
+    private static Map<String, Object> baseClaims() {
+        Map<String, Object> claims = new LinkedHashMap<>();
+        claims.put(IdTokenClaimNames.SUB, "abc-123");
+        claims.put(IdTokenClaimNames.ISS, "https://sts.example.com/adfs");
+        claims.put(IdTokenClaimNames.AUD, Collections.singletonList("client-id"));
+        claims.put(IdTokenClaimNames.IAT, Instant.now());
+        claims.put(IdTokenClaimNames.EXP, Instant.now().plusSeconds(3600));
+        claims.put("given_name", "Jane");
+        claims.put("family_name", "Doe");
+        return claims;
+    }
+
+    /**
+     * ADFS-style claim set with {@code given_name}/{@code family_name} removed, so the suggestion
+     * hint test isolates a single expected UsernameAttribute value.
+     */
+    private static Map<String, Object> adfsStyleClaims() {
+        Map<String, Object> claims = baseClaims();
+        claims.remove("given_name");
+        claims.remove("family_name");
+        return claims;
+    }
+
+    private static ClientRegistration stubRegistration() {
+        return ClientRegistration.withRegistrationId("demarest")
+                .clientId("client-id")
+                .clientSecret("client-secret")
+                .authorizationGrantType(AuthorizationGrantType.AUTHORIZATION_CODE)
+                .redirectUri("https://app.example.com/login/oauth2/code/demarest")
+                .authorizationUri("https://sts.example.com/adfs/oauth2/authorize")
+                .tokenUri("https://sts.example.com/adfs/oauth2/token")
+                .jwkSetUri("https://sts.example.com/adfs/discovery/keys")
+                .build();
+    }
+
+    /**
+     * Swap the private {@code delegate} field on {@link CustomOAuth2UserService} for a stub that
+     * returns a {@link DefaultOidcUser} built from the supplied claims. Lets us drive the test
+     * without standing up a real OIDC provider.
+     */
+    private void replaceDelegateWithStub(
+            CustomOAuth2UserService service, Map<String, Object> claims) throws Exception {
+        OidcIdToken idToken =
+                new OidcIdToken("raw-token", Instant.now(), Instant.MAX, new HashMap<>(claims));
+        DefaultOidcUser delegateUser =
+                new DefaultOidcUser(Collections.emptyList(), idToken, IdTokenClaimNames.SUB);
+        OidcUserService delegateMock = org.mockito.Mockito.mock(OidcUserService.class);
+        when(delegateMock.loadUser(any())).thenReturn(delegateUser);
+        Field f = CustomOAuth2UserService.class.getDeclaredField("delegate");
+        f.setAccessible(true);
+        f.set(service, delegateMock);
+    }
+}