From 43b67d213dc0a2f5ab7b56b87669a63650efa225 Mon Sep 17 00:00:00 2001 From: ConnorYoh <40631091+ConnorYoh@users.noreply.github.com> Date: Wed, 27 May 2026 14:01:51 +0100 Subject: [PATCH] feat(oauth2): opt-in claim-dump diagnostics for OIDC login failures (#6456) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit # 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' : ` 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: ` 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 --- .../common/model/ApplicationProperties.java | 10 + .../src/main/resources/settings.yml.template | 1 + .../service/CustomOAuth2UserService.java | 175 +++++++++++++- ...stomOAuth2UserServiceDebugLoggingTest.java | 221 ++++++++++++++++++ 4 files changed, 403 insertions(+), 4 deletions(-) create mode 100644 app/proprietary/src/test/java/stirling/software/proprietary/security/service/CustomOAuth2UserServiceDebugLoggingTest.java diff --git a/app/common/src/main/java/stirling/software/common/model/ApplicationProperties.java b/app/common/src/main/java/stirling/software/common/model/ApplicationProperties.java index e298edd07..cf3a9d201 100644 --- a/app/common/src/main/java/stirling/software/common/model/ApplicationProperties.java +++ b/app/common/src/main/java/stirling/software/common/model/ApplicationProperties.java @@ -528,6 +528,16 @@ public class ApplicationProperties { private String provider; private Client client = new Client(); + /** + * When true, the OAuth2/OIDC login flow logs the full set of ID token and UserInfo + * claims at INFO level (and again at ERROR level if the username attribute cannot be + * resolved). Used to diagnose provider misconfiguration (for example ADFS not returning + * an {@code email} claim). WARNING: writes PII (sub, email, name) to application logs. + * Leave disabled in production; enable only while actively troubleshooting and disable + * again afterwards. + */ + private Boolean debugLogging = false; + public void setScopes(String scopes) { List scopesList = Arrays.stream(scopes.split(",")).map(String::trim).toList(); diff --git a/app/core/src/main/resources/settings.yml.template b/app/core/src/main/resources/settings.yml.template index b6eca4332..7f686d582 100644 --- a/app/core/src/main/resources/settings.yml.template +++ b/app/core/src/main/resources/settings.yml.template @@ -20,6 +20,7 @@ security: password: "" # initial password for the first login oauth2: enabled: false # set to 'true' to enable login (Note: enableLogin must also be 'true' for this to work) + debugLogging: false # set to 'true' to log full ID token and UserInfo claims during OAuth2/OIDC login. Use this to diagnose claim issues (e.g. "Attribute value for 'email' cannot be null" with ADFS). WARNING: writes PII (sub, email, name) to logs; disable after troubleshooting. client: keycloak: issuer: "" # URL of the Keycloak realm's OpenID Connect Discovery endpoint diff --git a/app/proprietary/src/main/java/stirling/software/proprietary/security/service/CustomOAuth2UserService.java b/app/proprietary/src/main/java/stirling/software/proprietary/security/service/CustomOAuth2UserService.java index 6592bc95c..c1057c7e3 100644 --- a/app/proprietary/src/main/java/stirling/software/proprietary/security/service/CustomOAuth2UserService.java +++ b/app/proprietary/src/main/java/stirling/software/proprietary/security/service/CustomOAuth2UserService.java @@ -1,6 +1,10 @@ package stirling.software.proprietary.security.service; +import java.util.Collections; +import java.util.Map; import java.util.Optional; +import java.util.Set; +import java.util.TreeSet; import org.springframework.security.authentication.LockedException; import org.springframework.security.oauth2.client.oidc.userinfo.OidcUserRequest; @@ -8,6 +12,8 @@ import org.springframework.security.oauth2.client.oidc.userinfo.OidcUserService; import org.springframework.security.oauth2.client.userinfo.OAuth2UserService; import org.springframework.security.oauth2.core.OAuth2AuthenticationException; import org.springframework.security.oauth2.core.OAuth2Error; +import org.springframework.security.oauth2.core.oidc.OidcIdToken; +import org.springframework.security.oauth2.core.oidc.OidcUserInfo; import org.springframework.security.oauth2.core.oidc.user.DefaultOidcUser; import org.springframework.security.oauth2.core.oidc.user.OidcUser; @@ -39,20 +45,37 @@ public class CustomOAuth2UserService implements OAuth2UserService mergedAttributes, + boolean failure) { + StringBuilder sb = new StringBuilder(); + sb.append("\n========== [OAUTH2 DEBUG] ").append(banner).append(" ==========\n"); + sb.append("Provider registrationId : ").append(registrationId).append('\n'); + sb.append("Configured useAsUsername: ") + .append(oauth2Properties.getUseAsUsername()) + .append(" (looks up claim key '") + .append(usernameAttributeKey) + .append("')\n"); + + if (idToken != null) { + Map idClaims = idToken.getClaims(); + sb.append("\n-- ID token claims (") + .append(idClaims == null ? 0 : idClaims.size()) + .append(") --\n"); + appendClaims(sb, idClaims); + sb.append("ID token issued at : ").append(idToken.getIssuedAt()).append('\n'); + sb.append("ID token expires at: ").append(idToken.getExpiresAt()).append('\n'); + } else { + sb.append("\n-- ID token: --\n"); + } + + if (userInfo != null && userInfo.getClaims() != null) { + sb.append("\n-- UserInfo endpoint claims (") + .append(userInfo.getClaims().size()) + .append(") --\n"); + appendClaims(sb, userInfo.getClaims()); + } else { + sb.append("\n-- UserInfo endpoint claims: none returned --\n"); + } + + if (mergedAttributes != null) { + sb.append("\n-- Merged attribute keys available to useAsUsername: ") + .append(new TreeSet<>(mergedAttributes.keySet())) + .append("\n"); + Object resolved = mergedAttributes.get(usernameAttributeKey); + sb.append("-- Value at '") + .append(usernameAttributeKey) + .append("' : ") + .append(resolved == null ? "" : resolved) + .append('\n'); + + if (resolved == null) { + Set hints = suggestUsernameClaims(mergedAttributes.keySet()); + if (!hints.isEmpty()) { + sb.append( + "-- Hint: the following claim(s) are present and map to a" + + " known UsernameAttribute value — try setting" + + " security.oauth2.useAsUsername to one of: ") + .append(hints) + .append('\n'); + } + } + } + + sb.append( + "\nWARNING: this block contains PII. Set security.oauth2.debugLogging=false once" + + " troubleshooting is complete.\n"); + sb.append("========== [/OAUTH2 DEBUG] =========="); + + if (failure) { + log.error(sb.toString()); + } else { + log.info(sb.toString()); + } + } + + private static void appendClaims(StringBuilder sb, Map claims) { + if (claims == null || claims.isEmpty()) { + sb.append(" (no claims)\n"); + return; + } + // Sort for stable, scannable output + new TreeSet<>(claims.keySet()) + .forEach( + key -> { + Object value = claims.get(key); + sb.append(" ").append(key).append(" = ").append(value).append('\n'); + }); + } + + /** + * Returns the intersection of the claim keys the provider actually returned and the keys that + * {@link UsernameAttribute} accepts — i.e. valid values the operator could put in {@code + * security.oauth2.useAsUsername} to make this login work. + */ + private static Set suggestUsernameClaims(Set availableClaimKeys) { + Set supported = new TreeSet<>(); + for (UsernameAttribute attr : UsernameAttribute.values()) { + if (availableClaimKeys.contains(attr.getName())) { + supported.add(attr.getName()); + } + } + return supported; + } } diff --git a/app/proprietary/src/test/java/stirling/software/proprietary/security/service/CustomOAuth2UserServiceDebugLoggingTest.java b/app/proprietary/src/test/java/stirling/software/proprietary/security/service/CustomOAuth2UserServiceDebugLoggingTest.java new file mode 100644 index 000000000..b22aa41f2 --- /dev/null +++ b/app/proprietary/src/test/java/stirling/software/proprietary/security/service/CustomOAuth2UserServiceDebugLoggingTest.java @@ -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 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 claims = baseClaims(); + claims.put("upn", "jdoe@demarest.com.br"); + 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 claims = adfsStyleClaims(); + // ADFS-style: no `email`, but `preferred_username` IS a valid UsernameAttribute value. + claims.put("preferred_username", "jdoe@demarest.com.br"); + // `upn` is NOT in UsernameAttribute, so it must NOT appear in the suggestion hint. + claims.put("upn", "jdoe@demarest.com.br"); + 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 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 = jdoe@demarest.com.br") + .contains(""); + // 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 baseClaims() { + Map 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 adfsStyleClaims() { + Map 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 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); + } +}