Skip to content

Commit

Permalink
Add more OIDC debug messages
Browse files Browse the repository at this point in the history
  • Loading branch information
sberyozkin committed Sep 19, 2022
1 parent ddda1bf commit bece40f
Show file tree
Hide file tree
Showing 2 changed files with 30 additions and 2 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,7 @@ public Uni<SecurityIdentity> authenticate(RoutingContext context,

// if the session is already established then try to re-authenticate
if (sessionCookie != null) {
LOG.debug("Session cookie is present, starting the reauthentication");
context.put(OidcUtils.SESSION_COOKIE_NAME, sessionCookie.getName());
Uni<TenantConfigContext> resolvedContext = resolver.resolveContext(context);
return resolvedContext.onItem()
Expand All @@ -95,6 +96,7 @@ public Uni<SecurityIdentity> apply(TenantConfigContext tenantContext) {

// if the state cookie is available then try to complete the code flow and start a new session
if (stateCookie != null) {
LOG.debug("State cookie is present, processing an expected redirect from the OIDC provider");
if (ResponseMode.FORM_POST == oidcTenantConfig.authentication.responseMode.orElse(ResponseMode.QUERY)) {
if (OidcUtils.isFormUrlEncodedRequest(context)) {
return OidcUtils.getFormUrlEncodedData(context).onItem()
Expand Down Expand Up @@ -132,7 +134,7 @@ private Uni<SecurityIdentity> processRedirectFromOidc(RoutingContext context, Oi
}

if (requestParams.contains(OidcConstants.CODE_FLOW_CODE)) {
// start a new session by starting the code flow dance
LOG.debug("Authorization code is present, completing the code flow");
Uni<TenantConfigContext> resolvedContext = resolver.resolveContext(context);
return resolvedContext.onItem()
.transformToUni(new Function<TenantConfigContext, Uni<? extends SecurityIdentity>>() {
Expand Down Expand Up @@ -204,6 +206,7 @@ private Uni<SecurityIdentity> reAuthenticate(Cookie sessionCookie,
@Override
public Uni<? extends SecurityIdentity> apply(AuthorizationCodeTokens session) {
if (isBackChannelLogoutPendingAndValid(configContext, session.getIdToken())) {
LOG.debug("Performing a requested back-channel logout");
return OidcUtils
.removeSessionCookie(context, configContext.oidcConfig, sessionCookie.getName(),
resolver.getTokenStateManager())
Expand All @@ -225,6 +228,7 @@ public Uni<SecurityIdentity> apply(Void t) {
@Override
public Uni<Void> apply(SecurityIdentity identity) {
if (isLogout(context, configContext)) {
LOG.debug("Performing an RP initiated logout");
fireEvent(SecurityEvent.Type.OIDC_LOGOUT_RP_INITIATED, identity);
return buildLogoutRedirectUriUni(context, configContext,
session.getIdToken());
Expand All @@ -236,6 +240,7 @@ public Uni<Void> apply(SecurityIdentity identity) {
@Override
public Uni<? extends SecurityIdentity> apply(Throwable t) {
if (t instanceof AuthenticationRedirectException) {
LOG.debug("Redirecting after the reauthentication");
throw (AuthenticationRedirectException) t;
}

Expand All @@ -258,6 +263,7 @@ public Uni<? extends SecurityIdentity> apply(Throwable t) {
context,
identityProviderManager, false, null);
} else {
LOG.debug("Token auto-refresh is starting");
return refreshSecurityIdentity(configContext,
session.getRefreshToken(),
context,
Expand Down Expand Up @@ -362,6 +368,7 @@ public Uni<ChallengeData> apply(TenantConfigContext tenantContext) {
}

public Uni<ChallengeData> getChallengeInternal(RoutingContext context, TenantConfigContext configContext) {
LOG.debug("Starting an authentication challenge");
return removeSessionCookie(context, configContext.oidcConfig)
.chain(new Function<Void, Uni<? extends ChallengeData>>() {

Expand Down Expand Up @@ -513,6 +520,7 @@ private Uni<SecurityIdentity> performCodeFlow(IdentityProviderManager identityPr
final String finalUserQuery = userQuery;

final String code = requestParams.get(OidcConstants.CODE_FLOW_CODE);
LOG.debug("Exchanging the authorization code for the tokens");
Uni<AuthorizationCodeTokens> codeFlowTokensUni = getCodeFlowTokensUni(context, configContext, code,
stateBean != null ? stateBean.getCodeVerifier() : null);

Expand Down Expand Up @@ -543,6 +551,7 @@ public Uni<SecurityIdentity> apply(final AuthorizationCodeTokens tokens, final T

final String idToken = decryptIdTokenIfEncryptedByProvider(configContext, tokens.getIdToken());

LOG.debug("Authorization code has been exchanged, verifying ID token");
return authenticate(identityProviderManager, context,
new IdTokenCredential(idToken, internalIdToken))
.call(new Function<SecurityIdentity, Uni<?>>() {
Expand Down Expand Up @@ -583,7 +592,8 @@ public SecurityIdentity apply(SecurityIdentity identity) {
finalUriWithoutQuery.append(finalUserQuery);
}
String finalRedirectUri = finalUriWithoutQuery.toString();
LOG.debugf("Final redirect URI: %s", finalRedirectUri);
LOG.debugf("Removing code flow redirect parameters, final redirect URI: %s",
finalRedirectUri);
throw new AuthenticationRedirectException(finalRedirectUri);
} else {
return identity;
Expand All @@ -593,8 +603,10 @@ public SecurityIdentity apply(SecurityIdentity identity) {
@Override
public Throwable apply(Throwable tInner) {
if (tInner instanceof AuthenticationRedirectException) {
LOG.debugf("Starting the final redirect");
return tInner;
}
LOG.debugf("ID token verification has failed: %s", tInner.getMessage());
return new AuthenticationCompletionException(tInner);
}
});
Expand Down Expand Up @@ -641,6 +653,7 @@ private Uni<Void> processSuccessfulAuthentication(RoutingContext context,
AuthorizationCodeTokens tokens,
String idToken,
SecurityIdentity securityIdentity) {
LOG.debug("ID token has been verified, removing the existing session cookie if any and creating a new one");
return removeSessionCookie(context, configContext.oidcConfig)
.chain(new Function<Void, Uni<? extends Void>>() {

Expand All @@ -653,6 +666,7 @@ public Uni<? extends Void> apply(Void t) {
throw new AuthenticationCompletionException();
}
long maxAge = idTokenJson.getLong("exp") - idTokenJson.getLong("iat");
LOG.debugf("ID token is valid for %d seconds", maxAge);
if (configContext.oidcConfig.token.lifespanGrace.isPresent()) {
maxAge += configContext.oidcConfig.token.lifespanGrace.getAsInt();
}
Expand Down Expand Up @@ -847,6 +861,7 @@ public Uni<SecurityIdentity> apply(final AuthorizationCodeTokens tokens, final T

final String idToken = decryptIdTokenIfEncryptedByProvider(configContext, tokens.getIdToken());

LOG.debug("Verifying the refreshed ID token");
return authenticate(identityProviderManager, context,
new IdTokenCredential(idToken))
.call(new Function<SecurityIdentity, Uni<?>>() {
Expand All @@ -869,6 +884,7 @@ public SecurityIdentity apply(SecurityIdentity identity) {
}).onFailure().transform(new Function<Throwable, Throwable>() {
@Override
public Throwable apply(Throwable tInner) {
LOG.debugf("Verifying the refreshed ID token failed %s", tInner.getMessage());
return new AuthenticationFailedException(tInner);
}
});
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
import javax.enterprise.context.ApplicationScoped;
import javax.inject.Inject;

import org.jboss.logging.Logger;
import org.jose4j.lang.UnresolvableKeyException;

import io.quarkus.oidc.AccessTokenCredential;
Expand All @@ -36,6 +37,8 @@
@ApplicationScoped
public class OidcIdentityProvider implements IdentityProvider<TokenAuthenticationRequest> {

private static final Logger LOG = Logger.getLogger(OidcIdentityProvider.class);

static final String REFRESH_TOKEN_GRANT_RESPONSE = "refresh_token_grant_response";
static final String NEW_AUTHENTICATION = "new_authentication";

Expand All @@ -61,6 +64,7 @@ public Uni<SecurityIdentity> authenticate(TokenAuthenticationRequest request,
if (!(request.getToken() instanceof AccessTokenCredential || request.getToken() instanceof IdTokenCredential)) {
return Uni.createFrom().nullItem();
}
LOG.debug("Starting creating SecurityIidentity");
RoutingContext vertxContext = HttpSecurityUtils.getRoutingContextAttribute(request);
vertxContext.put(AuthenticationRequestContext.class.getName(), context);

Expand All @@ -84,6 +88,7 @@ private Uni<SecurityIdentity> authenticate(TokenAuthenticationRequest request,
RoutingContext vertxContext,
TenantConfigContext resolvedContext) {
if (resolvedContext.oidcConfig.publicKey.isPresent()) {
LOG.debug("Performing token verification with a configured public key");
return validateTokenWithoutOidcServer(request, resolvedContext);
} else {
return validateAllTokensWithOidcServer(vertxContext, request, resolvedContext);
Expand Down Expand Up @@ -280,21 +285,27 @@ private Uni<TokenVerificationResult> verifyCodeFlowAccessTokenUni(RoutingContext
private Uni<TokenVerificationResult> verifyTokenUni(TenantConfigContext resolvedContext, String token) {
if (OidcUtils.isOpaqueToken(token)) {
if (!resolvedContext.oidcConfig.token.allowOpaqueTokenIntrospection) {
LOG.debug("Token is opaque but the opaque token introspection is not allowed");
throw new AuthenticationFailedException();
}
LOG.debug("Starting the opaque token introspection");
return introspectTokenUni(resolvedContext, token);
} else if (resolvedContext.provider.getMetadata().getJsonWebKeySetUri() == null
|| resolvedContext.oidcConfig.token.requireJwtIntrospectionOnly) {
// Verify JWT token with the remote introspection
LOG.debug("Starting the JWT token introspection");
return introspectTokenUni(resolvedContext, token);
} else {
// Verify JWT token with the local JWK keys with a possible remote introspection fallback
try {
LOG.debug("Verifying the JWT token with the local JWK keys");
return Uni.createFrom().item(resolvedContext.provider.verifyJwtToken(token));
} catch (Throwable t) {
if (t.getCause() instanceof UnresolvableKeyException) {
LOG.debug("No matching JWK key is found, refreshing and repeating the verification");
return refreshJwksAndVerifyTokenUni(resolvedContext, token);
} else {
LOG.debugf("Token verification has failed: %s", t.getMessage());
return Uni.createFrom().failure(t);
}
}
Expand Down Expand Up @@ -369,6 +380,7 @@ private Uni<UserInfo> getUserInfoUni(RoutingContext vertxContext, TokenAuthentic
}
}

LOG.debug("Requesting UserInfo");
String accessToken = vertxContext.get(OidcConstants.ACCESS_TOKEN_VALUE);
if (accessToken == null) {
accessToken = request.getToken().getToken();
Expand Down

0 comments on commit bece40f

Please sign in to comment.