From e80853a4cf665d73e7e5cdcb652d3d51cd456068 Mon Sep 17 00:00:00 2001 From: Hao Kung Date: Thu, 11 Jun 2015 14:56:25 -0700 Subject: [PATCH] Cleanup logging --- .../IdentityLogger.cs | 47 -- .../IdentityResult.cs | 9 - .../Properties/Resources.Designer.cs | 48 -- src/Microsoft.AspNet.Identity/Resources.resx | 12 - src/Microsoft.AspNet.Identity/RoleManager.cs | 76 +-- .../SignInManager.cs | 1 - src/Microsoft.AspNet.Identity/SignInResult.cs | 9 - src/Microsoft.AspNet.Identity/UserManager.cs | 519 +++++++----------- .../UserManagerTest.cs | 2 - test/Shared/IdentityResultAssert.cs | 60 +- test/Shared/MockHelpers.cs | 2 +- test/Shared/TestLogger.cs | 9 +- test/Shared/TestLoggerFactory.cs | 22 - test/Shared/UserManagerTestBase.cs | 122 ++-- 14 files changed, 289 insertions(+), 649 deletions(-) delete mode 100644 src/Microsoft.AspNet.Identity/IdentityLogger.cs delete mode 100644 test/Shared/TestLoggerFactory.cs diff --git a/src/Microsoft.AspNet.Identity/IdentityLogger.cs b/src/Microsoft.AspNet.Identity/IdentityLogger.cs deleted file mode 100644 index 84210620ee..0000000000 --- a/src/Microsoft.AspNet.Identity/IdentityLogger.cs +++ /dev/null @@ -1,47 +0,0 @@ -// 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; -using System.Runtime.CompilerServices; -using Microsoft.Framework.Logging; - -namespace Microsoft.AspNet.Identity.Logging -{ - /// - /// Extensions to make logging easier. - /// - /// - /// To be deleted before RTM. - /// - public static class IdentityLoggerExtensions - { - private static TResult Log(this ILogger logger, TResult result, Func getLevel, - Func messageAccessor) - { - if (logger == null) - { - return result; - } - - var logLevel = getLevel(result); - - // Check if log level is enabled before creating the message. - if (logger.IsEnabled(logLevel)) - { - logger.Log(logLevel, 0, messageAccessor(), null, (msg, exp) => (string)msg); - } - - return result; - } - - public static SignInResult Log(this ILogger logger, SignInResult result, [CallerMemberName]string methodName = null) - => logger.Log(result, r => r.GetLogLevel(), () => Resources.FormatLoggingResult(methodName, result)); - - public static IdentityResult Log(this ILogger logger, IdentityResult result, [CallerMemberName]string methodName = null) - => logger.Log(result, r => r.GetLogLevel(), () => Resources.FormatLoggingResult(methodName, result)); - - public static bool Log(this ILogger logger, bool result, [CallerMemberName]string methodName = null) - => logger.Log(result, b => b ? LogLevel.Verbose : LogLevel.Warning, - () => Resources.FormatLoggingResult(methodName, result)); - } -} \ No newline at end of file diff --git a/src/Microsoft.AspNet.Identity/IdentityResult.cs b/src/Microsoft.AspNet.Identity/IdentityResult.cs index 1b5c9a89be..f82e7473aa 100644 --- a/src/Microsoft.AspNet.Identity/IdentityResult.cs +++ b/src/Microsoft.AspNet.Identity/IdentityResult.cs @@ -63,14 +63,5 @@ namespace Microsoft.AspNet.Identity "Succeeded" : string.Format("{0} : {1}", "Failed", string.Join(",", Errors.Select(x => x.Code).ToList())); } - - /// - /// Gets the for use with any instance. - /// - /// The for this result. - public virtual LogLevel GetLogLevel() - { - return Succeeded ? LogLevel.Verbose : LogLevel.Warning; - } } } \ No newline at end of file diff --git a/src/Microsoft.AspNet.Identity/Properties/Resources.Designer.cs b/src/Microsoft.AspNet.Identity/Properties/Resources.Designer.cs index f3f767543b..85ec23501c 100644 --- a/src/Microsoft.AspNet.Identity/Properties/Resources.Designer.cs +++ b/src/Microsoft.AspNet.Identity/Properties/Resources.Designer.cs @@ -650,54 +650,6 @@ namespace Microsoft.AspNet.Identity return string.Format(CultureInfo.CurrentCulture, GetString("UserNotInRole"), p0); } - /// - /// {0} : {1} - /// - internal static string LoggingResult - { - get { return GetString("LoggingResult"); } - } - - /// - /// {0} : {1} - /// - internal static string FormatLoggingResult(object p0, object p1) - { - return string.Format(CultureInfo.CurrentCulture, GetString("LoggingResult"), p0, p1); - } - - /// - /// {0} for user: {1} - /// - internal static string LoggingResultMessageForUser - { - get { return GetString("LoggingResultMessageForUser"); } - } - - /// - /// {0} for user: {1} - /// - internal static string FormatLoggingResultMessageForUser(object p0, object p1) - { - return string.Format(CultureInfo.CurrentCulture, GetString("LoggingResultMessageForUser"), p0, p1); - } - - /// - /// {0} for role: {1} - /// - internal static string LoggingResultMessageForRole - { - get { return GetString("LoggingResultMessageForRole"); } - } - - /// - /// {0} for role: {1} - /// - internal static string FormatLoggingResultMessageForRole(object p0, object p1) - { - return string.Format(CultureInfo.CurrentCulture, GetString("LoggingResultMessageForRole"), p0, p1); - } - private static string GetString(string name, params string[] formatterNames) { var value = _resourceManager.GetString(name); diff --git a/src/Microsoft.AspNet.Identity/Resources.resx b/src/Microsoft.AspNet.Identity/Resources.resx index 7497fbcea1..558724645a 100644 --- a/src/Microsoft.AspNet.Identity/Resources.resx +++ b/src/Microsoft.AspNet.Identity/Resources.resx @@ -277,16 +277,4 @@ User is not in role '{0}'. Error when a user is not in the role - - {0} : {1} - Logging statement for a result object - - - {0} for user: {1} - Message prefix for Identity result - - - {0} for role: {1} - Message prefix for Identity result for role operation - \ No newline at end of file diff --git a/src/Microsoft.AspNet.Identity/RoleManager.cs b/src/Microsoft.AspNet.Identity/RoleManager.cs index 2587bf0d86..345d6ffb75 100644 --- a/src/Microsoft.AspNet.Identity/RoleManager.cs +++ b/src/Microsoft.AspNet.Identity/RoleManager.cs @@ -10,7 +10,6 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.AspNet.Hosting; using Microsoft.AspNet.Http; -using Microsoft.AspNet.Identity.Logging; using Microsoft.Framework.Logging; namespace Microsoft.AspNet.Identity @@ -170,10 +169,7 @@ namespace Microsoft.AspNet.Identity } await UpdateNormalizedRoleNameAsync(role); result = await Store.CreateAsync(role, CancellationToken); - using (await BeginLoggingScopeAsync(role)) - { - return Logger.Log(result); - } + return result; } /// @@ -196,7 +192,7 @@ namespace Microsoft.AspNet.Identity /// /// The that represents the asynchronous operation, containing the for the update. /// - public virtual async Task UpdateAsync(TRole role) + public virtual Task UpdateAsync(TRole role) { ThrowIfDisposed(); if (role == null) @@ -204,10 +200,7 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("role"); } - using (await BeginLoggingScopeAsync(role)) - { - return Logger.Log(await UpdateRoleAsync(role)); - } + return UpdateRoleAsync(role); } /// @@ -217,7 +210,7 @@ namespace Microsoft.AspNet.Identity /// /// The that represents the asynchronous operation, containing the for the delete. /// - public virtual async Task DeleteAsync(TRole role) + public virtual Task DeleteAsync(TRole role) { ThrowIfDisposed(); if (role == null) @@ -225,10 +218,7 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("role"); } - using (await BeginLoggingScopeAsync(role)) - { - return Logger.Log(await Store.DeleteAsync(role, CancellationToken)); - } + return Store.DeleteAsync(role, CancellationToken); } /// @@ -267,10 +257,10 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the role /// associated with the specified /// - public virtual async Task FindByIdAsync(string roleId) + public virtual Task FindByIdAsync(string roleId) { ThrowIfDisposed(); - return await Store.FindByIdAsync(roleId, CancellationToken); + return Store.FindByIdAsync(roleId, CancellationToken); } /// @@ -281,10 +271,10 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the name of the /// specified . /// - public virtual async Task GetRoleNameAsync(TRole role) + public virtual Task GetRoleNameAsync(TRole role) { ThrowIfDisposed(); - return await Store.GetRoleNameAsync(role, CancellationToken); + return Store.GetRoleNameAsync(role, CancellationToken); } /// @@ -300,12 +290,9 @@ namespace Microsoft.AspNet.Identity { ThrowIfDisposed(); - using (await BeginLoggingScopeAsync(role)) - { - await Store.SetRoleNameAsync(role, name, CancellationToken); - await UpdateNormalizedRoleNameAsync(role); - return Logger.Log(IdentityResult.Success); - } + await Store.SetRoleNameAsync(role, name, CancellationToken); + await UpdateNormalizedRoleNameAsync(role); + return IdentityResult.Success; } /// @@ -316,10 +303,10 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the ID of the /// specified . /// - public virtual async Task GetRoleIdAsync(TRole role) + public virtual Task GetRoleIdAsync(TRole role) { ThrowIfDisposed(); - return await Store.GetRoleIdAsync(role, CancellationToken); + return Store.GetRoleIdAsync(role, CancellationToken); } /// @@ -330,7 +317,7 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the role /// associated with the specified /// - public virtual async Task FindByNameAsync(string roleName) + public virtual Task FindByNameAsync(string roleName) { ThrowIfDisposed(); if (roleName == null) @@ -338,7 +325,7 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("roleName"); } - return await Store.FindByNameAsync(NormalizeKey(roleName), CancellationToken); + return Store.FindByNameAsync(NormalizeKey(roleName), CancellationToken); } /// @@ -363,11 +350,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("role"); } - using (await BeginLoggingScopeAsync(role)) - { - await claimStore.AddClaimAsync(role, claim, CancellationToken); - return Logger.Log(await UpdateRoleAsync(role)); - } + await claimStore.AddClaimAsync(role, claim, CancellationToken); + return await UpdateRoleAsync(role); } /// @@ -388,11 +372,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("role"); } - using (await BeginLoggingScopeAsync(role)) - { - await claimStore.RemoveClaimAsync(role, claim, CancellationToken); - return Logger.Log(await UpdateRoleAsync(role)); - } + await claimStore.RemoveClaimAsync(role, claim, CancellationToken); + return await UpdateRoleAsync(role); } /// @@ -403,7 +384,7 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the list of s /// associated with the specified . /// - public virtual async Task> GetClaimsAsync(TRole role) + public virtual Task> GetClaimsAsync(TRole role) { ThrowIfDisposed(); var claimStore = GetClaimStore(); @@ -411,7 +392,7 @@ namespace Microsoft.AspNet.Identity { throw new ArgumentNullException("role"); } - return await claimStore.GetClaimsAsync(role, CancellationToken); + return claimStore.GetClaimsAsync(role, CancellationToken); } /// @@ -436,12 +417,6 @@ namespace Microsoft.AspNet.Identity _disposed = true; } - protected virtual async Task BeginLoggingScopeAsync(TRole role, [CallerMemberName] string methodName = null) - { - var state = Resources.FormatLoggingResultMessageForRole(methodName, await GetRoleIdAsync(role)); - return Logger?.BeginScope(state); - } - private async Task ValidateRoleInternal(TRole role) { var errors = new List(); @@ -453,7 +428,12 @@ namespace Microsoft.AspNet.Identity errors.AddRange(result.Errors); } } - return errors.Count > 0 ? IdentityResult.Failed(errors.ToArray()) : IdentityResult.Success; + if (errors.Count > 0) + { + Logger.LogWarning("Role {roleId} validation failed: {errors}.", await GetRoleIdAsync(role), string.Join(";", errors.Select(e => e.Code))); + return IdentityResult.Failed(errors.ToArray()); + } + return IdentityResult.Success; } private async Task UpdateRoleAsync(TRole role) diff --git a/src/Microsoft.AspNet.Identity/SignInManager.cs b/src/Microsoft.AspNet.Identity/SignInManager.cs index 7206d8b28b..ce059cddb3 100644 --- a/src/Microsoft.AspNet.Identity/SignInManager.cs +++ b/src/Microsoft.AspNet.Identity/SignInManager.cs @@ -9,7 +9,6 @@ using System.Threading.Tasks; using Microsoft.AspNet.Hosting; using Microsoft.AspNet.Http; using Microsoft.AspNet.Http.Authentication; -using Microsoft.AspNet.Identity.Logging; using Microsoft.Framework.Logging; using Microsoft.Framework.OptionsModel; diff --git a/src/Microsoft.AspNet.Identity/SignInResult.cs b/src/Microsoft.AspNet.Identity/SignInResult.cs index e03215fe18..bcc205d67a 100644 --- a/src/Microsoft.AspNet.Identity/SignInResult.cs +++ b/src/Microsoft.AspNet.Identity/SignInResult.cs @@ -87,14 +87,5 @@ namespace Microsoft.AspNet.Identity RequiresTwoFactor ? "RequiresTwoFactor" : Succeeded ? "Succeeded" : "Failed"; } - - /// - /// Gets the log level for the current object. - /// - /// The log level for the current object. - public virtual LogLevel GetLogLevel() - { - return Succeeded || RequiresTwoFactor ? LogLevel.Verbose : LogLevel.Warning; - } } } \ No newline at end of file diff --git a/src/Microsoft.AspNet.Identity/UserManager.cs b/src/Microsoft.AspNet.Identity/UserManager.cs index 0612283173..35bb2f548e 100644 --- a/src/Microsoft.AspNet.Identity/UserManager.cs +++ b/src/Microsoft.AspNet.Identity/UserManager.cs @@ -12,7 +12,6 @@ using System.Threading; using System.Threading.Tasks; using Microsoft.AspNet.Hosting; using Microsoft.AspNet.Http; -using Microsoft.AspNet.Identity.Logging; using Microsoft.Framework.Logging; using Microsoft.Framework.OptionsModel; @@ -333,11 +332,7 @@ namespace Microsoft.AspNet.Identity await UpdateNormalizedUserNameAsync(user); await UpdateNormalizedEmailAsync(user); - result = await Store.CreateAsync(user, CancellationToken); - using (await BeginLoggingScopeAsync(user)) - { - return Logger.Log(result); - } + return await Store.CreateAsync(user, CancellationToken); } /// @@ -348,7 +343,7 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the /// of the operation. /// - public virtual async Task UpdateAsync(TUser user) + public virtual Task UpdateAsync(TUser user) { ThrowIfDisposed(); if (user == null) @@ -356,10 +351,7 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - return Logger.Log(await UpdateUserAsync(user)); - } + return UpdateUserAsync(user); } /// @@ -370,7 +362,7 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, containing the /// of the operation. /// - public virtual async Task DeleteAsync(TUser user) + public virtual Task DeleteAsync(TUser user) { ThrowIfDisposed(); if (user == null) @@ -378,10 +370,7 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - return Logger.Log(await Store.DeleteAsync(user, CancellationToken)); - } + return Store.DeleteAsync(user, CancellationToken); } /// @@ -497,12 +486,9 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await Store.SetUserNameAsync(user, userName, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); - } + await Store.SetUserNameAsync(user, userName, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -534,17 +520,19 @@ namespace Microsoft.AspNet.Identity return false; } - using (await BeginLoggingScopeAsync(user)) + var result = await VerifyPasswordAsync(passwordStore, user, password); + if (result == PasswordVerificationResult.SuccessRehashNeeded) { - var result = await VerifyPasswordAsync(passwordStore, user, password); - if (result == PasswordVerificationResult.SuccessRehashNeeded) - { - Logger.Log(await UpdatePasswordHash(passwordStore, user, password, validatePassword: false)); - Logger.Log(await UpdateUserAsync(user)); - } - - return Logger.Log(result != PasswordVerificationResult.Failed); + await UpdatePasswordHash(passwordStore, user, password, validatePassword: false); + await UpdateUserAsync(user); } + + var success = result != PasswordVerificationResult.Failed; + if (!success) + { + Logger.LogWarning("Invalid password for user {userId}.", await GetUserIdAsync(user)); + } + return success; } /// @@ -555,7 +543,7 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, returning true if the specified has a password /// otherwise false. /// - public virtual async Task HasPasswordAsync(TUser user) + public virtual Task HasPasswordAsync(TUser user) { ThrowIfDisposed(); var passwordStore = GetPasswordStore(); @@ -564,10 +552,7 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - return Logger.Log(await passwordStore.HasPasswordAsync(user, CancellationToken)); - } + return passwordStore.HasPasswordAsync(user, CancellationToken); } /// @@ -589,20 +574,18 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + var hash = await passwordStore.GetPasswordHashAsync(user, CancellationToken); + if (hash != null) { - var hash = await passwordStore.GetPasswordHashAsync(user, CancellationToken); - if (hash != null) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.UserAlreadyHasPassword())); - } - var result = await UpdatePasswordHash(passwordStore, user, password); - if (!result.Succeeded) - { - return Logger.Log(result); - } - return Logger.Log(await UpdateUserAsync(user)); + Logger.LogWarning("User {userId} already has a password.", await GetUserIdAsync(user)); + return IdentityResult.Failed(ErrorDescriber.UserAlreadyHasPassword()); } + var result = await UpdatePasswordHash(passwordStore, user, password); + if (!result.Succeeded) + { + return result; + } + return await UpdateUserAsync(user); } /// @@ -625,19 +608,18 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + + if (await VerifyPasswordAsync(passwordStore, user, currentPassword) != PasswordVerificationResult.Failed) { - if (await VerifyPasswordAsync(passwordStore, user, currentPassword) != PasswordVerificationResult.Failed) + var result = await UpdatePasswordHash(passwordStore, user, newPassword); + if (!result.Succeeded) { - var result = await UpdatePasswordHash(passwordStore, user, newPassword); - if (!result.Succeeded) - { - return Logger.Log(result); - } - return Logger.Log(await UpdateUserAsync(user)); + return result; } - return Logger.Log(IdentityResult.Failed(ErrorDescriber.PasswordMismatch())); + return await UpdateUserAsync(user); } + Logger.LogWarning("Change password failed for user {userId}.", await GetUserIdAsync(user)); + return IdentityResult.Failed(ErrorDescriber.PasswordMismatch()); } /// @@ -659,11 +641,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await UpdatePasswordHash(passwordStore, user, null, validatePassword: false); - return Logger.Log(await UpdateUserAsync(user)); - } + await UpdatePasswordHash(passwordStore, user, null, validatePassword: false); + return await UpdateUserAsync(user); } /// @@ -722,11 +701,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); - } + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -736,16 +712,10 @@ namespace Microsoft.AspNet.Identity /// The user to generate a password reset token for. /// The that represents the asynchronous operation, /// containing a password reset token for the specified . - public virtual async Task GeneratePasswordResetTokenAsync(TUser user) + public virtual Task GeneratePasswordResetTokenAsync(TUser user) { ThrowIfDisposed(); - - using (await BeginLoggingScopeAsync(user)) - { - var token = await GenerateUserTokenAsync(user, Options.PasswordResetTokenProvider, "ResetPassword"); - Logger.Log(IdentityResult.Success); - return token; - } + return GenerateUserTokenAsync(user, Options.PasswordResetTokenProvider, "ResetPassword"); } /// @@ -767,21 +737,18 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + // Make sure the token is valid and the stamp matches + if (!await VerifyUserTokenAsync(user, Options.PasswordResetTokenProvider, "ResetPassword", token)) { - // Make sure the token is valid and the stamp matches - if (!await VerifyUserTokenAsync(user, Options.PasswordResetTokenProvider, "ResetPassword", token)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - } - var passwordStore = GetPasswordStore(); - var result = await UpdatePasswordHash(passwordStore, user, newPassword); - if (!result.Succeeded) - { - return Logger.Log(result); - } - return Logger.Log(await UpdateUserAsync(user)); + return IdentityResult.Failed(ErrorDescriber.InvalidToken()); } + var passwordStore = GetPasswordStore(); + var result = await UpdatePasswordHash(passwordStore, user, newPassword); + if (!result.Succeeded) + { + return result; + } + return await UpdateUserAsync(user); } /// @@ -835,12 +802,9 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await loginStore.RemoveLoginAsync(user, loginProvider, providerKey, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); - } + await loginStore.RemoveLoginAsync(user, loginProvider, providerKey, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -865,16 +829,14 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + var existingUser = await FindByLoginAsync(login.LoginProvider, login.ProviderKey); + if (existingUser != null) { - var existingUser = await FindByLoginAsync(login.LoginProvider, login.ProviderKey); - if (existingUser != null) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.LoginAlreadyAssociated())); - } - await loginStore.AddLoginAsync(user, login, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + Logger.LogWarning("AddLogin for user {userId} failed because it was already assocated with another user.", await GetUserIdAsync(user)); + return IdentityResult.Failed(ErrorDescriber.LoginAlreadyAssociated()); } + await loginStore.AddLoginAsync(user, login, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -941,11 +903,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await claimStore.AddClaimsAsync(user, claims, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); - } + await claimStore.AddClaimsAsync(user, claims, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -976,11 +935,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await claimStore.ReplaceClaimAsync(user, claim, newClaim, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); - } + await claimStore.ReplaceClaimAsync(user, claim, newClaim, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1029,11 +985,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("claims"); } - using (await BeginLoggingScopeAsync(user)) - { - await claimStore.RemoveClaimsAsync(user, claims, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); - } + await claimStore.RemoveClaimsAsync(user, claims, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1072,16 +1025,13 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + var userRoles = await userRoleStore.GetRolesAsync(user, CancellationToken); + if (userRoles.Contains(role)) { - var userRoles = await userRoleStore.GetRolesAsync(user, CancellationToken); - if (userRoles.Contains(role)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.UserAlreadyInRole(role))); - } - await userRoleStore.AddToRoleAsync(user, role, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + return await UserAlreadyInRoleError(user, role); } + await userRoleStore.AddToRoleAsync(user, role, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1106,19 +1056,16 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("roles"); } - using (await BeginLoggingScopeAsync(user)) + var userRoles = await userRoleStore.GetRolesAsync(user, CancellationToken); + foreach (var role in roles) { - var userRoles = await userRoleStore.GetRolesAsync(user, CancellationToken); - foreach (var role in roles) + if (userRoles.Contains(role)) { - if (userRoles.Contains(role)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.UserAlreadyInRole(role))); - } - await userRoleStore.AddToRoleAsync(user, role, CancellationToken); + return await UserAlreadyInRoleError(user, role); } - return Logger.Log(await UpdateUserAsync(user)); + await userRoleStore.AddToRoleAsync(user, role, CancellationToken); } + return await UpdateUserAsync(user); } /// @@ -1139,15 +1086,24 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + if (!await userRoleStore.IsInRoleAsync(user, role, CancellationToken)) { - if (!await userRoleStore.IsInRoleAsync(user, role, CancellationToken)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.UserNotInRole(role))); - } - await userRoleStore.RemoveFromRoleAsync(user, role, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + return await UserNotInRoleError(user, role); } + await userRoleStore.RemoveFromRoleAsync(user, role, CancellationToken); + return await UpdateUserAsync(user); + } + + private async Task UserAlreadyInRoleError(TUser user, string role) + { + Logger.LogWarning("User {userId} is already in role {role}.", await GetUserIdAsync(user), role); + return IdentityResult.Failed(ErrorDescriber.UserAlreadyInRole(role)); + } + + private async Task UserNotInRoleError(TUser user, string role) + { + Logger.LogWarning("User {userId} is not in role {role}.", await GetUserIdAsync(user), role); + return IdentityResult.Failed(ErrorDescriber.UserNotInRole(role)); } /// @@ -1172,18 +1128,15 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("roles"); } - using (await BeginLoggingScopeAsync(user)) + foreach (var role in roles) { - foreach (var role in roles) + if (!await userRoleStore.IsInRoleAsync(user, role, CancellationToken)) { - if (!await userRoleStore.IsInRoleAsync(user, role, CancellationToken)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.UserNotInRole(role))); - } - await userRoleStore.RemoveFromRoleAsync(user, role, CancellationToken); + return await UserNotInRoleError(user, role); } - return Logger.Log(await UpdateUserAsync(user)); + await userRoleStore.RemoveFromRoleAsync(user, role, CancellationToken); } + return await UpdateUserAsync(user); } /// @@ -1257,13 +1210,10 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await store.SetEmailAsync(user, email, CancellationToken); - await store.SetEmailConfirmedAsync(user, false, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); - } + await store.SetEmailAsync(user, email, CancellationToken); + await store.SetEmailConfirmedAsync(user, false, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -1307,16 +1257,10 @@ namespace Microsoft.AspNet.Identity /// /// The that represents the asynchronous operation, an email confirmation token. /// - public async virtual Task GenerateEmailConfirmationTokenAsync(TUser user) + public virtual Task GenerateEmailConfirmationTokenAsync(TUser user) { ThrowIfDisposed(); - - using (await BeginLoggingScopeAsync(user)) - { - var token = await GenerateUserTokenAsync(user, Options.EmailConfirmationTokenProvider, "Confirmation"); - Logger.Log(IdentityResult.Success); - return token; - } + return GenerateUserTokenAsync(user, Options.EmailConfirmationTokenProvider, "EmailConfirmation"); } /// @@ -1337,15 +1281,12 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + if (!await VerifyUserTokenAsync(user, Options.EmailConfirmationTokenProvider, "EmailConfirmation", token)) { - if (!await VerifyUserTokenAsync(user, Options.EmailConfirmationTokenProvider, "Confirmation", token)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - } - await store.SetEmailConfirmedAsync(user, true, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + return IdentityResult.Failed(ErrorDescriber.InvalidToken()); } + await store.SetEmailConfirmedAsync(user, true, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1375,16 +1316,10 @@ namespace Microsoft.AspNet.Identity /// /// The that represents the asynchronous operation, an email change token. /// - public virtual async Task GenerateChangeEmailTokenAsync(TUser user, string newEmail) + public virtual Task GenerateChangeEmailTokenAsync(TUser user, string newEmail) { ThrowIfDisposed(); - - using (await BeginLoggingScopeAsync(user)) - { - var token = await GenerateUserTokenAsync(user, Options.ChangeEmailTokenProvider, GetChangeEmailPurpose(newEmail)); - Logger.Log(IdentityResult.Success); - return token; - } + return GenerateUserTokenAsync(user, Options.ChangeEmailTokenProvider, GetChangeEmailPurpose(newEmail)); } /// @@ -1405,19 +1340,16 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + // Make sure the token is valid and the stamp matches + if (!await VerifyUserTokenAsync(user, Options.ChangeEmailTokenProvider, GetChangeEmailPurpose(newEmail), token)) { - // Make sure the token is valid and the stamp matches - if (!await VerifyUserTokenAsync(user, Options.ChangeEmailTokenProvider, GetChangeEmailPurpose(newEmail), token)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - } - var store = GetEmailStore(); - await store.SetEmailAsync(user, newEmail, CancellationToken); - await store.SetEmailConfirmedAsync(user, true, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); + return IdentityResult.Failed(ErrorDescriber.InvalidToken()); } + var store = GetEmailStore(); + await store.SetEmailAsync(user, newEmail, CancellationToken); + await store.SetEmailConfirmedAsync(user, true, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -1454,13 +1386,10 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await store.SetPhoneNumberAsync(user, phoneNumber, CancellationToken); - await store.SetPhoneNumberConfirmedAsync(user, false, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); - } + await store.SetPhoneNumberAsync(user, phoneNumber, CancellationToken); + await store.SetPhoneNumberConfirmedAsync(user, false, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -1483,17 +1412,15 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + if (!await VerifyChangePhoneNumberTokenAsync(user, token, phoneNumber)) { - if (!await VerifyChangePhoneNumberTokenAsync(user, token, phoneNumber)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - } - await store.SetPhoneNumberAsync(user, phoneNumber, CancellationToken); - await store.SetPhoneNumberConfirmedAsync(user, true, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); + Logger.LogWarning("Change phone number for user {userId} failed with invalid token.", await GetUserIdAsync(user)); + return IdentityResult.Failed(ErrorDescriber.InvalidToken()); } + await store.SetPhoneNumberAsync(user, phoneNumber, CancellationToken); + await store.SetPhoneNumberConfirmedAsync(user, true, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -1504,7 +1431,7 @@ namespace Microsoft.AspNet.Identity /// The that represents the asynchronous operation, returning true if the specified has a confirmed /// telephone number otherwise false. /// - public virtual async Task IsPhoneNumberConfirmedAsync(TUser user) + public virtual Task IsPhoneNumberConfirmedAsync(TUser user) { ThrowIfDisposed(); var store = GetPhoneNumberStore(); @@ -1512,7 +1439,7 @@ namespace Microsoft.AspNet.Identity { throw new ArgumentNullException("user"); } - return await store.GetPhoneNumberConfirmedAsync(user, CancellationToken); + return store.GetPhoneNumberConfirmedAsync(user, CancellationToken); } /// @@ -1526,15 +1453,9 @@ namespace Microsoft.AspNet.Identity public virtual async Task GenerateChangePhoneNumberTokenAsync(TUser user, string phoneNumber) { ThrowIfDisposed(); - - using (await BeginLoggingScopeAsync(user)) - { - var token = Rfc6238AuthenticationService.GenerateCode( - await CreateSecurityTokenAsync(user), phoneNumber) - .ToString(CultureInfo.InvariantCulture); - Logger.Log(IdentityResult.Success); - return token; - } + return Rfc6238AuthenticationService.GenerateCode( + await CreateSecurityTokenAsync(user), phoneNumber) + .ToString(CultureInfo.InvariantCulture); } /// @@ -1552,21 +1473,17 @@ namespace Microsoft.AspNet.Identity { ThrowIfDisposed(); - using (await BeginLoggingScopeAsync(user)) + var securityToken = await CreateSecurityTokenAsync(user); + int code; + if (securityToken != null && Int32.TryParse(token, out code)) { - var securityToken = await CreateSecurityTokenAsync(user); - int code; - if (securityToken != null && Int32.TryParse(token, out code)) + if (Rfc6238AuthenticationService.ValidateCode(securityToken, code, phoneNumber)) { - if (Rfc6238AuthenticationService.ValidateCode(securityToken, code, phoneNumber)) - { - Logger.Log(IdentityResult.Success); - return true; - } + return true; } - Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - return false; } + Logger.LogWarning("VerifyChangePhoneNumberTokenAsync() failed for user {userId}.", await GetUserIdAsync(user)); + return false; } /// @@ -1593,26 +1510,18 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException(nameof(tokenProvider)); } - using (await BeginLoggingScopeAsync(user)) + if (!_tokenProviders.ContainsKey(tokenProvider)) { - if (!_tokenProviders.ContainsKey(tokenProvider)) - { - throw new NotSupportedException(string.Format(CultureInfo.CurrentCulture, Resources.NoTokenProvider, tokenProvider)); - } - // Make sure the token is valid - var result = await _tokenProviders[tokenProvider].ValidateAsync(purpose, token, this, user); - - if (result) - { - Logger.Log(IdentityResult.Success); - } - else - { - Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - } - - return result; + throw new NotSupportedException(string.Format(CultureInfo.CurrentCulture, Resources.NoTokenProvider, tokenProvider)); } + // Make sure the token is valid + var result = await _tokenProviders[tokenProvider].ValidateAsync(purpose, token, this, user); + + if (!result) + { + Logger.LogWarning("VerifyUserTokenAsync() failed with purpose: {purpose} for user {userId}.", purpose, await GetUserIdAsync(user)); + } + return result; } /// @@ -1625,7 +1534,7 @@ namespace Microsoft.AspNet.Identity /// The that represents result of the asynchronous operation, a token for /// the given user and purpose. /// - public virtual async Task GenerateUserTokenAsync(TUser user, string tokenProvider, string purpose) + public virtual Task GenerateUserTokenAsync(TUser user, string tokenProvider, string purpose) { ThrowIfDisposed(); if (user == null) @@ -1641,10 +1550,7 @@ namespace Microsoft.AspNet.Identity throw new NotSupportedException(string.Format(CultureInfo.CurrentCulture, Resources.NoTokenProvider, tokenProvider)); } - //TODO: Should we scope here ? - var token = await _tokenProviders[tokenProvider].GenerateAsync(purpose, this, user); - Logger.Log(IdentityResult.Success); - return token; + return _tokenProviders[tokenProvider].GenerateAsync(purpose, this, user); } /// @@ -1711,20 +1617,13 @@ namespace Microsoft.AspNet.Identity Resources.NoTokenProvider, tokenProvider)); } - using (await BeginLoggingScopeAsync(user)) - { // Make sure the token is valid - var result = await _tokenProviders[tokenProvider].ValidateAsync("TwoFactor", token, this, user); - if (result) - { - Logger.Log(IdentityResult.Success); - } - else - { - Logger.Log(IdentityResult.Failed(ErrorDescriber.InvalidToken())); - } - return result; + var result = await _tokenProviders[tokenProvider].ValidateAsync("TwoFactor", token, this, user); + if (!result) + { + Logger.LogWarning($"{nameof(VerifyTwoFactorTokenAsync)}() failed for user {await GetUserIdAsync(user)}."); } + return result; } /// @@ -1736,7 +1635,7 @@ namespace Microsoft.AspNet.Identity /// The that represents result of the asynchronous operation, a two factor authentication token /// for the user. /// - public virtual async Task GenerateTwoFactorTokenAsync(TUser user, string tokenProvider) + public virtual Task GenerateTwoFactorTokenAsync(TUser user, string tokenProvider) { ThrowIfDisposed(); if (user == null) @@ -1749,12 +1648,7 @@ namespace Microsoft.AspNet.Identity Resources.NoTokenProvider, tokenProvider)); } - using (await BeginLoggingScopeAsync(user)) - { - var token = await _tokenProviders[tokenProvider].GenerateAsync("TwoFactor", this, user); - Logger.Log(IdentityResult.Success); - return token; - } + return _tokenProviders[tokenProvider].GenerateAsync("TwoFactor", this, user); } /// @@ -1794,12 +1688,9 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await store.SetTwoFactorEnabledAsync(user, enabled, CancellationToken); - await UpdateSecurityStampInternal(user); - return Logger.Log(await UpdateUserAsync(user)); - } + await store.SetTwoFactorEnabledAsync(user, enabled, CancellationToken); + await UpdateSecurityStampInternal(user); + return await UpdateUserAsync(user); } /// @@ -1845,11 +1736,8 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) - { - await store.SetLockoutEnabledAsync(user, enabled, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); - } + await store.SetLockoutEnabledAsync(user, enabled, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1904,15 +1792,13 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + if (!await store.GetLockoutEnabledAsync(user, CancellationToken)) { - if (!await store.GetLockoutEnabledAsync(user, CancellationToken)) - { - return Logger.Log(IdentityResult.Failed(ErrorDescriber.UserLockoutNotEnabled())); - } - await store.SetLockoutEndDateAsync(user, lockoutEnd, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + Logger.LogWarning("Lockout for user {userId} failed because lockout is not enabled for this user.", await GetUserIdAsync(user)); + return IdentityResult.Failed(ErrorDescriber.UserLockoutNotEnabled()); } + await store.SetLockoutEndDateAsync(user, lockoutEnd, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1931,19 +1817,17 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + // If this puts the user over the threshold for lockout, lock them out and reset the access failed count + var count = await store.IncrementAccessFailedCountAsync(user, CancellationToken); + if (count < Options.Lockout.MaxFailedAccessAttempts) { - // If this puts the user over the threshold for lockout, lock them out and reset the access failed count - var count = await store.IncrementAccessFailedCountAsync(user, CancellationToken); - if (count < Options.Lockout.MaxFailedAccessAttempts) - { - return Logger.Log(await UpdateUserAsync(user)); - } - await store.SetLockoutEndDateAsync(user, DateTimeOffset.UtcNow.Add(Options.Lockout.DefaultLockoutTimeSpan), - CancellationToken); - await store.ResetAccessFailedCountAsync(user, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + return await UpdateUserAsync(user); } + Logger.LogWarning("User {userId} is locked out.", await GetUserIdAsync(user)); + await store.SetLockoutEndDateAsync(user, DateTimeOffset.UtcNow.Add(Options.Lockout.DefaultLockoutTimeSpan), + CancellationToken); + await store.ResetAccessFailedCountAsync(user, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -1960,15 +1844,12 @@ namespace Microsoft.AspNet.Identity throw new ArgumentNullException("user"); } - using (await BeginLoggingScopeAsync(user)) + if (await GetAccessFailedCountAsync(user) == 0) { - if (await GetAccessFailedCountAsync(user) == 0) - { - return Logger.Log(IdentityResult.Success); - } - await store.ResetAccessFailedCountAsync(user, CancellationToken); - return Logger.Log(await UpdateUserAsync(user)); + return IdentityResult.Success; } + await store.ResetAccessFailedCountAsync(user, CancellationToken); + return await UpdateUserAsync(user); } /// @@ -2019,18 +1900,6 @@ namespace Microsoft.AspNet.Identity return store.GetUsersInRoleAsync(roleName, CancellationToken); } - /// - /// Starts a logging scope to contain the logging messages for an operation, as an asynchronous operation. - /// - /// The user the operation is acting on. - /// The method that called this method. - /// A containing the logging scope. - protected virtual async Task BeginLoggingScopeAsync(TUser user, [CallerMemberName] string methodName = null) - { - var state = Resources.FormatLoggingResultMessageForUser(methodName, await GetUserIdAsync(user)); - return Logger?.BeginScope(state); - } - /// /// Releases the unmanaged resources used by the role manager and optionally releases the managed resources. /// @@ -2183,7 +2052,12 @@ namespace Microsoft.AspNet.Identity errors.AddRange(result.Errors); } } - return errors.Count > 0 ? IdentityResult.Failed(errors.ToArray()) : IdentityResult.Success; + if (errors.Count > 0) + { + Logger.LogWarning("User {userId} validation failed: {errors}.", await GetUserIdAsync(user), string.Join(";", errors.Select(e => e.Code))); + return IdentityResult.Failed(errors.ToArray()); + } + return IdentityResult.Success; } private async Task ValidatePasswordInternal(TUser user, string password) @@ -2197,7 +2071,12 @@ namespace Microsoft.AspNet.Identity errors.AddRange(result.Errors); } } - return errors.Count > 0 ? IdentityResult.Failed(errors.ToArray()) : IdentityResult.Success; + if (errors.Count > 0) + { + Logger.LogWarning("User {userId} password validation failed: {errors}.", await GetUserIdAsync(user), string.Join(";", errors.Select(e => e.Code))); + return IdentityResult.Failed(errors.ToArray()); + } + return IdentityResult.Success; } /// diff --git a/test/Microsoft.AspNet.Identity.Test/UserManagerTest.cs b/test/Microsoft.AspNet.Identity.Test/UserManagerTest.cs index 4b0d451af1..b37d2f9710 100644 --- a/test/Microsoft.AspNet.Identity.Test/UserManagerTest.cs +++ b/test/Microsoft.AspNet.Identity.Test/UserManagerTest.cs @@ -423,8 +423,6 @@ namespace Microsoft.AspNet.Identity.Test store.Setup(s => s.GetPasswordHashAsync(user, CancellationToken.None)) .ReturnsAsync(hashed) .Verifiable(); - store.Setup(x => x.GetUserIdAsync(It.IsAny(), It.IsAny())) - .Returns(Task.FromResult(Guid.NewGuid().ToString())); store.Setup(x => x.UpdateAsync(It.IsAny(), It.IsAny())).Returns(Task.FromResult(IdentityResult.Success)); hasher.Setup(s => s.VerifyHashedPassword(user, hashed, pwd)).Returns(PasswordVerificationResult.SuccessRehashNeeded).Verifiable(); diff --git a/test/Shared/IdentityResultAssert.cs b/test/Shared/IdentityResultAssert.cs index 8ef7566c39..a950722c9f 100644 --- a/test/Shared/IdentityResultAssert.cs +++ b/test/Shared/IdentityResultAssert.cs @@ -1,6 +1,7 @@ // 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.Diagnostics; using System.Linq; using Microsoft.Framework.Logging; using Xunit; @@ -36,71 +37,16 @@ namespace Microsoft.AspNet.Identity.Test Assert.Equal(error.Code, result.Errors.First().Code); } - public static void VerifyUserManagerFailureLog(ILogger logger, string methodName, string userId, params IdentityError[] errors) - { - VerifyFailureLog(logger, "UserManager", methodName, userId, "user", errors); - } - - public static void VerifyRoleManagerFailureLog(ILogger logger, string methodName, string roleId, params IdentityError[] errors) - { - VerifyFailureLog(logger, "RoleManager", methodName, roleId, "role", errors); - } - - public static void VerifyUserManagerSuccessLog(ILogger logger, string methodName, string userId) - { - VerifySuccessLog(logger, "UserManager", methodName, userId, "user"); - - } - - public static void VerifyRoleManagerSuccessLog(ILogger logger, string methodName, string roleId) - { - VerifySuccessLog(logger, "RoleManager", methodName, roleId, "role"); - - } - private static void VerifySuccessLog(ILogger logger, string className, string methodName, string id, string userOrRole = "user") - { - TestLogger testlogger = logger as TestLogger; - if (testlogger != null) - { - string expectedScope = string.Format("{0} for {1}: {2}", methodName, userOrRole, id); - string expectedLog = string.Format("{0} : Succeeded", methodName); - Assert.True(testlogger.LogMessages.Contains(expectedScope)); - Assert.True(testlogger.LogMessages.Contains(expectedLog)); - } - else - { - Assert.True(true, "No logger registered"); - } - } - public static void VerifyLogMessage(ILogger logger, string expectedLog) { - TestLogger testlogger = logger as TestLogger; + var testlogger = logger as ITestLogger; if (testlogger != null) { Assert.True(testlogger.LogMessages.Contains(expectedLog)); } else { - Assert.True(true, "No logger registered"); - } - } - - private static void VerifyFailureLog(ILogger logger, string className, string methodName, string id, string userOrRole = "user", params IdentityError[] errors) - { - TestLogger testlogger = logger as TestLogger; - if (testlogger != null) - { - errors = errors ?? new IdentityError[] { new IdentityError() }; - string expectedScope = string.Format("{0} for {1}: {2}", methodName, userOrRole, id); - string expectedLog = string.Format("{0} : Failed : {1}", methodName, string.Join(",", errors.Select(x => x.Code).ToList())); - - Assert.True(testlogger.LogMessages.Contains(expectedScope)); - Assert.True(testlogger.LogMessages.Contains(expectedLog)); - } - else - { - Assert.True(true, "No logger registered"); + Assert.False(true, "No logger registered"); } } } diff --git a/test/Shared/MockHelpers.cs b/test/Shared/MockHelpers.cs index 870e1d564e..df5eeacc80 100644 --- a/test/Shared/MockHelpers.cs +++ b/test/Shared/MockHelpers.cs @@ -78,7 +78,7 @@ namespace Microsoft.AspNet.Identity.Test var userManager = new UserManager(store, options.Object, new PasswordHasher(), userValidators, pwdValidators, new UpperInvariantLookupNormalizer(), new IdentityErrorDescriber(), Enumerable.Empty>(), - null, + new Mock>>().Object, null); validator.Setup(v => v.ValidateAsync(userManager, It.IsAny())) .Returns(Task.FromResult(IdentityResult.Success)).Verifiable(); diff --git a/test/Shared/TestLogger.cs b/test/Shared/TestLogger.cs index 78a90d0e7b..a33360948e 100644 --- a/test/Shared/TestLogger.cs +++ b/test/Shared/TestLogger.cs @@ -7,9 +7,14 @@ using Microsoft.Framework.Logging; namespace Microsoft.AspNet.Identity.Test { - public class TestLogger : ILogger + public interface ITestLogger { - public IList LogMessages { get; private set; } = new List(); + IList LogMessages { get; } + } + + public class TestLogger : ILogger, ITestLogger + { + public IList LogMessages { get; } = new List(); public IDisposable BeginScopeImpl(object state) { diff --git a/test/Shared/TestLoggerFactory.cs b/test/Shared/TestLoggerFactory.cs deleted file mode 100644 index 2c02c3fe9c..0000000000 --- a/test/Shared/TestLoggerFactory.cs +++ /dev/null @@ -1,22 +0,0 @@ -// 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 Microsoft.Framework.Logging; - -namespace Microsoft.AspNet.Identity.Test -{ - public class TestLoggerFactory : ILoggerFactory - { - public LogLevel MinimumLevel { get; set; } - - public void AddProvider(ILoggerProvider provider) - { - - } - - public ILogger CreateLogger(string name) - { - return new TestLogger(); - } - } -} diff --git a/test/Shared/UserManagerTestBase.cs b/test/Shared/UserManagerTestBase.cs index 1dc5089a86..8bf5f876f5 100644 --- a/test/Shared/UserManagerTestBase.cs +++ b/test/Shared/UserManagerTestBase.cs @@ -27,7 +27,6 @@ namespace Microsoft.AspNet.Identity.Test where TKey : IEquatable { private readonly IdentityErrorDescriber _errorDescriber = new IdentityErrorDescriber(); - protected TestLoggerFactory LoggerFactory { get; } = new TestLoggerFactory(); protected virtual void SetupIdentityServices(IServiceCollection services, object context = null) { @@ -35,8 +34,9 @@ namespace Microsoft.AspNet.Identity.Test services.AddIdentity().AddDefaultTokenProviders(); AddUserStore(services, context); AddRoleStore(services, context); - services.AddInstance(LoggerFactory); services.AddLogging(); + services.AddInstance>>(new TestLogger>()); + services.AddInstance>>(new TestLogger>()); services.ConfigureIdentity(options => { options.Password.RequireDigit = false; @@ -100,11 +100,7 @@ namespace Microsoft.AspNet.Identity.Test var user = CreateTestUser(); IdentityResultAssert.IsSuccess(await manager.CreateAsync(user)); var userId = await manager.GetUserIdAsync(user); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "CreateAsync", userId); - IdentityResultAssert.IsSuccess(await manager.DeleteAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "DeleteAsync", userId); - Assert.Null(await manager.FindByIdAsync(userId)); } @@ -119,7 +115,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.Null(await manager.FindByNameAsync(newName)); IdentityResultAssert.IsSuccess(await manager.SetUserNameAsync(user, newName)); IdentityResultAssert.IsSuccess(await manager.UpdateAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "UpdateAsync", await manager.GetUserIdAsync(user)); Assert.NotNull(await manager.FindByNameAsync(newName)); Assert.Null(await manager.FindByNameAsync(name)); } @@ -128,7 +123,6 @@ namespace Microsoft.AspNet.Identity.Test public async Task CheckSetUserNameValidatesUser() { var manager = CreateManager(); - manager.UserValidators.Add(new UserValidator()); var username = "UpdateAsync" + Guid.NewGuid().ToString(); var newUsername = "New" + Guid.NewGuid().ToString(); var user = CreateTestUser(username, useNamePrefixAsUserName: true); @@ -140,8 +134,13 @@ namespace Microsoft.AspNet.Identity.Test var newUser = CreateTestUser(username, useNamePrefixAsUserName: true); IdentityResultAssert.IsSuccess(await manager.CreateAsync(newUser)); - IdentityResultAssert.IsFailure(await manager.SetUserNameAsync(newUser, ""), _errorDescriber.InvalidUserName("")); - IdentityResultAssert.IsFailure(await manager.SetUserNameAsync(newUser, newUsername), _errorDescriber.DuplicateUserName(newUsername)); + var error = _errorDescriber.InvalidUserName(""); + IdentityResultAssert.IsFailure(await manager.SetUserNameAsync(newUser, ""), error); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(newUser)} validation failed: {error.Code}."); + + error = _errorDescriber.DuplicateUserName(newUsername); + IdentityResultAssert.IsFailure(await manager.SetUserNameAsync(newUser, newUsername), error); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(newUser)} validation failed: {error.Code}."); } [Fact] @@ -185,14 +184,11 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.CreateAsync(user, "password")); Assert.True(await manager.CheckPasswordAsync(user, "password")); var userId = await manager.GetUserIdAsync(user); - string expectedLog = string.Format("{0} : {1}", "CheckPasswordAsync", true.ToString()); - IdentityResultAssert.VerifyLogMessage(manager.Logger, expectedLog); SetUserPasswordHash(user, manager.PasswordHasher.HashPassword(user, "New")); IdentityResultAssert.IsSuccess(await manager.UpdateAsync(user)); Assert.False(await manager.CheckPasswordAsync(user, "password")); - expectedLog = string.Format("{0} : {1}", "CheckPasswordAsync", false.ToString()); - IdentityResultAssert.VerifyLogMessage(manager.Logger, expectedLog); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"Invalid password for user {await manager.GetUserIdAsync(user)}."); Assert.True(await manager.CheckPasswordAsync(user, "New")); } @@ -213,6 +209,7 @@ namespace Microsoft.AspNet.Identity.Test manager.UserValidators.Clear(); manager.UserValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.CreateAsync(user), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -224,7 +221,7 @@ namespace Microsoft.AspNet.Identity.Test manager.UserValidators.Clear(); manager.UserValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.UpdateAsync(user), AlwaysBadValidator.ErrorMessage); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "UpdateAsync", await manager.GetUserIdAsync(user), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -232,10 +229,12 @@ namespace Microsoft.AspNet.Identity.Test { var manager = CreateManager(); manager.UserValidators.Clear(); + var user = CreateTestUser(); manager.UserValidators.Add(new AlwaysBadValidator()); manager.UserValidators.Add(new AlwaysBadValidator()); - var result = await manager.CreateAsync(CreateTestUser()); + var result = await manager.CreateAsync(user); IdentityResultAssert.IsFailure(result, AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} validation failed: {AlwaysBadValidator.ErrorMessage.Code};{AlwaysBadValidator.ErrorMessage.Code}."); Assert.Equal(2, result.Errors.Count()); } @@ -273,7 +272,7 @@ namespace Microsoft.AspNet.Identity.Test manager.PasswordValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.AddPasswordAsync(user, "password"), AlwaysBadValidator.ErrorMessage); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "AddPasswordAsync", await manager.GetUserIdAsync(user), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} password validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -300,7 +299,7 @@ namespace Microsoft.AspNet.Identity.Test manager.PasswordValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.ChangePasswordAsync(user, "password", "new"), AlwaysBadValidator.ErrorMessage); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ChangePasswordAsync", await manager.GetUserIdAsync(user), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} password validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -311,6 +310,7 @@ namespace Microsoft.AspNet.Identity.Test manager.PasswordValidators.Clear(); manager.PasswordValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.CreateAsync(user, "password"), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} password validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -338,7 +338,6 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.CreateAsync(user)); var providerKey = await manager.GetUserIdAsync(user); IdentityResultAssert.IsSuccess(await manager.AddLoginAsync(user, new UserLoginInfo(provider, providerKey, display))); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "AddLoginAsync", await manager.GetUserIdAsync(user)); var logins = await manager.GetLoginsAsync(user); Assert.NotNull(logins); Assert.Equal(1, logins.Count()); @@ -358,7 +357,6 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.AddLoginAsync(user, login)); Assert.False(await manager.HasPasswordAsync(user)); IdentityResultAssert.IsSuccess(await manager.AddPasswordAsync(user, "password")); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "AddPasswordAsync", userId); Assert.True(await manager.HasPasswordAsync(user)); var logins = await manager.GetLoginsAsync(user); Assert.NotNull(logins); @@ -376,7 +374,7 @@ namespace Microsoft.AspNet.Identity.Test Assert.True(await manager.HasPasswordAsync(user)); IdentityResultAssert.IsFailure(await manager.AddPasswordAsync(user, "password"), "User already has a password set."); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "AddPasswordAsync", await manager.GetUserIdAsync(user), _errorDescriber.UserAlreadyHasPassword()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} already has a password."); } [Fact] @@ -399,7 +397,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.Equal(login.ProviderDisplayName, logins.Last().ProviderDisplayName); var stamp = await manager.GetSecurityStampAsync(user); IdentityResultAssert.IsSuccess(await manager.RemoveLoginAsync(user, login.LoginProvider, login.ProviderKey)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "RemoveLoginAsync", userId); Assert.Null(await manager.FindByLoginAsync(login.LoginProvider, login.ProviderKey)); logins = await manager.GetLoginsAsync(user); Assert.NotNull(logins); @@ -417,7 +414,6 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); var username = await manager.GetUserNameAsync(user); IdentityResultAssert.IsSuccess(await manager.RemovePasswordAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "RemovePasswordAsync", await manager.GetUserIdAsync(user)); var u = await manager.FindByNameAsync(username); Assert.NotNull(u); Assert.False(await manager.HasPasswordAsync(user)); @@ -437,7 +433,6 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.ChangePasswordAsync(user, password, newPassword)); Assert.False(await manager.CheckPasswordAsync(user, password)); Assert.True(await manager.CheckPasswordAsync(user, newPassword)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "ChangePasswordAsync", await manager.GetUserIdAsync(user)); Assert.NotEqual(stamp, await manager.GetSecurityStampAsync(user)); } @@ -453,11 +448,9 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.AddClaimAsync(user, c)); } var userId = await manager.GetUserIdAsync(user); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "AddClaimsAsync", userId); var userClaims = await manager.GetClaimsAsync(user); Assert.Equal(3, userClaims.Count); IdentityResultAssert.IsSuccess(await manager.RemoveClaimAsync(user, claims[0])); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "RemoveClaimsAsync", userId); userClaims = await manager.GetClaimsAsync(user); Assert.Equal(2, userClaims.Count); IdentityResultAssert.IsSuccess(await manager.RemoveClaimAsync(user, claims[1])); @@ -509,7 +502,6 @@ namespace Microsoft.AspNet.Identity.Test Claim claim = new Claim("c", "b"); Claim oldClaim = userClaims.FirstOrDefault(); IdentityResultAssert.IsSuccess(await manager.ReplaceClaimAsync(user, oldClaim, claim)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "ReplaceClaimAsync", await manager.GetUserIdAsync(user)); var newUserClaims = await manager.GetClaimsAsync(user); Assert.Equal(1, newUserClaims.Count); Claim newClaim = newUserClaims.FirstOrDefault(); @@ -554,7 +546,7 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.CreateAsync(user, "password")); var result = await manager.ChangePasswordAsync(user, "bogus", "newpassword"); IdentityResultAssert.IsFailure(result, "Incorrect password."); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ChangePasswordAsync", await manager.GetUserIdAsync(user), _errorDescriber.PasswordMismatch()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"Change password failed for user {await manager.GetUserIdAsync(user)}."); } [Fact] @@ -600,7 +592,6 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); Assert.NotNull(stamp); IdentityResultAssert.IsSuccess(await manager.UpdateSecurityStampAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "UpdateSecurityStampAsync", await manager.GetUserIdAsync(user)); Assert.NotEqual(stamp, await manager.GetSecurityStampAsync(user)); } @@ -614,7 +605,7 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.AddLoginAsync(user, login)); var result = await manager.AddLoginAsync(user, login); IdentityResultAssert.IsFailure(result, _errorDescriber.LoginAlreadyAssociated()); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "AddLoginAsync", await manager.GetUserIdAsync(user), _errorDescriber.LoginAlreadyAssociated()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"AddLogin for user {await manager.GetUserIdAsync(user)} failed because it was already assocated with another user."); } // Email tests @@ -699,9 +690,7 @@ namespace Microsoft.AspNet.Identity.Test var token = await manager.GeneratePasswordResetTokenAsync(user); Assert.NotNull(token); var userId = await manager.GetUserIdAsync(user); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "GeneratePasswordResetTokenAsync", userId); IdentityResultAssert.IsSuccess(await manager.ResetPasswordAsync(user, token, newPassword)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "ResetPasswordAsync", userId); Assert.False(await manager.CheckPasswordAsync(user, password)); Assert.True(await manager.CheckPasswordAsync(user, newPassword)); Assert.NotEqual(stamp, await manager.GetSecurityStampAsync(user)); @@ -724,7 +713,7 @@ namespace Microsoft.AspNet.Identity.Test manager.PasswordValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.ResetPasswordAsync(user, token, newPassword), AlwaysBadValidator.ErrorMessage); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ResetPasswordAsync", await manager.GetUserIdAsync(user), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"User {await manager.GetUserIdAsync(user)} password validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); Assert.True(await manager.CheckPasswordAsync(user, password)); Assert.Equal(stamp, await manager.GetSecurityStampAsync(user)); } @@ -742,7 +731,7 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); Assert.NotNull(stamp); IdentityResultAssert.IsFailure(await manager.ResetPasswordAsync(user, "bogus", newPassword), "Invalid token."); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ResetPasswordAsync", await manager.GetUserIdAsync(user), _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: ResetPassword for user { await manager.GetUserIdAsync(user)}."); Assert.True(await manager.CheckPasswordAsync(user, password)); Assert.Equal(stamp, await manager.GetSecurityStampAsync(user)); } @@ -758,17 +747,17 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.CreateAsync(user2)); var userId = await manager.GetUserIdAsync(user); var token = await manager.GenerateUserTokenAsync(user, "Static", "test"); - var expectedLog = string.Format("{0} : {1}", "GenerateUserTokenAsync", "Succeeded"); - IdentityResultAssert.VerifyLogMessage(manager.Logger, expectedLog); Assert.True(await manager.VerifyUserTokenAsync(user, "Static", "test", token)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "VerifyUserTokenAsync", userId); Assert.False(await manager.VerifyUserTokenAsync(user, "Static", "test2", token)); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "VerifyUserTokenAsync", userId, _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: test2 for user { await manager.GetUserIdAsync(user)}."); Assert.False(await manager.VerifyUserTokenAsync(user, "Static", "test", token + "a")); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: test for user { await manager.GetUserIdAsync(user)}."); + Assert.False(await manager.VerifyUserTokenAsync(user2, "Static", "test", token)); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: test for user { await manager.GetUserIdAsync(user2)}."); } [Fact] @@ -783,9 +772,7 @@ namespace Microsoft.AspNet.Identity.Test var token = await manager.GenerateEmailConfirmationTokenAsync(user); Assert.NotNull(token); var userId = await manager.GetUserIdAsync(user); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "GenerateEmailConfirmationTokenAsync", userId); IdentityResultAssert.IsSuccess(await manager.ConfirmEmailAsync(user, token)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "ConfirmEmailAsync", userId); Assert.True(await manager.IsEmailConfirmedAsync(user)); IdentityResultAssert.IsSuccess(await manager.SetEmailAsync(user, null)); Assert.False(await manager.IsEmailConfirmedAsync(user)); @@ -802,7 +789,7 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.CreateAsync(user)); IdentityResultAssert.IsFailure(await manager.ConfirmEmailAsync(user, "bogus"), "Invalid token."); Assert.False(await manager.IsEmailConfirmedAsync(user)); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ConfirmEmailAsync", await manager.GetUserIdAsync(user), _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: EmailConfirmation for user { await manager.GetUserIdAsync(user)}."); } [Fact] @@ -816,6 +803,7 @@ namespace Microsoft.AspNet.Identity.Test Assert.NotNull(token); IdentityResultAssert.IsSuccess(await manager.ChangePasswordAsync(user, "password", "newpassword")); IdentityResultAssert.IsFailure(await manager.ConfirmEmailAsync(user, token), "Invalid token."); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: EmailConfirmation for user { await manager.GetUserIdAsync(user)}."); Assert.False(await manager.IsEmailConfirmedAsync(user)); } @@ -835,6 +823,8 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await mgr.AccessFailedAsync(user)); Assert.True(await mgr.IsLockedOutAsync(user)); Assert.True(await mgr.GetLockoutEndDateAsync(user) > DateTimeOffset.UtcNow.AddMinutes(55)); + IdentityResultAssert.VerifyLogMessage(mgr.Logger, $"User {await mgr.GetUserIdAsync(user)} is locked out."); + Assert.Equal(0, await mgr.GetAccessFailedCountAsync(user)); } @@ -856,6 +846,7 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await mgr.AccessFailedAsync(user)); Assert.True(await mgr.IsLockedOutAsync(user)); Assert.True(await mgr.GetLockoutEndDateAsync(user) > DateTimeOffset.UtcNow.AddMinutes(55)); + IdentityResultAssert.VerifyLogMessage(mgr.Logger, $"User {await mgr.GetUserIdAsync(user)} is locked out."); Assert.Equal(0, await mgr.GetAccessFailedCountAsync(user)); } @@ -875,7 +866,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.False(await mgr.GetLockoutEndDateAsync(user) > DateTimeOffset.UtcNow.AddMinutes(55)); Assert.Equal(1, await mgr.GetAccessFailedCountAsync(user)); IdentityResultAssert.IsSuccess(await mgr.ResetAccessFailedCountAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(mgr.Logger, "ResetAccessFailedCountAsync", await mgr.GetUserIdAsync(user)); Assert.Equal(0, await mgr.GetAccessFailedCountAsync(user)); Assert.False(await mgr.IsLockedOutAsync(user)); Assert.False(await mgr.GetLockoutEndDateAsync(user) > DateTimeOffset.UtcNow.AddMinutes(55)); @@ -896,16 +886,15 @@ namespace Microsoft.AspNet.Identity.Test Assert.False(await mgr.GetLockoutEnabledAsync(user)); IdentityResultAssert.IsSuccess(await mgr.SetLockoutEnabledAsync(user, true)); Assert.True(await mgr.GetLockoutEnabledAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(mgr.Logger, "SetLockoutEnabledAsync", await mgr.GetUserIdAsync(user)); Assert.False(await mgr.IsLockedOutAsync(user)); IdentityResultAssert.IsSuccess(await mgr.AccessFailedAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(mgr.Logger, "AccessFailedAsync", await mgr.GetUserIdAsync(user)); Assert.False(await mgr.IsLockedOutAsync(user)); Assert.False(await mgr.GetLockoutEndDateAsync(user) > DateTimeOffset.UtcNow.AddMinutes(55)); Assert.Equal(1, await mgr.GetAccessFailedCountAsync(user)); IdentityResultAssert.IsSuccess(await mgr.AccessFailedAsync(user)); Assert.True(await mgr.IsLockedOutAsync(user)); Assert.True(await mgr.GetLockoutEndDateAsync(user) > DateTimeOffset.UtcNow.AddMinutes(55)); + IdentityResultAssert.VerifyLogMessage(mgr.Logger, $"User {await mgr.GetUserIdAsync(user)} is locked out."); Assert.Equal(0, await mgr.GetAccessFailedCountAsync(user)); } @@ -919,7 +908,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.True(await mgr.GetLockoutEnabledAsync(user)); IdentityResultAssert.IsSuccess(await mgr.SetLockoutEndDateAsync(user, new DateTimeOffset())); Assert.False(await mgr.IsLockedOutAsync(user)); - IdentityResultAssert.VerifyUserManagerSuccessLog(mgr.Logger, "SetLockoutEndDateAsync", await mgr.GetUserIdAsync(user)); Assert.Equal(new DateTimeOffset(), await mgr.GetLockoutEndDateAsync(user)); } @@ -932,6 +920,7 @@ namespace Microsoft.AspNet.Identity.Test Assert.False(await mgr.GetLockoutEnabledAsync(user)); IdentityResultAssert.IsFailure(await mgr.SetLockoutEndDateAsync(user, new DateTimeOffset()), "Lockout is not enabled for this user."); + IdentityResultAssert.VerifyLogMessage(mgr.Logger, $"Lockout for user {await mgr.GetUserIdAsync(user)} failed because lockout is not enabled for this user."); Assert.False(await mgr.IsLockedOutAsync(user)); } @@ -1024,8 +1013,10 @@ namespace Microsoft.AspNet.Identity.Test var manager = CreateRoleManager(); manager.RoleValidators.Clear(); manager.RoleValidators.Add(new AlwaysBadValidator()); - IdentityResultAssert.IsFailure(await manager.CreateAsync(CreateTestRole("blocked")), + var role = CreateTestRole("blocked"); + IdentityResultAssert.IsFailure(await manager.CreateAsync(role), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"Role {await manager.GetRoleIdAsync(role)} validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -1035,8 +1026,10 @@ namespace Microsoft.AspNet.Identity.Test manager.RoleValidators.Clear(); manager.RoleValidators.Add(new AlwaysBadValidator()); manager.RoleValidators.Add(new AlwaysBadValidator()); - var result = await manager.CreateAsync(CreateTestRole("blocked")); + var role = CreateTestRole("blocked"); + var result = await manager.CreateAsync(role); IdentityResultAssert.IsFailure(result, AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"Role {await manager.GetRoleIdAsync(role)} validation failed: {AlwaysBadValidator.ErrorMessage.Code};{AlwaysBadValidator.ErrorMessage.Code}."); Assert.Equal(2, result.Errors.Count()); } @@ -1050,7 +1043,7 @@ namespace Microsoft.AspNet.Identity.Test manager.RoleValidators.Clear(); manager.RoleValidators.Add(new AlwaysBadValidator()); IdentityResultAssert.IsFailure(await manager.UpdateAsync(role), error); - IdentityResultAssert.VerifyRoleManagerFailureLog(manager.Logger, "UpdateAsync", await manager.GetRoleIdAsync(role), AlwaysBadValidator.ErrorMessage); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"Role {await manager.GetRoleIdAsync(role)} validation failed: {AlwaysBadValidator.ErrorMessage.Code}."); } [Fact] @@ -1064,7 +1057,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.True(await manager.RoleExistsAsync(roleName)); IdentityResultAssert.IsSuccess(await manager.DeleteAsync(role)); Assert.False(await manager.RoleExistsAsync(roleName)); - IdentityResultAssert.VerifyRoleManagerSuccessLog(manager.Logger, "DeleteAsync", await manager.GetRoleIdAsync(role)); } [Fact] @@ -1078,7 +1070,6 @@ namespace Microsoft.AspNet.Identity.Test { IdentityResultAssert.IsSuccess(await manager.AddClaimAsync(role, c)); } - IdentityResultAssert.VerifyRoleManagerSuccessLog(manager.Logger, "AddClaimAsync", await manager.GetRoleIdAsync(role)); var roleClaims = await manager.GetClaimsAsync(role); Assert.Equal(3, roleClaims.Count); IdentityResultAssert.IsSuccess(await manager.RemoveClaimAsync(role, claims[0])); @@ -1090,8 +1081,6 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.RemoveClaimAsync(role, claims[2])); roleClaims = await manager.GetClaimsAsync(role); Assert.Equal(0, roleClaims.Count); - - IdentityResultAssert.VerifyRoleManagerSuccessLog(manager.Logger, "RemoveClaimAsync", await manager.GetRoleIdAsync(role)); } [Fact] @@ -1127,7 +1116,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.True(await manager.RoleExistsAsync(roleName)); IdentityResultAssert.IsSuccess(await manager.SetRoleNameAsync(role, "Changed")); IdentityResultAssert.IsSuccess(await manager.UpdateAsync(role)); - IdentityResultAssert.VerifyRoleManagerSuccessLog(manager.Logger, "UpdateAsync", await manager.GetRoleIdAsync(role)); Assert.False(await manager.RoleExistsAsync("update")); Assert.Equal(role, await manager.FindByNameAsync("Changed")); } @@ -1200,7 +1188,6 @@ namespace Microsoft.AspNet.Identity.Test var role = CreateTestRole(roleName, useRoleNamePrefixAsRoleName: true); Assert.False(await manager.RoleExistsAsync(roleName)); IdentityResultAssert.IsSuccess(await manager.CreateAsync(role)); - IdentityResultAssert.VerifyRoleManagerSuccessLog(manager.Logger, "CreateAsync", await manager.GetRoleIdAsync(role)); Assert.True(await manager.RoleExistsAsync(roleName)); var role2 = CreateTestRole(roleName, useRoleNamePrefixAsRoleName: true); IdentityResultAssert.IsFailure(await manager.CreateAsync(role2)); @@ -1224,8 +1211,6 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await manager.CreateAsync(u)); IdentityResultAssert.IsSuccess(await manager.AddToRoleAsync(u, roleName)); Assert.True(await manager.IsInRoleAsync(u, roleName)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "AddToRoleAsync", await manager.GetUserIdAsync(u)); - } } @@ -1279,7 +1264,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.True(await userManager.IsInRoleAsync(user, await roleManager.GetRoleNameAsync(r))); } IdentityResultAssert.IsSuccess(await userManager.RemoveFromRoleAsync(user, await roleManager.GetRoleNameAsync(roles[2]))); - IdentityResultAssert.VerifyUserManagerSuccessLog(userManager.Logger, "RemoveFromRoleAsync", await userManager.GetUserIdAsync(user)); Assert.False(await userManager.IsInRoleAsync(user, await roleManager.GetRoleNameAsync(roles[2]))); } @@ -1321,7 +1305,7 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await roleMgr.CreateAsync(role)); var result = await userMgr.RemoveFromRoleAsync(user, roleName); IdentityResultAssert.IsFailure(result, _errorDescriber.UserNotInRole(roleName)); - IdentityResultAssert.VerifyUserManagerFailureLog(userMgr.Logger, "RemoveFromRoleAsync", await userMgr.GetUserIdAsync(user), _errorDescriber.UserNotInRole(roleName)); + IdentityResultAssert.VerifyLogMessage(userMgr.Logger, $"User {await userMgr.GetUserIdAsync(user)} is not in role {roleName}."); } [Fact] @@ -1338,7 +1322,7 @@ namespace Microsoft.AspNet.Identity.Test IdentityResultAssert.IsSuccess(await userMgr.AddToRoleAsync(user, roleName)); Assert.True(await userMgr.IsInRoleAsync(user, roleName)); IdentityResultAssert.IsFailure(await userMgr.AddToRoleAsync(user, roleName), _errorDescriber.UserAlreadyInRole(roleName)); - IdentityResultAssert.VerifyUserManagerFailureLog(userMgr.Logger, "AddToRoleAsync", await userMgr.GetUserIdAsync(user), _errorDescriber.UserAlreadyInRole(roleName)); + IdentityResultAssert.VerifyLogMessage(userMgr.Logger, $"User {await userMgr.GetUserIdAsync(user)} is already in role {roleName}."); } [Fact] @@ -1384,7 +1368,6 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); var token1 = await manager.GenerateChangePhoneNumberTokenAsync(user, "111-111-1111"); IdentityResultAssert.IsSuccess(await manager.ChangePhoneNumberAsync(user, "111-111-1111", token1)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "ChangePhoneNumberAsync", await manager.GetUserIdAsync(user)); Assert.True(await manager.IsPhoneNumberConfirmedAsync(user)); Assert.Equal(await manager.GetPhoneNumberAsync(user), "111-111-1111"); Assert.NotEqual(stamp, await manager.GetSecurityStampAsync(user)); @@ -1400,7 +1383,7 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); IdentityResultAssert.IsFailure(await manager.ChangePhoneNumberAsync(user, "111-111-1111", "bogus"), "Invalid token."); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ChangePhoneNumberAsync", await manager.GetUserIdAsync(user), _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyChangePhoneNumberTokenAsync() failed for user {await manager.GetUserIdAsync(user)}."); Assert.False(await manager.IsPhoneNumberConfirmedAsync(user)); Assert.Equal(await manager.GetPhoneNumberAsync(user), "123-456-7890"); Assert.Equal(stamp, await manager.GetSecurityStampAsync(user)); @@ -1432,16 +1415,14 @@ namespace Microsoft.AspNet.Identity.Test const string num2 = "111-111-1111"; var userId = await manager.GetUserIdAsync(user); var token1 = await manager.GenerateChangePhoneNumberTokenAsync(user, num1); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "GenerateChangePhoneNumberTokenAsync", userId); var token2 = await manager.GenerateChangePhoneNumberTokenAsync(user, num2); Assert.NotEqual(token1, token2); Assert.True(await manager.VerifyChangePhoneNumberTokenAsync(user, token1, num1)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "VerifyChangePhoneNumberTokenAsync", userId); Assert.True(await manager.VerifyChangePhoneNumberTokenAsync(user, token2, num2)); Assert.False(await manager.VerifyChangePhoneNumberTokenAsync(user, token2, num1)); Assert.False(await manager.VerifyChangePhoneNumberTokenAsync(user, token1, num2)); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "VerifyChangePhoneNumberTokenAsync", userId, _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyChangePhoneNumberTokenAsync() failed for user {await manager.GetUserIdAsync(user)}."); } [Fact] @@ -1457,7 +1438,6 @@ namespace Microsoft.AspNet.Identity.Test var newEmail = await manager.GetUserNameAsync(user) + "@en.vec"; var token1 = await manager.GenerateChangeEmailTokenAsync(user, newEmail); IdentityResultAssert.IsSuccess(await manager.ChangeEmailAsync(user, newEmail, token1)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "ChangeEmailAsync", await manager.GetUserIdAsync(user)); Assert.True(await manager.IsEmailConfirmedAsync(user)); Assert.Equal(await manager.GetEmailAsync(user), newEmail); Assert.NotEqual(stamp, await manager.GetSecurityStampAsync(user)); @@ -1476,7 +1456,7 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); IdentityResultAssert.IsFailure(await manager.ChangeEmailAsync(user, "whatevah@foo.barf", "bogus"), "Invalid token."); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "ChangeEmailAsync", await manager.GetUserIdAsync(user), _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: ChangeEmail:whatevah@foo.barf for user { await manager.GetUserIdAsync(user)}."); Assert.False(await manager.IsEmailConfirmedAsync(user)); Assert.Equal(await manager.GetEmailAsync(user), oldEmail); Assert.Equal(stamp, await manager.GetSecurityStampAsync(user)); @@ -1496,6 +1476,7 @@ namespace Microsoft.AspNet.Identity.Test var token1 = await manager.GenerateChangeEmailTokenAsync(user, "forgot@alrea.dy"); IdentityResultAssert.IsFailure(await manager.ChangeEmailAsync(user, "oops@foo.barf", token1), "Invalid token."); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyUserTokenAsync() failed with purpose: ChangeEmail:oops@foo.barf for user { await manager.GetUserIdAsync(user)}."); Assert.False(await manager.IsEmailConfirmedAsync(user)); Assert.Equal(await manager.GetEmailAsync(user), oldEmail); Assert.Equal(stamp, await manager.GetSecurityStampAsync(user)); @@ -1519,6 +1500,7 @@ namespace Microsoft.AspNet.Identity.Test Assert.NotNull(token); IdentityResultAssert.IsSuccess(await manager.UpdateSecurityStampAsync(user)); Assert.False(await manager.VerifyTwoFactorTokenAsync(user, factorId, token)); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyTwoFactorTokenAsync() failed for user {await manager.GetUserIdAsync(user)}."); } [Fact] @@ -1530,7 +1512,6 @@ namespace Microsoft.AspNet.Identity.Test var stamp = await manager.GetSecurityStampAsync(user); Assert.NotNull(stamp); IdentityResultAssert.IsSuccess(await manager.SetTwoFactorEnabledAsync(user, true)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "SetTwoFactorEnabledAsync", await manager.GetUserIdAsync(user)); Assert.NotEqual(stamp, await manager.GetSecurityStampAsync(user)); Assert.True(await manager.GetTwoFactorEnabledAsync(user)); } @@ -1571,7 +1552,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.NotNull(factors); Assert.False(factors.Any()); IdentityResultAssert.IsSuccess(await manager.SetPhoneNumberAsync(user, "111-111-1111")); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "SetPhoneNumberAsync", userId); var token = await manager.GenerateChangePhoneNumberTokenAsync(user, "111-111-1111"); IdentityResultAssert.IsSuccess(await manager.ChangePhoneNumberAsync(user, "111-111-1111", token)); await manager.UpdateAsync(user); @@ -1580,7 +1560,6 @@ namespace Microsoft.AspNet.Identity.Test Assert.Equal(1, factors.Count()); Assert.Equal("Phone", factors[0]); IdentityResultAssert.IsSuccess(await manager.SetEmailAsync(user, "test@test.com")); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "SetEmailAsync", userId); token = await manager.GenerateEmailConfirmationTokenAsync(user); await manager.ConfirmEmailAsync(user, token); factors = await manager.GetValidTwoFactorProvidersAsync(user); @@ -1606,6 +1585,7 @@ namespace Microsoft.AspNet.Identity.Test Assert.NotNull(token); IdentityResultAssert.IsSuccess(await manager.UpdateSecurityStampAsync(user)); Assert.False(await manager.VerifyTwoFactorTokenAsync(user, factorId, token)); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyTwoFactorTokenAsync() failed for user {await manager.GetUserIdAsync(user)}."); } [Fact] @@ -1617,6 +1597,7 @@ namespace Microsoft.AspNet.Identity.Test var token = await manager.GenerateTwoFactorTokenAsync(user, "Phone"); Assert.NotNull(token); Assert.False(await manager.VerifyTwoFactorTokenAsync(user, "Email", token)); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyTwoFactorTokenAsync() failed for user {await manager.GetUserIdAsync(user)}."); } [Fact] @@ -1626,7 +1607,7 @@ namespace Microsoft.AspNet.Identity.Test var user = CreateTestUser(phoneNumber: "4251234567"); IdentityResultAssert.IsSuccess(await manager.CreateAsync(user)); Assert.False(await manager.VerifyTwoFactorTokenAsync(user, "Phone", "bogus")); - IdentityResultAssert.VerifyUserManagerFailureLog(manager.Logger, "VerifyTwoFactorTokenAsync", await manager.GetUserIdAsync(user), _errorDescriber.InvalidToken()); + IdentityResultAssert.VerifyLogMessage(manager.Logger, $"VerifyTwoFactorTokenAsync() failed for user {await manager.GetUserIdAsync(user)}."); } [Fact] @@ -1691,7 +1672,6 @@ namespace Microsoft.AspNet.Identity.Test if ((i % 2) == 0) { IdentityResultAssert.IsSuccess(await manager.AddToRolesAsync(user, roleNameList)); - IdentityResultAssert.VerifyUserManagerSuccessLog(manager.Logger, "AddToRolesAsync", await manager.GetUserIdAsync(user)); } }