Skip to content

Commit 241e688

Browse files
author
Steve Riesenberg
committed
Add logging for authentication providers
Issue spring-projectsgh-159
1 parent 6dc3944 commit 241e688

12 files changed

+173
-0
lines changed

‎oauth2-authorization-server/src/main/java/org/springframework/security/oauth2/server/authorization/authentication/ClientSecretAuthenticationProvider.java

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,9 @@
1717

1818
import java.time.Instant;
1919

20+
import org.apache.commons.logging.Log;
21+
import org.apache.commons.logging.LogFactory;
22+
2023
import org.springframework.security.authentication.AuthenticationProvider;
2124
import org.springframework.security.core.Authentication;
2225
import org.springframework.security.core.AuthenticationException;
@@ -47,6 +50,7 @@
4750
*/
4851
public final class ClientSecretAuthenticationProvider implements AuthenticationProvider {
4952
private static final String ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc6749#section-3.2.1";
53+
private static final Log logger = LogFactory.getLog(ClientSecretAuthenticationProvider.class);
5054
private final RegisteredClientRepository registeredClientRepository;
5155
private final CodeVerifierAuthenticator codeVerifierAuthenticator;
5256
private PasswordEncoder passwordEncoder;
@@ -86,6 +90,7 @@ public Authentication authenticate(Authentication authentication) throws Authent
8690

8791
if (!ClientAuthenticationMethod.CLIENT_SECRET_BASIC.equals(clientAuthentication.getClientAuthenticationMethod()) &&
8892
!ClientAuthenticationMethod.CLIENT_SECRET_POST.equals(clientAuthentication.getClientAuthenticationMethod())) {
93+
logger.trace("Did not match client authentication method");
8994
return null;
9095
}
9196

@@ -95,6 +100,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
95100
throwInvalidClient(OAuth2ParameterNames.CLIENT_ID);
96101
}
97102

103+
logger.trace("Retrieved registered client");
104+
98105
if (!registeredClient.getClientAuthenticationMethods().contains(
99106
clientAuthentication.getClientAuthenticationMethod())) {
100107
throwInvalidClient("authentication_method");
@@ -114,9 +121,13 @@ public Authentication authenticate(Authentication authentication) throws Authent
114121
throwInvalidClient("client_secret_expires_at");
115122
}
116123

124+
logger.trace("Validated client authentication parameters");
125+
117126
// Validate the "code_verifier" parameter for the confidential client, if available
118127
this.codeVerifierAuthenticator.authenticateIfAvailable(clientAuthentication, registeredClient);
119128

129+
logger.debug("Authenticated client secret");
130+
120131
return new OAuth2ClientAuthenticationToken(registeredClient,
121132
clientAuthentication.getClientAuthenticationMethod(), clientAuthentication.getCredentials());
122133
}

‎oauth2-authorization-server/src/main/java/org/springframework/security/oauth2/server/authorization/authentication/CodeVerifierAuthenticator.java

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,9 @@
2121
import java.util.Base64;
2222
import java.util.Map;
2323

24+
import org.apache.commons.logging.Log;
25+
import org.apache.commons.logging.LogFactory;
26+
2427
import org.springframework.security.oauth2.core.AuthorizationGrantType;
2528
import org.springframework.security.oauth2.core.OAuth2AuthenticationException;
2629
import org.springframework.security.oauth2.core.OAuth2Error;
@@ -47,6 +50,7 @@
4750
*/
4851
final class CodeVerifierAuthenticator {
4952
private static final OAuth2TokenType AUTHORIZATION_CODE_TOKEN_TYPE = new OAuth2TokenType(OAuth2ParameterNames.CODE);
53+
private static final Log logger = LogFactory.getLog(CodeVerifierAuthenticator.class);
5054
private final OAuth2AuthorizationService authorizationService;
5155

5256
CodeVerifierAuthenticator(OAuth2AuthorizationService authorizationService) {
@@ -81,6 +85,8 @@ private boolean authenticate(OAuth2ClientAuthenticationToken clientAuthenticatio
8185
throwInvalidGrant(OAuth2ParameterNames.CODE);
8286
}
8387

88+
logger.trace("Retrieved authorization with authorization code");
89+
8490
OAuth2AuthorizationRequest authorizationRequest = authorization.getAttribute(
8591
OAuth2AuthorizationRequest.class.getName());
8692

@@ -90,17 +96,22 @@ private boolean authenticate(OAuth2ClientAuthenticationToken clientAuthenticatio
9096
if (registeredClient.getClientSettings().isRequireProofKey()) {
9197
throwInvalidGrant(PkceParameterNames.CODE_CHALLENGE);
9298
} else {
99+
logger.debug("Did not authenticate code verifier since requireProofKey=false");
93100
return false;
94101
}
95102
}
96103

104+
logger.trace("Validated code verifier parameters");
105+
97106
String codeChallengeMethod = (String) authorizationRequest.getAdditionalParameters()
98107
.get(PkceParameterNames.CODE_CHALLENGE_METHOD);
99108
String codeVerifier = (String) parameters.get(PkceParameterNames.CODE_VERIFIER);
100109
if (!codeVerifierValid(codeVerifier, codeChallenge, codeChallengeMethod)) {
101110
throwInvalidGrant(PkceParameterNames.CODE_VERIFIER);
102111
}
103112

113+
logger.debug("Authenticated code verifier");
114+
104115
return true;
105116
}
106117

‎oauth2-authorization-server/src/main/java/org/springframework/security/oauth2/server/authorization/authentication/JwtClientAssertionAuthenticationProvider.java

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,9 @@
1515
*/
1616
package org.springframework.security.oauth2.server.authorization.authentication;
1717

18+
import org.apache.commons.logging.Log;
19+
import org.apache.commons.logging.LogFactory;
20+
1821
import org.springframework.security.authentication.AuthenticationProvider;
1922
import org.springframework.security.core.Authentication;
2023
import org.springframework.security.core.AuthenticationException;
@@ -48,6 +51,7 @@
4851
*/
4952
public final class JwtClientAssertionAuthenticationProvider implements AuthenticationProvider {
5053
private static final String ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc6749#section-3.2.1";
54+
private static final Log logger = LogFactory.getLog(JwtClientAssertionAuthenticationProvider.class);
5155
private static final ClientAuthenticationMethod JWT_CLIENT_ASSERTION_AUTHENTICATION_METHOD =
5256
new ClientAuthenticationMethod("urn:ietf:params:oauth:client-assertion-type:jwt-bearer");
5357
private final RegisteredClientRepository registeredClientRepository;
@@ -75,6 +79,7 @@ public Authentication authenticate(Authentication authentication) throws Authent
7579
(OAuth2ClientAuthenticationToken) authentication;
7680

7781
if (!JWT_CLIENT_ASSERTION_AUTHENTICATION_METHOD.equals(clientAuthentication.getClientAuthenticationMethod())) {
82+
logger.trace("Did not match client authentication method");
7883
return null;
7984
}
8085

@@ -84,6 +89,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
8489
throwInvalidClient(OAuth2ParameterNames.CLIENT_ID);
8590
}
8691

92+
logger.trace("Retrieved registered client");
93+
8794
if (!registeredClient.getClientAuthenticationMethods().contains(ClientAuthenticationMethod.PRIVATE_KEY_JWT) &&
8895
!registeredClient.getClientAuthenticationMethods().contains(ClientAuthenticationMethod.CLIENT_SECRET_JWT)) {
8996
throwInvalidClient("authentication_method");
@@ -101,6 +108,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
101108
throwInvalidClient(OAuth2ParameterNames.CLIENT_ASSERTION, ex);
102109
}
103110

111+
logger.trace("Validated client authentication parameters");
112+
104113
// Validate the "code_verifier" parameter for the confidential client, if available
105114
this.codeVerifierAuthenticator.authenticateIfAvailable(clientAuthentication, registeredClient);
106115

@@ -109,6 +118,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
109118
ClientAuthenticationMethod.PRIVATE_KEY_JWT :
110119
ClientAuthenticationMethod.CLIENT_SECRET_JWT;
111120

121+
logger.debug("Authenticated client assertion");
122+
112123
return new OAuth2ClientAuthenticationToken(registeredClient, clientAuthenticationMethod, jwtAssertion);
113124
}
114125

‎oauth2-authorization-server/src/main/java/org/springframework/security/oauth2/server/authorization/authentication/OAuth2AuthorizationCodeAuthenticationProvider.java

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,10 @@
2020
import java.util.HashMap;
2121
import java.util.Map;
2222

23+
import org.apache.commons.logging.Log;
24+
import org.apache.commons.logging.LogFactory;
25+
26+
import org.springframework.core.log.LogMessage;
2327
import org.springframework.security.authentication.AuthenticationProvider;
2428
import org.springframework.security.core.Authentication;
2529
import org.springframework.security.core.AuthenticationException;
@@ -68,6 +72,7 @@
6872
*/
6973
public final class OAuth2AuthorizationCodeAuthenticationProvider implements AuthenticationProvider {
7074
private static final String ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc6749#section-5.2";
75+
private static final Log logger = LogFactory.getLog(OAuth2AuthorizationCodeAuthenticationProvider.class);
7176
private static final OAuth2TokenType AUTHORIZATION_CODE_TOKEN_TYPE =
7277
new OAuth2TokenType(OAuth2ParameterNames.CODE);
7378
private static final OAuth2TokenType ID_TOKEN_TOKEN_TYPE =
@@ -99,11 +104,16 @@ public Authentication authenticate(Authentication authentication) throws Authent
99104
getAuthenticatedClientElseThrowInvalidClient(authorizationCodeAuthentication);
100105
RegisteredClient registeredClient = clientPrincipal.getRegisteredClient();
101106

107+
logger.trace("Retrieved registered client");
108+
102109
OAuth2Authorization authorization = this.authorizationService.findByToken(
103110
authorizationCodeAuthentication.getCode(), AUTHORIZATION_CODE_TOKEN_TYPE);
104111
if (authorization == null) {
105112
throw new OAuth2AuthenticationException(OAuth2ErrorCodes.INVALID_GRANT);
106113
}
114+
115+
logger.trace("Retrieved authorization with authorization code");
116+
107117
OAuth2Authorization.Token<OAuth2AuthorizationCode> authorizationCode =
108118
authorization.getToken(OAuth2AuthorizationCode.class);
109119

@@ -115,6 +125,7 @@ public Authentication authenticate(Authentication authentication) throws Authent
115125
// Invalidate the authorization code given that a different client is attempting to use it
116126
authorization = OAuth2AuthenticationProviderUtils.invalidate(authorization, authorizationCode.getToken());
117127
this.authorizationService.save(authorization);
128+
logger.warn(LogMessage.format("Invalidated authorization code used by %s", registeredClient.getClientId()));
118129
}
119130
throw new OAuth2AuthenticationException(OAuth2ErrorCodes.INVALID_GRANT);
120131
}
@@ -128,6 +139,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
128139
throw new OAuth2AuthenticationException(OAuth2ErrorCodes.INVALID_GRANT);
129140
}
130141

142+
logger.trace("Validated token request parameters");
143+
131144
// @formatter:off
132145
DefaultOAuth2TokenContext.Builder tokenContextBuilder = DefaultOAuth2TokenContext.builder()
133146
.registeredClient(registeredClient)
@@ -149,6 +162,9 @@ public Authentication authenticate(Authentication authentication) throws Authent
149162
"The token generator failed to generate the access token.", ERROR_URI);
150163
throw new OAuth2AuthenticationException(error);
151164
}
165+
166+
logger.trace("Generated access token");
167+
152168
OAuth2AccessToken accessToken = new OAuth2AccessToken(OAuth2AccessToken.TokenType.BEARER,
153169
generatedAccessToken.getTokenValue(), generatedAccessToken.getIssuedAt(),
154170
generatedAccessToken.getExpiresAt(), tokenContext.getAuthorizedScopes());
@@ -172,6 +188,9 @@ public Authentication authenticate(Authentication authentication) throws Authent
172188
"The token generator failed to generate the refresh token.", ERROR_URI);
173189
throw new OAuth2AuthenticationException(error);
174190
}
191+
192+
logger.trace("Generated refresh token");
193+
175194
refreshToken = (OAuth2RefreshToken) generatedRefreshToken;
176195
authorizationBuilder.refreshToken(refreshToken);
177196
}
@@ -191,6 +210,9 @@ public Authentication authenticate(Authentication authentication) throws Authent
191210
"The token generator failed to generate the ID token.", ERROR_URI);
192211
throw new OAuth2AuthenticationException(error);
193212
}
213+
214+
logger.trace("Generated id token");
215+
194216
idToken = new OidcIdToken(generatedIdToken.getTokenValue(), generatedIdToken.getIssuedAt(),
195217
generatedIdToken.getExpiresAt(), ((Jwt) generatedIdToken).getClaims());
196218
authorizationBuilder.token(idToken, (metadata) ->
@@ -206,12 +228,16 @@ public Authentication authenticate(Authentication authentication) throws Authent
206228

207229
this.authorizationService.save(authorization);
208230

231+
logger.trace("Saved authorization");
232+
209233
Map<String, Object> additionalParameters = Collections.emptyMap();
210234
if (idToken != null) {
211235
additionalParameters = new HashMap<>();
212236
additionalParameters.put(OidcParameterNames.ID_TOKEN, idToken.getTokenValue());
213237
}
214238

239+
logger.debug("Authenticated token request");
240+
215241
return new OAuth2AccessTokenAuthenticationToken(
216242
registeredClient, clientPrincipal, accessToken, refreshToken, additionalParameters);
217243
}

‎oauth2-authorization-server/src/main/java/org/springframework/security/oauth2/server/authorization/authentication/OAuth2AuthorizationCodeRequestAuthenticationProvider.java

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,9 @@
2020
import java.util.Set;
2121
import java.util.function.Consumer;
2222

23+
import org.apache.commons.logging.Log;
24+
import org.apache.commons.logging.LogFactory;
25+
2326
import org.springframework.security.authentication.AnonymousAuthenticationToken;
2427
import org.springframework.security.authentication.AuthenticationProvider;
2528
import org.springframework.security.core.Authentication;
@@ -67,6 +70,7 @@
6770
public final class OAuth2AuthorizationCodeRequestAuthenticationProvider implements AuthenticationProvider {
6871
private static final String ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc6749#section-4.1.2.1";
6972
private static final String PKCE_ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc7636#section-4.4.1";
73+
private static final Log logger = LogFactory.getLog(OAuth2AuthorizationCodeRequestAuthenticationProvider.class);
7074
private static final StringKeyGenerator DEFAULT_STATE_GENERATOR =
7175
new Base64StringKeyGenerator(Base64.getUrlEncoder());
7276
private final RegisteredClientRepository registeredClientRepository;
@@ -105,6 +109,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
105109
authorizationCodeRequestAuthentication, null);
106110
}
107111

112+
logger.trace("Retrieved registered client");
113+
108114
OAuth2AuthorizationCodeRequestAuthenticationContext authenticationContext =
109115
OAuth2AuthorizationCodeRequestAuthenticationContext.with(authorizationCodeRequestAuthentication)
110116
.registeredClient(registeredClient)
@@ -129,13 +135,16 @@ public Authentication authenticate(Authentication authentication) throws Authent
129135
authorizationCodeRequestAuthentication, registeredClient, null);
130136
}
131137

138+
logger.trace("Validated authorization code request parameters");
139+
132140
// ---------------
133141
// The request is valid - ensure the resource owner is authenticated
134142
// ---------------
135143

136144
Authentication principal = (Authentication) authorizationCodeRequestAuthentication.getPrincipal();
137145
if (!isPrincipalAuthenticated(principal)) {
138146
// Return the authorization request as-is where isAuthenticated() is false
147+
logger.debug("Did not authenticate authorization code request since principal not authenticated");
139148
return authorizationCodeRequestAuthentication;
140149
}
141150

@@ -161,6 +170,8 @@ public Authentication authenticate(Authentication authentication) throws Authent
161170
Set<String> currentAuthorizedScopes = currentAuthorizationConsent != null ?
162171
currentAuthorizationConsent.getScopes() : null;
163172

173+
logger.debug("Generated state and saved authorization");
174+
164175
return new OAuth2AuthorizationConsentAuthenticationToken(authorizationRequest.getAuthorizationUri(),
165176
registeredClient.getClientId(), principal, state, currentAuthorizedScopes, null);
166177
}
@@ -174,17 +185,22 @@ public Authentication authenticate(Authentication authentication) throws Authent
174185
throw new OAuth2AuthorizationCodeRequestAuthenticationException(error, null);
175186
}
176187

188+
logger.trace("Generated authorization code");
189+
177190
OAuth2Authorization authorization = authorizationBuilder(registeredClient, principal, authorizationRequest)
178191
.authorizedScopes(authorizationRequest.getScopes())
179192
.token(authorizationCode)
180193
.build();
181194
this.authorizationService.save(authorization);
182195

196+
logger.trace("Saved authorization");
197+
183198
String redirectUri = authorizationRequest.getRedirectUri();
184199
if (!StringUtils.hasText(redirectUri)) {
185200
redirectUri = registeredClient.getRedirectUris().iterator().next();
186201
}
187202

203+
logger.debug("Authenticated authorization code request");
188204
return new OAuth2AuthorizationCodeRequestAuthenticationToken(authorizationRequest.getAuthorizationUri(),
189205
registeredClient.getClientId(), principal, authorizationCode, redirectUri,
190206
authorizationRequest.getState(), authorizationRequest.getScopes());

0 commit comments

Comments
 (0)