Skip to content

Commit 2c4bd29

Browse files
Steve Riesenbergjgrandja
Steve Riesenberg
authored and
jgrandja
committed
Add logging for authentication providers
Issue gh-159
1 parent 7e03795 commit 2c4bd29

14 files changed

+349
-0
lines changed

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

+16
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 final Log logger = LogFactory.getLog(getClass());
5054
private final RegisteredClientRepository registeredClientRepository;
5155
private final CodeVerifierAuthenticator codeVerifierAuthenticator;
5256
private PasswordEncoder passwordEncoder;
@@ -95,6 +99,10 @@ public Authentication authenticate(Authentication authentication) throws Authent
9599
throwInvalidClient(OAuth2ParameterNames.CLIENT_ID);
96100
}
97101

102+
if (this.logger.isTraceEnabled()) {
103+
this.logger.trace("Retrieved registered client");
104+
}
105+
98106
if (!registeredClient.getClientAuthenticationMethods().contains(
99107
clientAuthentication.getClientAuthenticationMethod())) {
100108
throwInvalidClient("authentication_method");
@@ -114,9 +122,17 @@ public Authentication authenticate(Authentication authentication) throws Authent
114122
throwInvalidClient("client_secret_expires_at");
115123
}
116124

125+
if (this.logger.isTraceEnabled()) {
126+
this.logger.trace("Validated client authentication parameters");
127+
}
128+
117129
// Validate the "code_verifier" parameter for the confidential client, if available
118130
this.codeVerifierAuthenticator.authenticateIfAvailable(clientAuthentication, registeredClient);
119131

132+
if (this.logger.isTraceEnabled()) {
133+
this.logger.trace("Authenticated client secret");
134+
}
135+
120136
return new OAuth2ClientAuthenticationToken(registeredClient,
121137
clientAuthentication.getClientAuthenticationMethod(), clientAuthentication.getCredentials());
122138
}

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

+19
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 final Log logger = LogFactory.getLog(getClass());
5054
private final OAuth2AuthorizationService authorizationService;
5155

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

88+
if (this.logger.isTraceEnabled()) {
89+
this.logger.trace("Retrieved authorization with authorization code");
90+
}
91+
8492
OAuth2AuthorizationRequest authorizationRequest = authorization.getAttribute(
8593
OAuth2AuthorizationRequest.class.getName());
8694

@@ -90,17 +98,28 @@ private boolean authenticate(OAuth2ClientAuthenticationToken clientAuthenticatio
9098
if (registeredClient.getClientSettings().isRequireProofKey()) {
9199
throwInvalidGrant(PkceParameterNames.CODE_CHALLENGE);
92100
} else {
101+
if (this.logger.isTraceEnabled()) {
102+
this.logger.trace("Did not authenticate code verifier since requireProofKey=false");
103+
}
93104
return false;
94105
}
95106
}
96107

108+
if (this.logger.isTraceEnabled()) {
109+
this.logger.trace("Validated code verifier parameters");
110+
}
111+
97112
String codeChallengeMethod = (String) authorizationRequest.getAdditionalParameters()
98113
.get(PkceParameterNames.CODE_CHALLENGE_METHOD);
99114
String codeVerifier = (String) parameters.get(PkceParameterNames.CODE_VERIFIER);
100115
if (!codeVerifierValid(codeVerifier, codeChallenge, codeChallengeMethod)) {
101116
throwInvalidGrant(PkceParameterNames.CODE_VERIFIER);
102117
}
103118

119+
if (this.logger.isTraceEnabled()) {
120+
this.logger.trace("Authenticated code verifier");
121+
}
122+
104123
return true;
105124
}
106125

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

+16
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;
@@ -50,6 +53,7 @@ public final class JwtClientAssertionAuthenticationProvider implements Authentic
5053
private static final String ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc6749#section-3.2.1";
5154
private static final ClientAuthenticationMethod JWT_CLIENT_ASSERTION_AUTHENTICATION_METHOD =
5255
new ClientAuthenticationMethod("urn:ietf:params:oauth:client-assertion-type:jwt-bearer");
56+
private final Log logger = LogFactory.getLog(getClass());
5357
private final RegisteredClientRepository registeredClientRepository;
5458
private final CodeVerifierAuthenticator codeVerifierAuthenticator;
5559
private JwtDecoderFactory<RegisteredClient> jwtDecoderFactory;
@@ -84,6 +88,10 @@ public Authentication authenticate(Authentication authentication) throws Authent
8488
throwInvalidClient(OAuth2ParameterNames.CLIENT_ID);
8589
}
8690

91+
if (this.logger.isTraceEnabled()) {
92+
this.logger.trace("Retrieved registered client");
93+
}
94+
8795
if (!registeredClient.getClientAuthenticationMethods().contains(ClientAuthenticationMethod.PRIVATE_KEY_JWT) &&
8896
!registeredClient.getClientAuthenticationMethods().contains(ClientAuthenticationMethod.CLIENT_SECRET_JWT)) {
8997
throwInvalidClient("authentication_method");
@@ -101,6 +109,10 @@ public Authentication authenticate(Authentication authentication) throws Authent
101109
throwInvalidClient(OAuth2ParameterNames.CLIENT_ASSERTION, ex);
102110
}
103111

112+
if (this.logger.isTraceEnabled()) {
113+
this.logger.trace("Validated client authentication parameters");
114+
}
115+
104116
// Validate the "code_verifier" parameter for the confidential client, if available
105117
this.codeVerifierAuthenticator.authenticateIfAvailable(clientAuthentication, registeredClient);
106118

@@ -109,6 +121,10 @@ public Authentication authenticate(Authentication authentication) throws Authent
109121
ClientAuthenticationMethod.PRIVATE_KEY_JWT :
110122
ClientAuthenticationMethod.CLIENT_SECRET_JWT;
111123

124+
if (this.logger.isTraceEnabled()) {
125+
this.logger.trace("Authenticated client assertion");
126+
}
127+
112128
return new OAuth2ClientAuthenticationToken(registeredClient, clientAuthenticationMethod, jwtAssertion);
113129
}
114130

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

+44
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;
@@ -72,6 +76,7 @@ public final class OAuth2AuthorizationCodeAuthenticationProvider implements Auth
7276
new OAuth2TokenType(OAuth2ParameterNames.CODE);
7377
private static final OAuth2TokenType ID_TOKEN_TOKEN_TYPE =
7478
new OAuth2TokenType(OidcParameterNames.ID_TOKEN);
79+
private final Log logger = LogFactory.getLog(getClass());
7580
private final OAuth2AuthorizationService authorizationService;
7681
private final OAuth2TokenGenerator<? extends OAuth2Token> tokenGenerator;
7782

@@ -99,11 +104,20 @@ public Authentication authenticate(Authentication authentication) throws Authent
99104
getAuthenticatedClientElseThrowInvalidClient(authorizationCodeAuthentication);
100105
RegisteredClient registeredClient = clientPrincipal.getRegisteredClient();
101106

107+
if (this.logger.isTraceEnabled()) {
108+
this.logger.trace("Retrieved registered client");
109+
}
110+
102111
OAuth2Authorization authorization = this.authorizationService.findByToken(
103112
authorizationCodeAuthentication.getCode(), AUTHORIZATION_CODE_TOKEN_TYPE);
104113
if (authorization == null) {
105114
throw new OAuth2AuthenticationException(OAuth2ErrorCodes.INVALID_GRANT);
106115
}
116+
117+
if (this.logger.isTraceEnabled()) {
118+
this.logger.trace("Retrieved authorization with authorization code");
119+
}
120+
107121
OAuth2Authorization.Token<OAuth2AuthorizationCode> authorizationCode =
108122
authorization.getToken(OAuth2AuthorizationCode.class);
109123

@@ -115,6 +129,9 @@ public Authentication authenticate(Authentication authentication) throws Authent
115129
// Invalidate the authorization code given that a different client is attempting to use it
116130
authorization = OAuth2AuthenticationProviderUtils.invalidate(authorization, authorizationCode.getToken());
117131
this.authorizationService.save(authorization);
132+
if (this.logger.isWarnEnabled()) {
133+
this.logger.warn(LogMessage.format("Invalidated authorization code used by registered client '%s'", registeredClient.getId()));
134+
}
118135
}
119136
throw new OAuth2AuthenticationException(OAuth2ErrorCodes.INVALID_GRANT);
120137
}
@@ -128,6 +145,10 @@ public Authentication authenticate(Authentication authentication) throws Authent
128145
throw new OAuth2AuthenticationException(OAuth2ErrorCodes.INVALID_GRANT);
129146
}
130147

148+
if (this.logger.isTraceEnabled()) {
149+
this.logger.trace("Validated token request parameters");
150+
}
151+
131152
// @formatter:off
132153
DefaultOAuth2TokenContext.Builder tokenContextBuilder = DefaultOAuth2TokenContext.builder()
133154
.registeredClient(registeredClient)
@@ -149,6 +170,11 @@ public Authentication authenticate(Authentication authentication) throws Authent
149170
"The token generator failed to generate the access token.", ERROR_URI);
150171
throw new OAuth2AuthenticationException(error);
151172
}
173+
174+
if (this.logger.isTraceEnabled()) {
175+
this.logger.trace("Generated access token");
176+
}
177+
152178
OAuth2AccessToken accessToken = new OAuth2AccessToken(OAuth2AccessToken.TokenType.BEARER,
153179
generatedAccessToken.getTokenValue(), generatedAccessToken.getIssuedAt(),
154180
generatedAccessToken.getExpiresAt(), tokenContext.getAuthorizedScopes());
@@ -172,6 +198,11 @@ public Authentication authenticate(Authentication authentication) throws Authent
172198
"The token generator failed to generate the refresh token.", ERROR_URI);
173199
throw new OAuth2AuthenticationException(error);
174200
}
201+
202+
if (this.logger.isTraceEnabled()) {
203+
this.logger.trace("Generated refresh token");
204+
}
205+
175206
refreshToken = (OAuth2RefreshToken) generatedRefreshToken;
176207
authorizationBuilder.refreshToken(refreshToken);
177208
}
@@ -191,6 +222,11 @@ public Authentication authenticate(Authentication authentication) throws Authent
191222
"The token generator failed to generate the ID token.", ERROR_URI);
192223
throw new OAuth2AuthenticationException(error);
193224
}
225+
226+
if (this.logger.isTraceEnabled()) {
227+
this.logger.trace("Generated id token");
228+
}
229+
194230
idToken = new OidcIdToken(generatedIdToken.getTokenValue(), generatedIdToken.getIssuedAt(),
195231
generatedIdToken.getExpiresAt(), ((Jwt) generatedIdToken).getClaims());
196232
authorizationBuilder.token(idToken, (metadata) ->
@@ -206,12 +242,20 @@ public Authentication authenticate(Authentication authentication) throws Authent
206242

207243
this.authorizationService.save(authorization);
208244

245+
if (this.logger.isTraceEnabled()) {
246+
this.logger.trace("Saved authorization");
247+
}
248+
209249
Map<String, Object> additionalParameters = Collections.emptyMap();
210250
if (idToken != null) {
211251
additionalParameters = new HashMap<>();
212252
additionalParameters.put(OidcParameterNames.ID_TOKEN, idToken.getTokenValue());
213253
}
214254

255+
if (this.logger.isTraceEnabled()) {
256+
this.logger.trace("Authenticated token request");
257+
}
258+
215259
return new OAuth2AccessTokenAuthenticationToken(
216260
registeredClient, clientPrincipal, accessToken, refreshToken, additionalParameters);
217261
}

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

+36
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;
@@ -69,6 +72,7 @@ public final class OAuth2AuthorizationCodeRequestAuthenticationProvider implemen
6972
private static final String PKCE_ERROR_URI = "https://datatracker.ietf.org/doc/html/rfc7636#section-4.4.1";
7073
private static final StringKeyGenerator DEFAULT_STATE_GENERATOR =
7174
new Base64StringKeyGenerator(Base64.getUrlEncoder());
75+
private final Log logger = LogFactory.getLog(getClass());
7276
private final RegisteredClientRepository registeredClientRepository;
7377
private final OAuth2AuthorizationService authorizationService;
7478
private final OAuth2AuthorizationConsentService authorizationConsentService;
@@ -105,6 +109,10 @@ public Authentication authenticate(Authentication authentication) throws Authent
105109
authorizationCodeRequestAuthentication, null);
106110
}
107111

112+
if (this.logger.isTraceEnabled()) {
113+
this.logger.trace("Retrieved registered client");
114+
}
115+
108116
OAuth2AuthorizationCodeRequestAuthenticationContext authenticationContext =
109117
OAuth2AuthorizationCodeRequestAuthenticationContext.with(authorizationCodeRequestAuthentication)
110118
.registeredClient(registeredClient)
@@ -129,12 +137,19 @@ public Authentication authenticate(Authentication authentication) throws Authent
129137
authorizationCodeRequestAuthentication, registeredClient, null);
130138
}
131139

140+
if (this.logger.isTraceEnabled()) {
141+
this.logger.trace("Validated authorization code request parameters");
142+
}
143+
132144
// ---------------
133145
// The request is valid - ensure the resource owner is authenticated
134146
// ---------------
135147

136148
Authentication principal = (Authentication) authorizationCodeRequestAuthentication.getPrincipal();
137149
if (!isPrincipalAuthenticated(principal)) {
150+
if (this.logger.isTraceEnabled()) {
151+
this.logger.trace("Did not authenticate authorization code request since principal not authenticated");
152+
}
138153
// Return the authorization request as-is where isAuthenticated() is false
139154
return authorizationCodeRequestAuthentication;
140155
}
@@ -156,11 +171,20 @@ public Authentication authenticate(Authentication authentication) throws Authent
156171
OAuth2Authorization authorization = authorizationBuilder(registeredClient, principal, authorizationRequest)
157172
.attribute(OAuth2ParameterNames.STATE, state)
158173
.build();
174+
175+
if (this.logger.isTraceEnabled()) {
176+
logger.trace("Generated authorization consent state");
177+
}
178+
159179
this.authorizationService.save(authorization);
160180

161181
Set<String> currentAuthorizedScopes = currentAuthorizationConsent != null ?
162182
currentAuthorizationConsent.getScopes() : null;
163183

184+
if (this.logger.isTraceEnabled()) {
185+
this.logger.trace("Saved authorization");
186+
}
187+
164188
return new OAuth2AuthorizationConsentAuthenticationToken(authorizationRequest.getAuthorizationUri(),
165189
registeredClient.getClientId(), principal, state, currentAuthorizedScopes, null);
166190
}
@@ -174,17 +198,29 @@ public Authentication authenticate(Authentication authentication) throws Authent
174198
throw new OAuth2AuthorizationCodeRequestAuthenticationException(error, null);
175199
}
176200

201+
if (this.logger.isTraceEnabled()) {
202+
this.logger.trace("Generated authorization code");
203+
}
204+
177205
OAuth2Authorization authorization = authorizationBuilder(registeredClient, principal, authorizationRequest)
178206
.authorizedScopes(authorizationRequest.getScopes())
179207
.token(authorizationCode)
180208
.build();
181209
this.authorizationService.save(authorization);
182210

211+
if (this.logger.isTraceEnabled()) {
212+
this.logger.trace("Saved authorization");
213+
}
214+
183215
String redirectUri = authorizationRequest.getRedirectUri();
184216
if (!StringUtils.hasText(redirectUri)) {
185217
redirectUri = registeredClient.getRedirectUris().iterator().next();
186218
}
187219

220+
if (this.logger.isTraceEnabled()) {
221+
this.logger.trace("Authenticated authorization code request");
222+
}
223+
188224
return new OAuth2AuthorizationCodeRequestAuthenticationToken(authorizationRequest.getAuthorizationUri(),
189225
registeredClient.getClientId(), principal, authorizationCode, redirectUri,
190226
authorizationRequest.getState(), authorizationRequest.getScopes());

0 commit comments

Comments
 (0)