From 6d4a80e747b3fddf73cc7fb1ce6c75c235aaa7d7 Mon Sep 17 00:00:00 2001 From: Kiran Challa Date: Thu, 11 Feb 2016 16:08:27 -0800 Subject: [PATCH] [Fixes #532] Replace hard-coded logging event ids with a class of consts --- .../JwtBearerHandler.cs | 6 +- .../LoggingExtensions.cs | 45 ++ .../LoggingExtensions.cs | 446 ++++++++++++++++++ .../OpenIdConnectHandler.cs | 93 ++-- .../LoggingExtensions.cs | 36 ++ .../TwitterHandler.cs | 4 +- .../AuthenticationHandler.cs | 20 +- .../LoggingExtensions.cs | 175 +++++++ .../RemoteAuthenticationHandler.cs | 12 +- .../DefaultAuthorizationService.cs | 4 +- .../LoggingExtensions.cs | 35 ++ 11 files changed, 809 insertions(+), 67 deletions(-) create mode 100644 src/Microsoft.AspNetCore.Authentication.JwtBearer/LoggingExtensions.cs create mode 100644 src/Microsoft.AspNetCore.Authentication.OpenIdConnect/LoggingExtensions.cs create mode 100644 src/Microsoft.AspNetCore.Authentication.Twitter/LoggingExtensions.cs create mode 100644 src/Microsoft.AspNetCore.Authentication/LoggingExtensions.cs create mode 100644 src/Microsoft.AspNetCore.Authorization/LoggingExtensions.cs diff --git a/src/Microsoft.AspNetCore.Authentication.JwtBearer/JwtBearerHandler.cs b/src/Microsoft.AspNetCore.Authentication.JwtBearer/JwtBearerHandler.cs index 613dfbc152..b1d2d702eb 100644 --- a/src/Microsoft.AspNetCore.Authentication.JwtBearer/JwtBearerHandler.cs +++ b/src/Microsoft.AspNetCore.Authentication.JwtBearer/JwtBearerHandler.cs @@ -119,7 +119,7 @@ namespace Microsoft.AspNetCore.Authentication.JwtBearer } catch (Exception ex) { - Logger.LogInformation(0, ex, "Failed to validate the token: " + token); + Logger.TokenValidationFailed(token, ex); // Refresh the configuration for exceptions that may be caused by key rollovers. The user can also request a refresh in the event. if (Options.RefreshOnIssuerKeyNotFound && ex.GetType().Equals(typeof(SecurityTokenSignatureKeyNotFoundException))) @@ -135,7 +135,7 @@ namespace Microsoft.AspNetCore.Authentication.JwtBearer continue; } - Logger.LogInformation("Successfully validated the token"); + Logger.TokenValidationSucceeded(); var ticket = new AuthenticationTicket(principal, new AuthenticationProperties(), Options.AuthenticationScheme); var validatedTokenContext = new ValidatedTokenContext(Context, Options) @@ -189,7 +189,7 @@ namespace Microsoft.AspNetCore.Authentication.JwtBearer } catch (Exception ex) { - Logger.LogError(0, ex, "Exception occurred while processing message"); + Logger.ErrorProcessingMessage(ex); var authenticationFailedContext = new AuthenticationFailedContext(Context, Options) { diff --git a/src/Microsoft.AspNetCore.Authentication.JwtBearer/LoggingExtensions.cs b/src/Microsoft.AspNetCore.Authentication.JwtBearer/LoggingExtensions.cs new file mode 100644 index 0000000000..643da92906 --- /dev/null +++ b/src/Microsoft.AspNetCore.Authentication.JwtBearer/LoggingExtensions.cs @@ -0,0 +1,45 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; + +namespace Microsoft.Extensions.Logging +{ + internal static class LoggingExtensions + { + private static Action _tokenValidationFailed; + private static Action _tokenValidationSucceeded; + private static Action _errorProcessingMessage; + + static LoggingExtensions() + { + _tokenValidationFailed = LoggerMessage.Define( + eventId: 1, + logLevel: LogLevel.Information, + formatString: "Failed to validate the token {Token}."); + _tokenValidationSucceeded = LoggerMessage.Define( + eventId: 2, + logLevel: LogLevel.Information, + formatString: "Successfully validated the token."); + _errorProcessingMessage = LoggerMessage.Define( + eventId: 3, + logLevel: LogLevel.Error, + formatString: "Exception occurred while processing message."); + } + + public static void TokenValidationFailed(this ILogger logger, string token, Exception ex) + { + _tokenValidationFailed(logger, token, ex); + } + + public static void TokenValidationSucceeded(this ILogger logger) + { + _tokenValidationSucceeded(logger, null, null); + } + + public static void ErrorProcessingMessage(this ILogger logger, Exception ex) + { + _errorProcessingMessage(logger, ex); + } + } +} diff --git a/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/LoggingExtensions.cs b/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/LoggingExtensions.cs new file mode 100644 index 0000000000..8d45c9918c --- /dev/null +++ b/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/LoggingExtensions.cs @@ -0,0 +1,446 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; + +namespace Microsoft.Extensions.Logging +{ + internal static class LoggingExtensions + { + private static Action _redirectToEndSessionEndpointHandledResponse; + private static Action _redirectToEndSessionEndpointSkipped; + private static Action _redirectToAuthenticationEndpointHandledResponse; + private static Action _redirectToAuthenticationEndpointSkipped; + private static Action _updatingConfiguration; + private static Action _receivedIdToken; + private static Action _redeemingCodeForTokens; + private static Action _enteringOpenIdAuthenticationHandlerHandleRemoteAuthenticateAsync; + private static Action _enteringOpenIdAuthenticationHandlerHandleUnauthorizedAsync; + private static Action _messageReceived; + private static Action _messageReceivedContextHandledResponse; + private static Action _messageReceivedContextSkipped; + private static Action _authorizationResponseReceived; + private static Action _authorizationCodeReceived; + private static Action _configurationManagerRequestRefreshCalled; + private static Action _tokenResponseReceived; + private static Action _authorizationResponseReceivedHandledResponse; + private static Action _authorizationResponseReceivedSkipped; + private static Action _authenticationFailedContextHandledResponse; + private static Action _authenticationFailedContextSkipped; + private static Action _authorizationCodeReceivedContextHandledResponse; + private static Action _authorizationCodeReceivedContextSkipped; + private static Action _authorizationCodeRedeemedContextHandledResponse; + private static Action _authorizationCodeRedeemedContextSkipped; + private static Action _authenticationValidatedHandledResponse; + private static Action _authenticationValidatedtSkipped; + private static Action _userInformationReceived; + private static Action _userInformationReceivedHandledResponse; + private static Action _userInformationReceivedSkipped; + private static Action _invalidLogoutQueryStringRedirectUrl; + private static Action _nullOrEmptyAuthorizationResponseState; + private static Action _unableToReadAuthorizationResponseState; + private static Action _authorizationResponseError; + private static Action _exceptionProcessingMessage; + private static Action _accessTokenNotAvailable; + private static Action _retrievingClaims; + private static Action _userInfoEndpointNotSet; + private static Action _unableToProtectNonceCookie; + private static Action _invalidAuthenticationRequestUrl; + private static Action _unableToReadIdToken; + private static Action _invalidSecurityTokenType; + private static Action _unableToValidateIdToken; + private static Action _postAuthenticationLocalRedirect; + + static LoggingExtensions() + { + // Final + _redirectToEndSessionEndpointHandledResponse = LoggerMessage.Define( + eventId: 1, + logLevel: LogLevel.Debug, + formatString: "RedirectToEndSessionEndpoint.HandledResponse"); + _redirectToEndSessionEndpointSkipped = LoggerMessage.Define( + eventId: 2, + logLevel: LogLevel.Debug, + formatString: "RedirectToEndSessionEndpoint.Skipped"); + _invalidLogoutQueryStringRedirectUrl = LoggerMessage.Define( + eventId: 3, + logLevel: LogLevel.Warning, + formatString: "The query string for Logout is not a well-formed URI. Redirect URI: '{RedirectUrl}'."); + _enteringOpenIdAuthenticationHandlerHandleUnauthorizedAsync = LoggerMessage.Define( + eventId: 4, + logLevel: LogLevel.Trace, + formatString: "Entering {OpenIdConnectHandlerType}'s HandleUnauthorizedAsync."); + _postAuthenticationLocalRedirect = LoggerMessage.Define( + eventId: 5, + logLevel: LogLevel.Trace, + formatString: "Using properties.RedirectUri for 'local redirect' post authentication: '{RedirectUri}'."); + _redirectToAuthenticationEndpointHandledResponse = LoggerMessage.Define( + eventId: 6, + logLevel: LogLevel.Debug, + formatString: "RedirectToAuthenticationEndpoint.HandledResponse"); + _redirectToAuthenticationEndpointSkipped = LoggerMessage.Define( + eventId: 7, + logLevel: LogLevel.Debug, + formatString: "RedirectToAuthenticationEndpoint.Skipped"); + _invalidAuthenticationRequestUrl = LoggerMessage.Define( + eventId: 8, + logLevel: LogLevel.Warning, + formatString: "The redirect URI is not well-formed. The URI is: '{AuthenticationRequestUrl}'."); + _enteringOpenIdAuthenticationHandlerHandleRemoteAuthenticateAsync = LoggerMessage.Define( + eventId: 9, + logLevel: LogLevel.Trace, + formatString: "Entering {OpenIdConnectHandlerType}'s HandleRemoteAuthenticateAsync."); + _nullOrEmptyAuthorizationResponseState = LoggerMessage.Define( + eventId: 10, + logLevel: LogLevel.Debug, + formatString: "message.State is null or empty."); + _unableToReadAuthorizationResponseState = LoggerMessage.Define( + eventId: 11, + logLevel: LogLevel.Debug, + formatString: "Unable to read the message.State."); + _authorizationResponseError = LoggerMessage.Define( + eventId: 12, + logLevel: LogLevel.Error, + formatString: "Message contains error: '{Error}', error_description: '{ErrorDescription}', error_uri: '{ErrorUri}'."); + _updatingConfiguration = LoggerMessage.Define( + eventId: 13, + logLevel: LogLevel.Debug, + formatString: "Updating configuration"); + _authorizationResponseReceived = LoggerMessage.Define( + eventId: 14, + logLevel: LogLevel.Trace, + formatString: "Authorization response received."); + _authorizationResponseReceivedHandledResponse = LoggerMessage.Define( + eventId: 15, + logLevel: LogLevel.Debug, + formatString: "AuthorizationResponseReceived.HandledResponse"); + _authorizationResponseReceivedSkipped = LoggerMessage.Define( + eventId: 16, + logLevel: LogLevel.Debug, + formatString: "AuthorizationResponseReceived.Skipped"); + _exceptionProcessingMessage = LoggerMessage.Define( + eventId: 17, + logLevel: LogLevel.Error, + formatString: "Exception occurred while processing message."); + _configurationManagerRequestRefreshCalled = LoggerMessage.Define( + eventId: 18, + logLevel: LogLevel.Debug, + formatString: "Exception of type 'SecurityTokenSignatureKeyNotFoundException' thrown, Options.ConfigurationManager.RequestRefresh() called."); + _redeemingCodeForTokens = LoggerMessage.Define( + eventId: 19, + logLevel: LogLevel.Debug, + formatString: "Redeeming code for tokens."); + _retrievingClaims = LoggerMessage.Define( + eventId: 20, + logLevel: LogLevel.Trace, + formatString: "Retrieving claims from the user info endpoint."); + _receivedIdToken = LoggerMessage.Define( + eventId: 21, + logLevel: LogLevel.Debug, + formatString: "Received 'id_token'"); + _userInfoEndpointNotSet = LoggerMessage.Define( + eventId: 22, + logLevel: LogLevel.Debug, + formatString: "UserInfoEndpoint is not set. Claims cannot be retrieved."); + _unableToProtectNonceCookie = LoggerMessage.Define( + eventId: 23, + logLevel: LogLevel.Warning, + formatString: "Failed to un-protect the nonce cookie."); + _messageReceived = LoggerMessage.Define( + eventId: 24, + logLevel: LogLevel.Trace, + formatString: "MessageReceived: '{RedirectUrl}'."); + _messageReceivedContextHandledResponse = LoggerMessage.Define( + eventId: 25, + logLevel: LogLevel.Debug, + formatString: "MessageReceivedContext.HandledResponse"); + _messageReceivedContextSkipped = LoggerMessage.Define( + eventId: 26, + logLevel: LogLevel.Debug, + formatString: "MessageReceivedContext.Skipped"); + _authorizationCodeReceived = LoggerMessage.Define( + eventId: 27, + logLevel: LogLevel.Trace, + formatString: "Authorization code received."); + _authorizationCodeReceivedContextHandledResponse = LoggerMessage.Define( + eventId: 28, + logLevel: LogLevel.Debug, + formatString: "AuthorizationCodeReceivedContext.HandledResponse"); + _authorizationCodeReceivedContextSkipped = LoggerMessage.Define( + eventId: 29, + logLevel: LogLevel.Debug, + formatString: "AuthorizationCodeReceivedContext.Skipped"); + _tokenResponseReceived = LoggerMessage.Define( + eventId: 30, + logLevel: LogLevel.Trace, + formatString: "Token response received."); + _authorizationCodeRedeemedContextHandledResponse = LoggerMessage.Define( + eventId: 31, + logLevel: LogLevel.Debug, + formatString: "AuthorizationCodeRedeemedContext.HandledResponse"); + _authorizationCodeRedeemedContextSkipped = LoggerMessage.Define( + eventId: 32, + logLevel: LogLevel.Debug, + formatString: "AuthorizationCodeRedeemedContext.Skipped"); + _authenticationValidatedHandledResponse = LoggerMessage.Define( + eventId: 33, + logLevel: LogLevel.Debug, + formatString: "AuthenticationFailedContext.HandledResponse"); + _authenticationValidatedtSkipped = LoggerMessage.Define( + eventId: 34, + logLevel: LogLevel.Debug, + formatString: "AuthenticationFailedContext.Skipped"); + _userInformationReceived = LoggerMessage.Define( + eventId: 35, + logLevel: LogLevel.Trace, + formatString: "User information received: {User}"); + _userInformationReceivedHandledResponse = LoggerMessage.Define( + eventId: 36, + logLevel: LogLevel.Debug, + formatString: "The UserInformationReceived event returned Handled."); + _userInformationReceivedSkipped = LoggerMessage.Define( + eventId: 37, + logLevel: LogLevel.Debug, + formatString: "The UserInformationReceived event returned Skipped."); + _authenticationFailedContextHandledResponse = LoggerMessage.Define( + eventId: 38, + logLevel: LogLevel.Debug, + formatString: "AuthenticationFailedContext.HandledResponse"); + _authenticationFailedContextSkipped = LoggerMessage.Define( + eventId: 39, + logLevel: LogLevel.Debug, + formatString: "AuthenticationFailedContext.Skipped"); + _invalidSecurityTokenType = LoggerMessage.Define( + eventId: 40, + logLevel: LogLevel.Error, + formatString: "The Validated Security Token must be of type JwtSecurityToken, but instead its type is: '{SecurityTokenType}'"); + _unableToValidateIdToken = LoggerMessage.Define( + eventId: 41, + logLevel: LogLevel.Error, + formatString: "Unable to validate the 'id_token', no suitable ISecurityTokenValidator was found for: '{IdToken}'."); + _accessTokenNotAvailable = LoggerMessage.Define( + eventId: 42, + logLevel: LogLevel.Debug, + formatString: "The access_token is not available. Claims cannot be retrieved."); + _unableToReadIdToken = LoggerMessage.Define( + eventId: 43, + logLevel: LogLevel.Error, + formatString: "Unable to read the 'id_token', no suitable ISecurityTokenValidator was found for: '{IdToken}'."); + } + + public static void UpdatingConfiguration(this ILogger logger) + { + _updatingConfiguration(logger, null); + } + + public static void ConfigurationManagerRequestRefreshCalled(this ILogger logger) + { + _configurationManagerRequestRefreshCalled(logger, null); + } + + public static void AuthorizationCodeReceived(this ILogger logger) + { + _authorizationCodeReceived(logger, null); + } + + public static void TokenResponseReceived(this ILogger logger) + { + _tokenResponseReceived(logger, null); + } + + public static void ReceivedIdToken(this ILogger logger) + { + _receivedIdToken(logger, null); + } + + public static void RedeemingCodeForTokens(this ILogger logger) + { + _redeemingCodeForTokens(logger, null); + } + + public static void AuthorizationResponseReceived(this ILogger logger) + { + _authorizationResponseReceived(logger, null); + } + + public static void AuthorizationResponseReceivedHandledResponse(this ILogger logger) + { + _authorizationResponseReceivedHandledResponse(logger, null); + } + + public static void AuthorizationResponseReceivedSkipped(this ILogger logger) + { + _authorizationResponseReceivedSkipped(logger, null); + } + + public static void AuthorizationCodeReceivedContextHandledResponse(this ILogger logger) + { + _authorizationCodeReceivedContextHandledResponse(logger, null); + } + + public static void AuthorizationCodeReceivedContextSkipped(this ILogger logger) + { + _authorizationCodeReceivedContextSkipped(logger, null); + } + + public static void AuthorizationCodeRedeemedContextHandledResponse(this ILogger logger) + { + _authorizationCodeRedeemedContextHandledResponse(logger, null); + } + + public static void AuthorizationCodeRedeemedContextSkipped(this ILogger logger) + { + _authorizationCodeRedeemedContextSkipped(logger, null); + } + + public static void AuthenticationValidatedHandledResponse(this ILogger logger) + { + _authenticationValidatedHandledResponse(logger, null); + } + + public static void AuthenticationValidatedSkipped(this ILogger logger) + { + _authenticationValidatedtSkipped(logger, null); + } + + public static void AuthenticationFailedContextHandledResponse(this ILogger logger) + { + _authenticationFailedContextHandledResponse(logger, null); + } + + public static void AuthenticationFailedContextSkipped(this ILogger logger) + { + _authenticationFailedContextSkipped(logger, null); + } + + public static void MessageReceived(this ILogger logger, string redirectUrl) + { + _messageReceived(logger, redirectUrl, null); + } + + public static void MessageReceivedContextHandledResponse(this ILogger logger) + { + _messageReceivedContextHandledResponse(logger, null); + } + + public static void MessageReceivedContextSkipped(this ILogger logger) + { + _messageReceivedContextSkipped(logger, null); + } + + public static void RedirectToEndSessionEndpointHandledResponse(this ILogger logger) + { + _redirectToEndSessionEndpointHandledResponse(logger, null); + } + + public static void RedirectToEndSessionEndpointSkipped(this ILogger logger) + { + _redirectToEndSessionEndpointSkipped(logger, null); + } + + public static void RedirectToAuthenticationEndpointHandledResponse(this ILogger logger) + { + _redirectToAuthenticationEndpointHandledResponse(logger, null); + } + + public static void RedirectToAuthenticationEndpointSkipped(this ILogger logger) + { + _redirectToAuthenticationEndpointSkipped(logger, null); + } + + public static void UserInformationReceivedHandledResponse(this ILogger logger) + { + _userInformationReceivedHandledResponse(logger, null); + } + + public static void UserInformationReceivedSkipped(this ILogger logger) + { + _userInformationReceivedSkipped(logger, null); + } + + public static void InvalidLogoutQueryStringRedirectUrl(this ILogger logger, string redirectUrl) + { + _invalidLogoutQueryStringRedirectUrl(logger, redirectUrl, null); + } + + public static void NullOrEmptyAuthorizationResponseState(this ILogger logger) + { + _nullOrEmptyAuthorizationResponseState(logger, null); + } + + public static void UnableToReadAuthorizationResponseState(this ILogger logger) + { + _unableToReadAuthorizationResponseState(logger, null); + } + + public static void AuthorizationResponseError(this ILogger logger, string error, string errorDescription, string errorUri) + { + _authorizationResponseError(logger, error, errorDescription, errorUri, null); + } + + public static void ExceptionProcessingMessage(this ILogger logger, Exception ex) + { + _exceptionProcessingMessage(logger, ex); + } + + public static void AccessTokenNotAvailable(this ILogger logger) + { + _accessTokenNotAvailable(logger, null); + } + + public static void RetrievingClaims(this ILogger logger) + { + _retrievingClaims(logger, null); + } + + public static void UserInfoEndpointNotSet(this ILogger logger) + { + _userInfoEndpointNotSet(logger, null); + } + + public static void UnableToProtectNonceCookie(this ILogger logger, Exception ex) + { + _unableToProtectNonceCookie(logger, ex); + } + + public static void InvalidAuthenticationRequestUrl(this ILogger logger, string redirectUri) + { + _invalidAuthenticationRequestUrl(logger, redirectUri, null); + } + + public static void UnableToReadIdToken(this ILogger logger, string idToken) + { + _unableToReadIdToken(logger, idToken, null); + } + + public static void InvalidSecurityTokenType(this ILogger logger, string tokenType) + { + _invalidSecurityTokenType(logger, tokenType, null); + } + + public static void UnableToValidateIdToken(this ILogger logger, string idToken) + { + _unableToValidateIdToken(logger, idToken, null); + } + + public static void EnteringOpenIdAuthenticationHandlerHandleRemoteAuthenticateAsync(this ILogger logger, string openIdConnectHandlerTypeName) + { + _enteringOpenIdAuthenticationHandlerHandleRemoteAuthenticateAsync(logger, openIdConnectHandlerTypeName, null); + } + + public static void EnteringOpenIdAuthenticationHandlerHandleUnauthorizedAsync(this ILogger logger, string openIdConnectHandlerTypeName) + { + _enteringOpenIdAuthenticationHandlerHandleUnauthorizedAsync(logger, openIdConnectHandlerTypeName, null); + } + + public static void UserInformationReceived(this ILogger logger, string user) + { + _userInformationReceived(logger, user, null); + } + + public static void PostAuthenticationLocalRedirect(this ILogger logger, string redirectUri) + { + _postAuthenticationLocalRedirect(logger, redirectUri, null); + } + } +} diff --git a/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/OpenIdConnectHandler.cs b/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/OpenIdConnectHandler.cs index 9c157e57bf..5c534696b8 100644 --- a/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/OpenIdConnectHandler.cs +++ b/src/Microsoft.AspNetCore.Authentication.OpenIdConnect/OpenIdConnectHandler.cs @@ -114,12 +114,12 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.RedirectToEndSessionEndpoint(redirectContext); if (redirectContext.HandledResponse) { - Logger.LogDebug(1, "RedirectToEndSessionEndpoint.HandledResponse"); + Logger.RedirectToEndSessionEndpointHandledResponse(); return; } else if (redirectContext.Skipped) { - Logger.LogDebug(2, "RedirectToEndSessionEndpoint.Skipped"); + Logger.RedirectToEndSessionEndpointSkipped(); return; } @@ -130,7 +130,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect var redirectUri = message.CreateLogoutRequestUrl(); if (!Uri.IsWellFormedUriString(redirectUri, UriKind.Absolute)) { - Logger.LogWarning(3, "The query string for Logout is not a well-formed URI. Redirect URI: '{0}'.", redirectUri); + Logger.InvalidLogoutQueryStringRedirectUrl(redirectUri); } Response.Redirect(redirectUri); @@ -177,7 +177,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect throw new ArgumentNullException(nameof(context)); } - Logger.LogTrace(4, "Entering {0}." + nameof(HandleUnauthorizedAsync), GetType()); + Logger.EnteringOpenIdAuthenticationHandlerHandleUnauthorizedAsync(GetType().FullName); // order for local RedirectUri // 1. challenge.Properties.RedirectUri @@ -191,7 +191,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect { properties.RedirectUri = CurrentUri; } - Logger.LogTrace(5, "Using properties.RedirectUri for 'local redirect' post authentication: '{0}'.", properties.RedirectUri); + Logger.PostAuthenticationLocalRedirect(properties.RedirectUri); if (_configuration == null && Options.ConfigurationManager != null) { @@ -233,12 +233,12 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.RedirectToAuthenticationEndpoint(redirectContext); if (redirectContext.HandledResponse) { - Logger.LogDebug(6, "RedirectToAuthenticationEndpoint.HandledResponse"); + Logger.RedirectToAuthenticationEndpointHandledResponse(); return true; } else if (redirectContext.Skipped) { - Logger.LogDebug(7, "RedirectToAuthenticationEndpoint.Skipped"); + Logger.RedirectToAuthenticationEndpointSkipped(); return false; } @@ -259,7 +259,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect var redirectUri = message.CreateAuthenticationRequestUrl(); if (!Uri.IsWellFormedUriString(redirectUri, UriKind.Absolute)) { - Logger.LogWarning(9, "The redirect URI is not well-formed. The URI is: '{0}'.", redirectUri); + Logger.InvalidAuthenticationRequestUrl(redirectUri); } Response.Redirect(redirectUri); @@ -303,7 +303,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect /// An if successful. protected override async Task HandleRemoteAuthenticateAsync() { - Logger.LogTrace(10, "Entering: {0}." + nameof(HandleRemoteAuthenticateAsync), GetType()); + Logger.EnteringOpenIdAuthenticationHandlerHandleRemoteAuthenticateAsync(GetType().FullName); OpenIdConnectMessage authorizationResponse = null; @@ -361,7 +361,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect if (string.IsNullOrEmpty(authorizationResponse.State)) { // This wasn't a valid OIDC message, it may not have been intended for us. - Logger.LogDebug(11, "message.State is null or empty."); + Logger.NullOrEmptyAuthorizationResponseState(); if (Options.SkipUnrecognizedRequests) { return AuthenticateResult.Skip(); @@ -373,7 +373,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect var properties = Options.StateDataFormat.Unprotect(Uri.UnescapeDataString(authorizationResponse.State)); if (properties == null) { - Logger.LogDebug(12, "Unable to read the message.State."); + Logger.UnableToReadAuthorizationResponseState(); if (Options.SkipUnrecognizedRequests) { // Not for us? @@ -385,7 +385,11 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect // if any of the error fields are set, throw error null if (!string.IsNullOrEmpty(authorizationResponse.Error)) { - Logger.LogError(13, "Message contains error: '{0}', error_description: '{1}', error_uri: '{2}'.", authorizationResponse.Error, authorizationResponse.ErrorDescription ?? "ErrorDecription null", authorizationResponse.ErrorUri ?? "ErrorUri null"); + Logger.AuthorizationResponseError( + authorizationResponse.Error, + authorizationResponse.ErrorDescription ?? "ErrorDecription null", + authorizationResponse.ErrorUri ?? "ErrorUri null"); + return AuthenticateResult.Fail(new OpenIdConnectProtocolException(string.Format(CultureInfo.InvariantCulture, Resources.MessageContainsError, authorizationResponse.Error, authorizationResponse.ErrorDescription ?? "ErrorDecription null", authorizationResponse.ErrorUri ?? "ErrorUri null"))); } @@ -400,7 +404,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect if (_configuration == null && Options.ConfigurationManager != null) { - Logger.LogDebug(14, "Updating configuration"); + Logger.UpdatingConfiguration(); _configuration = await Options.ConfigurationManager.GetConfigurationAsync(Context.RequestAborted); } @@ -422,7 +426,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect // Hybrid or Implicit flow if (!string.IsNullOrEmpty(authorizationResponse.IdToken)) { - Logger.LogDebug(23, "'id_token' received."); + Logger.ReceivedIdToken(); ticket = ValidateToken(authorizationResponse.IdToken, properties, validationParameters, out jwt); nonce = jwt?.Payload.Nonce; @@ -525,14 +529,14 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect } catch (Exception exception) { - Logger.LogError(19, "Exception occurred while processing message.", exception); + Logger.ExceptionProcessingMessage(exception); // Refresh the configuration for exceptions that may be caused by key rollovers. The user can also request a refresh in the event. if (Options.RefreshOnIssuerKeyNotFound && exception.GetType().Equals(typeof(SecurityTokenSignatureKeyNotFoundException))) { if (Options.ConfigurationManager != null) { - Logger.LogDebug(20, "exception of type 'SecurityTokenSignatureKeyNotFoundException' thrown, Options.ConfigurationManager.RequestRefresh() called."); + Logger.ConfigurationManagerRequestRefreshCalled(); Options.ConfigurationManager.RequestRefresh(); } } @@ -583,7 +587,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect /// OpenIdConnect message that has tokens inside it. protected virtual async Task RedeemAuthorizationCodeAsync(OpenIdConnectMessage tokenEndpointRequest) { - Logger.LogDebug(21, "Redeeming code for tokens."); + Logger.RedeemingCodeForTokens(); var requestMessage = new HttpRequestMessage(HttpMethod.Post, _configuration.TokenEndpoint); requestMessage.Content = new FormUrlEncodedContent(tokenEndpointRequest.Parameters); var responseMessage = await Backchannel.SendAsync(requestMessage); @@ -606,16 +610,15 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect if (string.IsNullOrEmpty(userInfoEndpoint)) { - Logger.LogDebug(24, $"{nameof(_configuration.UserInfoEndpoint)} is not set. Claims cannot be retrieved."); + Logger.UserInfoEndpointNotSet(); return AuthenticateResult.Success(ticket); } if (string.IsNullOrEmpty(message.AccessToken)) { - Logger.LogDebug(47, "The access_token is not available. Claims cannot be retrieved."); + Logger.AccessTokenNotAvailable(); return AuthenticateResult.Success(ticket); } - Logger.LogTrace(22, "Retrieving claims from the user info endpoint."); - + Logger.RetrievingClaims(); var requestMessage = new HttpRequestMessage(HttpMethod.Get, userInfoEndpoint); requestMessage.Headers.Authorization = new AuthenticationHeaderValue("Bearer", message.AccessToken); var responseMessage = await Backchannel.SendAsync(requestMessage); @@ -789,7 +792,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect } catch (Exception ex) { - Logger.LogWarning(25, "Failed to un-protect the nonce cookie.", ex); + Logger.UnableToProtectNonceCookie(ex); } } } @@ -829,7 +832,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect private async Task RunMessageReceivedEventAsync(OpenIdConnectMessage message) { - Logger.LogTrace(29, "MessageReceived: '{0}'", message.BuildRedirectUrl()); + Logger.MessageReceived(message.BuildRedirectUrl()); var messageReceivedContext = new MessageReceivedContext(Context, Options) { ProtocolMessage = message @@ -838,11 +841,11 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.MessageReceived(messageReceivedContext); if (messageReceivedContext.HandledResponse) { - Logger.LogDebug(30, "MessageReceivedContext.HandledResponse"); + Logger.MessageReceivedContextHandledResponse(); } else if (messageReceivedContext.Skipped) { - Logger.LogDebug(31, "MessageReceivedContext.Skipped"); + Logger.MessageReceivedContextSkipped(); } return messageReceivedContext; @@ -850,7 +853,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect private async Task RunAuthorizationResponseReceivedEventAsync(OpenIdConnectMessage message, AuthenticationProperties properties) { - Logger.LogTrace(15, "Authorization response received."); + Logger.AuthorizationResponseReceived(); var authorizationResponseReceivedContext = new AuthorizationResponseReceivedContext(Context, Options, properties) { ProtocolMessage = message @@ -858,18 +861,18 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.AuthorizationResponseReceived(authorizationResponseReceivedContext); if (authorizationResponseReceivedContext.HandledResponse) { - Logger.LogDebug(16, "AuthorizationResponseReceived.HandledResponse"); + Logger.AuthorizationResponseReceivedHandledResponse(); } else if (authorizationResponseReceivedContext.Skipped) { - Logger.LogDebug(17, "AuthorizationResponseReceived.Skipped"); + Logger.AuthorizationResponseReceivedSkipped(); } return authorizationResponseReceivedContext; } private async Task RunAuthorizationCodeReceivedEventAsync(OpenIdConnectMessage authorizationResponse, AuthenticationProperties properties, AuthenticationTicket ticket, JwtSecurityToken jwt) { - Logger.LogTrace(32, "AuthorizationCode received"); + Logger.AuthorizationCodeReceived(); var tokenEndpointRequest = new OpenIdConnectMessage() { @@ -893,11 +896,11 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.AuthorizationCodeReceived(authorizationCodeReceivedContext); if (authorizationCodeReceivedContext.HandledResponse) { - Logger.LogDebug(33, "AuthorizationCodeReceivedContext.HandledResponse"); + Logger.AuthorizationCodeReceivedContextHandledResponse(); } else if (authorizationCodeReceivedContext.Skipped) { - Logger.LogDebug(34, "AuthorizationCodeReceivedContext.Skipped"); + Logger.AuthorizationCodeReceivedContextSkipped(); } return authorizationCodeReceivedContext; @@ -905,7 +908,8 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect private async Task RunTokenResponseReceivedEventAsync(OpenIdConnectMessage message, OpenIdConnectMessage tokenEndpointResponse, AuthenticationProperties properties) { - Logger.LogTrace(35, "Token response received."); + Logger.TokenResponseReceived(); + var tokenResponseReceivedContext = new TokenResponseReceivedContext(Context, Options, properties) { ProtocolMessage = message, @@ -915,12 +919,13 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.TokenResponseReceived(tokenResponseReceivedContext); if (tokenResponseReceivedContext.HandledResponse) { - Logger.LogDebug(36, "AuthorizationCodeRedeemedContext.HandledResponse"); + Logger.AuthorizationCodeRedeemedContextHandledResponse(); } else if (tokenResponseReceivedContext.Skipped) { - Logger.LogDebug(37, "AuthorizationCodeRedeemedContext.Skipped"); + Logger.AuthorizationCodeRedeemedContextSkipped(); } + return tokenResponseReceivedContext; } @@ -936,11 +941,11 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.AuthenticationValidated(authenticationValidatedContext); if (authenticationValidatedContext.HandledResponse) { - Logger.LogDebug(38, "AuthenticationValidated.HandledResponse"); + Logger.AuthenticationValidatedHandledResponse(); } else if (authenticationValidatedContext.Skipped) { - Logger.LogDebug(39, "AuthenticationValidated.Skipped"); + Logger.AuthenticationValidatedSkipped(); } return authenticationValidatedContext; @@ -948,7 +953,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect private async Task RunUserInformationReceivedEventAsync(AuthenticationTicket ticket, OpenIdConnectMessage message, JObject user) { - Logger.LogTrace(40, "User information received: {0}", user.ToString()); + Logger.UserInformationReceived(user.ToString()); var userInformationReceivedContext = new UserInformationReceivedContext(Context, Options) { @@ -960,11 +965,11 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.UserInformationReceived(userInformationReceivedContext); if (userInformationReceivedContext.HandledResponse) { - Logger.LogDebug(41, "The UserInformationReceived event returned Handled."); + Logger.UserInformationReceivedHandledResponse(); } else if (userInformationReceivedContext.Skipped) { - Logger.LogDebug(42, "The UserInformationReceived event returned Skipped."); + Logger.UserInformationReceivedSkipped(); } return userInformationReceivedContext; @@ -981,11 +986,11 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect await Options.Events.AuthenticationFailed(authenticationFailedContext); if (authenticationFailedContext.HandledResponse) { - Logger.LogDebug(43, "AuthenticationFailedContext.HandledResponse"); + Logger.AuthenticationFailedContextHandledResponse(); } else if (authenticationFailedContext.Skipped) { - Logger.LogDebug(44, "AuthenticationFailedContext.Skipped"); + Logger.AuthenticationFailedContextSkipped(); } return authenticationFailedContext; @@ -995,7 +1000,7 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect { if (!Options.SecurityTokenValidator.CanReadToken(idToken)) { - Logger.LogError(48, "Unable to read the 'id_token', no suitable ISecurityTokenValidator was found for: '{0}'.", idToken); + Logger.UnableToReadIdToken(idToken); throw new SecurityTokenException(string.Format(CultureInfo.InvariantCulture, Resources.UnableToValidateToken, idToken)); } @@ -1018,13 +1023,13 @@ namespace Microsoft.AspNetCore.Authentication.OpenIdConnect jwt = validatedToken as JwtSecurityToken; if (jwt == null) { - Logger.LogError(45, "The Validated Security Token must be of type JwtSecurityToken, but instead its type is: '{0}'", validatedToken?.GetType()); + Logger.InvalidSecurityTokenType(validatedToken?.GetType().ToString()); throw new SecurityTokenException(string.Format(CultureInfo.InvariantCulture, Resources.ValidatedSecurityTokenNotJwt, validatedToken?.GetType())); } if (validatedToken == null) { - Logger.LogError(46, "Unable to validate the 'id_token', no suitable ISecurityTokenValidator was found for: '{0}'.", idToken); + Logger.UnableToValidateIdToken(idToken); throw new SecurityTokenException(string.Format(CultureInfo.InvariantCulture, Resources.UnableToValidateToken, idToken)); } diff --git a/src/Microsoft.AspNetCore.Authentication.Twitter/LoggingExtensions.cs b/src/Microsoft.AspNetCore.Authentication.Twitter/LoggingExtensions.cs new file mode 100644 index 0000000000..21a4ac541d --- /dev/null +++ b/src/Microsoft.AspNetCore.Authentication.Twitter/LoggingExtensions.cs @@ -0,0 +1,36 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; + +namespace Microsoft.Extensions.Logging +{ + internal static class LoggingExtensions + { + private static Action _obtainRequestToken; + private static Action _obtainAccessToken; + + static LoggingExtensions() + { + _obtainRequestToken = LoggerMessage.Define( + eventId: 1, + logLevel: LogLevel.Debug, + formatString: "ObtainRequestToken"); + _obtainAccessToken = LoggerMessage.Define( + eventId: 2, + logLevel: LogLevel.Debug, + formatString: "ObtainAccessToken"); + + } + + public static void ObtainAccessToken(this ILogger logger) + { + _obtainAccessToken(logger, null); + } + + public static void ObtainRequestToken(this ILogger logger) + { + _obtainRequestToken(logger, null); + } + } +} diff --git a/src/Microsoft.AspNetCore.Authentication.Twitter/TwitterHandler.cs b/src/Microsoft.AspNetCore.Authentication.Twitter/TwitterHandler.cs index d856a9b845..d7383e9393 100644 --- a/src/Microsoft.AspNetCore.Authentication.Twitter/TwitterHandler.cs +++ b/src/Microsoft.AspNetCore.Authentication.Twitter/TwitterHandler.cs @@ -155,7 +155,7 @@ namespace Microsoft.AspNetCore.Authentication.Twitter private async Task ObtainRequestTokenAsync(string consumerKey, string consumerSecret, string callBackUri, AuthenticationProperties properties) { - Logger.LogDebug("ObtainRequestToken"); + Logger.ObtainRequestToken(); var nonce = Guid.NewGuid().ToString("N"); @@ -216,7 +216,7 @@ namespace Microsoft.AspNetCore.Authentication.Twitter { // https://dev.twitter.com/docs/api/1/post/oauth/access_token - Logger.LogDebug("ObtainAccessToken"); + Logger.ObtainAccessToken(); var nonce = Guid.NewGuid().ToString("N"); diff --git a/src/Microsoft.AspNetCore.Authentication/AuthenticationHandler.cs b/src/Microsoft.AspNetCore.Authentication/AuthenticationHandler.cs index f50fd3dbbd..ebb25af212 100644 --- a/src/Microsoft.AspNetCore.Authentication/AuthenticationHandler.cs +++ b/src/Microsoft.AspNetCore.Authentication/AuthenticationHandler.cs @@ -104,13 +104,13 @@ namespace Microsoft.AspNetCore.Authentication var result = await HandleAuthenticateOnceAsync(); if (result.Failure != null) { - Logger.LogInformation(0, $"{Options.AuthenticationScheme} not authenticated: " + result.Failure.Message); + Logger.AuthenticationSchemeNotAuthenticatedWithFailure(Options.AuthenticationScheme, result.Failure.Message); } var ticket = result?.Ticket; if (ticket?.Principal != null) { Context.User = SecurityHelper.MergeUserPrincipal(Context.User, ticket.Principal); - Logger.LogInformation(0, "HttpContext.User merged via AutomaticAuthentication from authenticationScheme: {scheme}.", Options.AuthenticationScheme); + Logger.UserPrinicpalMerged(Options.AuthenticationScheme); } } } @@ -171,7 +171,7 @@ namespace Microsoft.AspNetCore.Authentication /// /// Called once by common code after initialization. If an authentication middleware responds directly to - /// specifically known paths it must override this virtual, compare the request path to it's known paths, + /// specifically known paths it must override this virtual, compare the request path to it's known paths, /// provide any response information as appropriate, and true to stop further processing. /// /// Returning false will cause the common code to call the next middleware in line. Returning true will @@ -203,7 +203,7 @@ namespace Microsoft.AspNetCore.Authentication var handled = false; if (ShouldHandleScheme(context.AuthenticationScheme, Options.AutomaticAuthenticate)) { - // Calling Authenticate more than once should always return the original value. + // Calling Authenticate more than once should always return the original value. var result = await HandleAuthenticateOnceAsync(); if (result?.Failure != null) @@ -216,13 +216,13 @@ namespace Microsoft.AspNetCore.Authentication if (ticket?.Principal != null) { context.Authenticated(ticket.Principal, ticket.Properties.Items, Options.Description.Items); - Logger.LogInformation(1, "AuthenticationScheme: {scheme} was successfully authenticated.", Options.AuthenticationScheme); + Logger.AuthenticationSchemeAuthenticated(Options.AuthenticationScheme); handled = true; } else { context.NotAuthenticated(); - Logger.LogDebug(2, "AuthenticationScheme: {scheme} was not authenticated.", Options.AuthenticationScheme); + Logger.AuthenticationSchemeNotAuthenticated(Options.AuthenticationScheme); } } } @@ -250,7 +250,7 @@ namespace Microsoft.AspNetCore.Authentication { SignInAccepted = true; await HandleSignInAsync(context); - Logger.LogInformation(3, "AuthenticationScheme: {scheme} signed in.", Options.AuthenticationScheme); + Logger.AuthenticationSchemeSignedIn(Options.AuthenticationScheme); context.Accept(); } else if (PriorHandler != null) @@ -270,7 +270,7 @@ namespace Microsoft.AspNetCore.Authentication { SignOutAccepted = true; await HandleSignOutAsync(context); - Logger.LogInformation(4, "AuthenticationScheme: {scheme} signed out.", Options.AuthenticationScheme); + Logger.AuthenticationSchemeSignedOut(Options.AuthenticationScheme); context.Accept(); } else if (PriorHandler != null) @@ -321,11 +321,11 @@ namespace Microsoft.AspNetCore.Authentication goto case ChallengeBehavior.Unauthorized; case ChallengeBehavior.Unauthorized: handled = await HandleUnauthorizedAsync(context); - Logger.LogInformation(5, "AuthenticationScheme: {scheme} was challenged.", Options.AuthenticationScheme); + Logger.AuthenticationSchemeChallenged(Options.AuthenticationScheme); break; case ChallengeBehavior.Forbidden: handled = await HandleForbiddenAsync(context); - Logger.LogInformation(6, "AuthenticationScheme: {scheme} was forbidden.", Options.AuthenticationScheme); + Logger.AuthenticationSchemeForbidden(Options.AuthenticationScheme); break; } context.Accept(); diff --git a/src/Microsoft.AspNetCore.Authentication/LoggingExtensions.cs b/src/Microsoft.AspNetCore.Authentication/LoggingExtensions.cs new file mode 100644 index 0000000000..49fc8db050 --- /dev/null +++ b/src/Microsoft.AspNetCore.Authentication/LoggingExtensions.cs @@ -0,0 +1,175 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; + +namespace Microsoft.Extensions.Logging +{ + internal static class LoggingExtensions + { + private static Action _authSchemeAuthenticated; + private static Action _authSchemeNotAuthenticated; + private static Action _authSchemeNotAuthenticatedWithFailure; + private static Action _authSchemeSignedIn; + private static Action _authSchemeSignedOut; + private static Action _authSchemeChallenged; + private static Action _authSchemeForbidden; + private static Action _userAuthorizationFailed; + private static Action _userAuthorizationSucceeded; + private static Action _userPrincipalMerged; + private static Action _remoteAuthenticationError; + private static Action _signInHandled; + private static Action _signInSkipped; + private static Action _correlationPropertyNotFound; + private static Action _correlationCookieNotFound; + private static Action _unexpectedCorrelationCookieValue; + + static LoggingExtensions() + { + _userAuthorizationSucceeded = LoggerMessage.Define( + eventId: 1, + logLevel: LogLevel.Information, + formatString: "Authorization was successful for user: {UserName}."); + _userAuthorizationFailed = LoggerMessage.Define( + eventId: 2, + logLevel: LogLevel.Information, + formatString: "Authorization failed for user: {UserName}."); + _userPrincipalMerged = LoggerMessage.Define( + eventId: 3, + logLevel: LogLevel.Information, + formatString: "HttpContext.User merged via AutomaticAuthentication from authenticationScheme: {AuthenticationScheme}."); + _remoteAuthenticationError = LoggerMessage.Define( + eventId: 4, + logLevel: LogLevel.Information, + formatString: "Error from RemoteAuthentication: {ErrorMessage}."); + _signInHandled = LoggerMessage.Define( + eventId: 5, + logLevel: LogLevel.Debug, + formatString: "The SigningIn event returned Handled."); + _signInSkipped = LoggerMessage.Define( + eventId: 6, + logLevel: LogLevel.Debug, + formatString: "The SigningIn event returned Skipped."); + _authSchemeNotAuthenticatedWithFailure = LoggerMessage.Define( + eventId: 7, + logLevel: LogLevel.Information, + formatString: "{AuthenticationScheme} was not authenticated. Failure message: {FailureMessage}"); + _authSchemeAuthenticated = LoggerMessage.Define( + eventId: 8, + logLevel: LogLevel.Information, + formatString: "AuthenticationScheme: {AuthenticationScheme} was successfully authenticated."); + _authSchemeNotAuthenticated = LoggerMessage.Define( + eventId: 9, + logLevel: LogLevel.Debug, + formatString: "AuthenticationScheme: {AuthenticationScheme} was not authenticated."); + _authSchemeSignedIn = LoggerMessage.Define( + eventId: 10, + logLevel: LogLevel.Information, + formatString: "AuthenticationScheme: {AuthenticationScheme} signed in."); + _authSchemeSignedOut = LoggerMessage.Define( + eventId: 11, + logLevel: LogLevel.Information, + formatString: "AuthenticationScheme: {AuthenticationScheme} signed out."); + _authSchemeChallenged = LoggerMessage.Define( + eventId: 12, + logLevel: LogLevel.Information, + formatString: "AuthenticationScheme: {AuthenticationScheme} was challenged."); + _authSchemeForbidden = LoggerMessage.Define( + eventId: 13, + logLevel: LogLevel.Information, + formatString: "AuthenticationScheme: {AuthenticationScheme} was forbidden."); + _correlationPropertyNotFound = LoggerMessage.Define( + eventId: 14, + logLevel: LogLevel.Warning, + formatString: "{CorrelationProperty} state property not found."); + _correlationCookieNotFound = LoggerMessage.Define( + eventId: 15, + logLevel: LogLevel.Warning, + formatString: "'{CorrelationCookieName}' cookie not found."); + _unexpectedCorrelationCookieValue = LoggerMessage.Define( + eventId: 16, + logLevel: LogLevel.Warning, + formatString: "The correlation cookie value '{CorrelationCookieName}' did not match the expected value '{CorrelationCookieValue}'."); + } + + public static void AuthenticationSchemeAuthenticated(this ILogger logger, string authenticationScheme) + { + _authSchemeAuthenticated(logger, authenticationScheme, null); + } + + public static void AuthenticationSchemeNotAuthenticated(this ILogger logger, string authenticationScheme) + { + _authSchemeNotAuthenticated(logger, authenticationScheme, null); + } + + public static void AuthenticationSchemeNotAuthenticatedWithFailure(this ILogger logger, string authenticationScheme, string failureMessage) + { + _authSchemeNotAuthenticatedWithFailure(logger, authenticationScheme, failureMessage, null); + } + + public static void AuthenticationSchemeSignedIn(this ILogger logger, string authenticationScheme) + { + _authSchemeSignedIn(logger, authenticationScheme, null); + } + + public static void AuthenticationSchemeSignedOut(this ILogger logger, string authenticationScheme) + { + _authSchemeSignedOut(logger, authenticationScheme, null); + } + + public static void AuthenticationSchemeChallenged(this ILogger logger, string authenticationScheme) + { + _authSchemeChallenged(logger, authenticationScheme, null); + } + + public static void AuthenticationSchemeForbidden(this ILogger logger, string authenticationScheme) + { + _authSchemeForbidden(logger, authenticationScheme, null); + } + + public static void UserAuthorizationSucceeded(this ILogger logger, string userName) + { + _userAuthorizationSucceeded(logger, userName, null); + } + + public static void UserAuthorizationFailed(this ILogger logger, string userName) + { + _userAuthorizationFailed(logger, userName, null); + } + + public static void UserPrinicpalMerged(this ILogger logger, string authenticationScheme) + { + _userPrincipalMerged(logger, authenticationScheme, null); + } + + public static void RemoteAuthenticationError(this ILogger logger, string errorMessage) + { + _remoteAuthenticationError(logger, errorMessage, null); + } + + public static void SigninHandled(this ILogger logger) + { + _signInHandled(logger, null); + } + + public static void SigninSkipped(this ILogger logger) + { + _signInSkipped(logger, null); + } + + public static void CorrelationPropertyNotFound(this ILogger logger, string correlationPrefix) + { + _correlationPropertyNotFound(logger, correlationPrefix, null); + } + + public static void CorrelationCookieNotFound(this ILogger logger, string cookieName) + { + _correlationCookieNotFound(logger, cookieName, null); + } + + public static void UnexpectedCorrelationCookieValue(this ILogger logger, string cookieName, string cookieValue) + { + _unexpectedCorrelationCookieValue(logger, cookieName, cookieValue, null); + } + } +} diff --git a/src/Microsoft.AspNetCore.Authentication/RemoteAuthenticationHandler.cs b/src/Microsoft.AspNetCore.Authentication/RemoteAuthenticationHandler.cs index bf64109a2c..d6cc4ce7fc 100644 --- a/src/Microsoft.AspNetCore.Authentication/RemoteAuthenticationHandler.cs +++ b/src/Microsoft.AspNetCore.Authentication/RemoteAuthenticationHandler.cs @@ -39,7 +39,7 @@ namespace Microsoft.AspNetCore.Authentication if (authResult == null || !authResult.Succeeded) { var errorContext = new FailureContext(Context, authResult?.Failure ?? new Exception("Invalid return state, unable to redirect.")); - Logger.LogInformation("Error from RemoteAuthentication: " + errorContext.Failure.Message); + Logger.RemoteAuthenticationError(errorContext.Failure.Message); await Options.Events.RemoteFailure(errorContext); if (errorContext.HandledResponse) { @@ -66,12 +66,12 @@ namespace Microsoft.AspNetCore.Authentication if (context.HandledResponse) { - Logger.LogDebug("The SigningIn event returned Handled."); + Logger.SigninHandled(); return true; } else if (context.Skipped) { - Logger.LogDebug("The SigningIn event returned Skipped."); + Logger.SigninSkipped(); return false; } @@ -144,7 +144,7 @@ namespace Microsoft.AspNetCore.Authentication string correlationId; if (!properties.Items.TryGetValue(CorrelationProperty, out correlationId)) { - Logger.LogWarning(26, "{0} state property not found.", CorrelationPrefix); + Logger.CorrelationPropertyNotFound(CorrelationPrefix); return false; } @@ -155,7 +155,7 @@ namespace Microsoft.AspNetCore.Authentication var correlationCookie = Request.Cookies[cookieName]; if (string.IsNullOrEmpty(correlationCookie)) { - Logger.LogWarning(27, "'{0}' cookie not found.", cookieName); + Logger.CorrelationCookieNotFound(cookieName); return false; } @@ -168,7 +168,7 @@ namespace Microsoft.AspNetCore.Authentication if (!string.Equals(correlationCookie, CorrelationMarker, StringComparison.Ordinal)) { - Logger.LogWarning(28, "The correlation cookie value '{0}' did not match the expected value '{1}'.", cookieName); + Logger.UnexpectedCorrelationCookieValue(cookieName, correlationCookie); return false; } diff --git a/src/Microsoft.AspNetCore.Authorization/DefaultAuthorizationService.cs b/src/Microsoft.AspNetCore.Authorization/DefaultAuthorizationService.cs index c5bdcc7a76..7d46ac8b82 100644 --- a/src/Microsoft.AspNetCore.Authorization/DefaultAuthorizationService.cs +++ b/src/Microsoft.AspNetCore.Authorization/DefaultAuthorizationService.cs @@ -51,12 +51,12 @@ namespace Microsoft.AspNetCore.Authorization if (authContext.HasSucceeded) { - _logger.LogInformation(0, "Authorization was successful for user: {userName}.", user?.Identity?.Name); + _logger.UserAuthorizationSucceeded(user?.Identity?.Name); return true; } else { - _logger.LogInformation(1, "Authorization failed for user: {userName}.", user?.Identity?.Name); + _logger.UserAuthorizationFailed(user?.Identity?.Name); return false; } } diff --git a/src/Microsoft.AspNetCore.Authorization/LoggingExtensions.cs b/src/Microsoft.AspNetCore.Authorization/LoggingExtensions.cs new file mode 100644 index 0000000000..1d524dd74e --- /dev/null +++ b/src/Microsoft.AspNetCore.Authorization/LoggingExtensions.cs @@ -0,0 +1,35 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; + +namespace Microsoft.Extensions.Logging +{ + internal static class LoggingExtensions + { + private static Action _userAuthorizationFailed; + private static Action _userAuthorizationSucceeded; + + static LoggingExtensions() + { + _userAuthorizationSucceeded = LoggerMessage.Define( + eventId: 1, + logLevel: LogLevel.Information, + formatString: "Authorization was successful for user: {UserName}."); + _userAuthorizationFailed = LoggerMessage.Define( + eventId: 2, + logLevel: LogLevel.Information, + formatString: "Authorization failed for user: {UserName}."); + } + + public static void UserAuthorizationSucceeded(this ILogger logger, string userName) + { + _userAuthorizationSucceeded(logger, userName, null); + } + + public static void UserAuthorizationFailed(this ILogger logger, string userName) + { + _userAuthorizationFailed(logger, userName, null); + } + } +}