Skip to content

Commit

Permalink
Update logging following conventions (#199)
Browse files Browse the repository at this point in the history
Update logging following conventions in all project classes:
* Use PascalCase for named placeholders. in log messages
* Exception handling: No more logging, but instead rethrow it with some contextual information
* Update unit tests accordingly
  • Loading branch information
axunonb authored Oct 6, 2024
1 parent ae8b50f commit 048729e
Show file tree
Hide file tree
Showing 56 changed files with 188 additions and 213 deletions.
11 changes: 4 additions & 7 deletions Axuno.BackgroundTask/BackgroundQueue.cs
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ public void QueueTask(IBackgroundTask taskItem)

TaskItems.Enqueue(taskItem);
_signal.Release(); // increase the semaphore count for each item
_logger.LogDebug("Number of queued TaskItems is {taskItemCount}", _signal.CurrentCount);
_logger.LogDebug("Number of queued TaskItems is {TaskItemCount}", _signal.CurrentCount);
}

/// <summary>
Expand All @@ -46,7 +46,7 @@ public void QueueTask(IBackgroundTask taskItem)
/// <returns>Returns the next <see cref="IBackgroundTask"/> from the queue.</returns>
public IBackgroundTask DequeueTask()
{
if (TaskItems.TryDequeue(out var nextTaskItem))
if (TaskItems.TryDequeue(out var nextTaskItem))
return nextTaskItem;

_logger.LogDebug("No TaskItem could be dequeued.");
Expand All @@ -72,20 +72,17 @@ public async Task RunTaskAsync(IBackgroundTask? task, CancellationToken cancella
}
catch (Exception e) when (e is TaskCanceledException || e is OperationCanceledException)
{
_logger.LogError(e, $"Task canceled when executing a {nameof(IBackgroundTask)}.");
// _onException will deliberately not be called
throw;
}
catch (Exception e) when (e is TimeoutException)
{
_logger.LogError(e, $"Task timed out.");
_onException?.Invoke(e);
_onException.Invoke(e);
throw;
}
catch (Exception e)
{
_logger.LogError(e, $"Exception when executing a {nameof(IBackgroundTask)}. ");
_onException?.Invoke(e);
_onException.Invoke(e);
throw;
}
finally
Expand Down
1 change: 0 additions & 1 deletion League.Demo/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -57,7 +57,6 @@ public static async Task Main(string[] args)
catch (Exception e)
{
logger.Fatal(e, "Application stopped after Exception.");
throw;
}
finally
{
Expand Down
1 change: 1 addition & 0 deletions League.Demo/Seed/Create-Db-Objects.sql
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
/* @Generated by a tool */
/****** Object: UserDefinedFunction [dbo].[GetSetsAsText] Script Date: 06.08.2023 20:51:06 ******/
SET ANSI_NULLS ON
GO
Expand Down
1 change: 1 addition & 0 deletions League.Demo/Seed/Insert-Initial-Data.sql
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
/* @Generated by a tool */
/* Data for the 'dbo.IdentityRole' table (Records 1 - 2) */

SET IDENTITY_INSERT dbo.IdentityRole ON;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ namespace League.WebApp.ViewComponents;
public class CustomMainNavigationNodeBuilder : MainNavigationNodeBuilder
{
/// <inheritdoc />
public CustomMainNavigationNodeBuilder(TenantStore tenantStore, ITenantContext tenantContext, IAuthorizationService authorizationService, TenantLink tenantUrlHelper, IStringLocalizer<MainNavigationNodeBuilder> localizer, ILogger<MainNavigationNodeBuilder> logger) : base(tenantStore, tenantContext, authorizationService, tenantUrlHelper, localizer, logger)
public CustomMainNavigationNodeBuilder(TenantStore tenantStore, ITenantContext tenantContext, IAuthorizationService authorizationService, TenantLink tenantUrlHelper, IStringLocalizer<CustomMainNavigationNodeBuilder> localizer, ILogger<MainNavigationNodeBuilder> logger) : base(tenantStore, tenantContext, authorizationService, tenantUrlHelper, localizer, logger)
{ }

/// <inheritdoc />
Expand Down
4 changes: 2 additions & 2 deletions League.Tests/Identity/RoleStoreTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -131,8 +131,8 @@ await da.ExecuteSQLAsync(CancellationToken.None,
_appDb.DbContext.CommandTimeOut = 2;
// new claim
var claim = new Claim(Constants.ClaimType.ManagesTeam, "y", "z");
Assert.ThrowsAsync<ORMQueryExecutionException>(() => _roleStore.AddClaimAsync(role, claim, CancellationToken.None));
Assert.ThrowsAsync<ORMQueryExecutionException>(() => _roleStore.RemoveClaimAsync(role, claim, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(() => _roleStore.AddClaimAsync(role, claim, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(() => _roleStore.RemoveClaimAsync(role, claim, CancellationToken.None));
da.Rollback("transaction1");
}
_appDb.DbContext.CommandTimeOut = currentTimeOut;
Expand Down
2 changes: 1 addition & 1 deletion League.Tests/Identity/UserAuthenticationTokenStoreTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -108,7 +108,7 @@ await da.ExecuteSQLAsync(CancellationToken.None,
$"SELECT 1 FROM [{_appDb.DbContext.Schema}].[{da.GetPersistentTableName(new IdentityUserLoginEntity())}] WITH (TABLOCKX)");
// Trying to update will fail because the table is locked
_appDb.DbContext.CommandTimeOut = 2;
Assert.ThrowsAsync<ORMQueryExecutionException>(async () => await _store.SetTokenAsync(GetNewUser(), "Provider", "TokenName", "TheValue", CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.SetTokenAsync(GetNewUser(), "Provider", "TokenName", "TheValue", CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.RemoveTokenAsync(GetNewUser(), "Provider", "TokenName", CancellationToken.None));
da.Rollback("transaction1");
}
Expand Down
18 changes: 9 additions & 9 deletions League.Tests/Identity/UserClaimStoreTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -69,9 +69,9 @@ await da.ExecuteSQLAsync(CancellationToken.None,
_appDb.DbContext.CommandTimeOut = 2;
// new claim
var claim = new Claim("type", "value", "valueType", "issuer");
Assert.ThrowsAsync<ORMQueryExecutionException>(async () => await _store.AddClaimsAsync(_user, new[] { claim }, CancellationToken.None));
Assert.ThrowsAsync<ORMQueryExecutionException>(async () => await _store.RemoveClaimsAsync(_user, new[] { claim }, CancellationToken.None));
Assert.ThrowsAsync<ORMQueryExecutionException>(async () => await _store.ReplaceClaimAsync(_user, claim, claim, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.AddClaimsAsync(_user, new[] { claim }, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.RemoveClaimsAsync(_user, new[] { claim }, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.ReplaceClaimAsync(_user, claim, claim, CancellationToken.None));
da.Rollback("transaction1");
}
_appDb.DbContext.CommandTimeOut = currentTimeOut;
Expand Down Expand Up @@ -148,10 +148,10 @@ public async Task Add_and_Remove_Manager_Claim()
var claim = new Claim(Constants.ClaimType.ManagesTeam, _team.Id.ToString());
await _store.AddClaimsAsync(_user, new[] { claim }, CancellationToken.None);
// non-existent team should throw
Assert.ThrowsAsync<ArgumentException>(() => _store.AddClaimsAsync(_user,
Assert.ThrowsAsync<InvalidOperationException>(() => _store.AddClaimsAsync(_user,
new [] {new Claim(Constants.ClaimType.ManagesTeam, "0")}, CancellationToken.None));
// not implemented claim - should throw
Assert.ThrowsAsync<NotImplementedException>(() => _store.AddClaimsAsync(_user,
Assert.ThrowsAsync<InvalidOperationException>(() => _store.AddClaimsAsync(_user,
new [] { new Claim(Constants.ClaimType.NotImplementedClaim, _team.Id.ToString()) }, CancellationToken.None));

// same manager claim again - should not be added
Expand All @@ -165,10 +165,10 @@ public async Task Add_and_Remove_Manager_Claim()
claims = await _store.GetClaimsAsync(_user, CancellationToken.None);
Assert.That(claims.FirstOrDefault(c => c.Type == claim.Type && c.Value == claim.Value), Is.EqualTo(null));
// non-existent team should throw
Assert.ThrowsAsync<ArgumentException>(() => _store.RemoveClaimsAsync(_user,
Assert.ThrowsAsync<InvalidOperationException>(() => _store.RemoveClaimsAsync(_user,
new [] { new Claim(Constants.ClaimType.ManagesTeam, "0") }, CancellationToken.None));
// not implemented claim - should throw
Assert.ThrowsAsync<NotImplementedException>(() => _store.RemoveClaimsAsync(_user,
Assert.ThrowsAsync<InvalidOperationException>(() => _store.RemoveClaimsAsync(_user,
new [] { new Claim(Constants.ClaimType.NotImplementedClaim, _team.Id.ToString()) }, CancellationToken.None));

// replace manager should fail
Expand Down Expand Up @@ -229,14 +229,14 @@ public void Add_and_Replace_and_Remove_Programmatic_Claim()
{
// Programmatic claims cannot be stored
var claim = new Claim(Constants.ClaimType.ImpersonatedByUser, "123", "valueType", "issuer");
Assert.ThrowsAsync<ArgumentException>(() => _store.AddClaimsAsync(_user, new []{claim}, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(() => _store.AddClaimsAsync(_user, new []{claim}, CancellationToken.None));

// Programmatic claims cannot be replaced
Assert.ThrowsAsync<ArgumentException>(() => _store.ReplaceClaimAsync(_user, claim, new Claim("type", "value"), CancellationToken.None));
Assert.ThrowsAsync<ArgumentException>(() => _store.ReplaceClaimAsync(_user, new Claim("type", "value"), claim, CancellationToken.None));

// Programmatic claims cannot be removed
Assert.ThrowsAsync<ArgumentException>(() => _store.RemoveClaimsAsync(_user, new []{ claim }, CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(() => _store.RemoveClaimsAsync(_user, new []{ claim }, CancellationToken.None));
}

#endregion
Expand Down
4 changes: 2 additions & 2 deletions League.Tests/Identity/UserLoginStoreTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -126,8 +126,8 @@ await da.ExecuteSQLAsync(CancellationToken.None,
$"SELECT 1 FROM [{_appDb.DbContext.Schema}].[{da.GetPersistentTableName(new IdentityUserLoginEntity())}] WITH (TABLOCKX)");
// Trying to update will fail because the table is locked
_appDb.DbContext.CommandTimeOut = 2;
Assert.ThrowsAsync<ORMQueryExecutionException>(async () => await _store.AddLoginAsync(GetNewUser(), GetUserLoginInfo() , CancellationToken.None));
Assert.ThrowsAsync<ORMQueryExecutionException>(async () => await _store.RemoveLoginAsync(GetNewUser(), "x", "y", CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.AddLoginAsync(GetNewUser(), GetUserLoginInfo() , CancellationToken.None));
Assert.ThrowsAsync<InvalidOperationException>(async () => await _store.RemoveLoginAsync(GetNewUser(), "x", "y", CancellationToken.None));
da.Rollback("transaction1");
}
_appDb.DbContext.CommandTimeOut = currentTimeOut;
Expand Down
2 changes: 1 addition & 1 deletion League.Tests/TestComponents/UnitTestHelpers.cs
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ public UserStore GetUserStore()

public RoleStore GetRoleStore()
{
return new RoleStore(_tenantContext, new NullLogger<UserStore>(), new UpperInvariantLookupNormalizer(), new Mock<MultiLanguageIdentityErrorDescriber>(null!).Object);
return new League.Identity.RoleStore(_tenantContext, new NullLogger<League.Identity.RoleStore>(), new UpperInvariantLookupNormalizer(), new Mock<MultiLanguageIdentityErrorDescriber>(null!).Object);
}

public ServiceProvider GetStandardServiceProvider()
Expand Down
4 changes: 2 additions & 2 deletions League/ApiControllers/Cron.cs
Original file line number Diff line number Diff line change
Expand Up @@ -89,7 +89,7 @@ public async Task<IActionResult> RunAllAutoMails(string key)
}
catch (AggregateException e)
{
_logger.LogCritical("Failure invoking automail urls. {exception}", e);
_logger.LogCritical(e, "Failure invoking automail Urls.");
}

return Ok(results);
Expand Down Expand Up @@ -227,7 +227,7 @@ private async Task<InvocationResult> InvokeUrl(string urlSegmentValue)
routeValues, scheme: Uri.UriSchemeHttps) ?? string.Empty;

var result = await httpClient.GetAsync(url);
_logger.LogInformation("Get request for url '{url}' completed.", url);
_logger.LogInformation("Get request for url '{Url}' completed.", url);
return new InvocationResult
{
Success = true, Url = url,
Expand Down
6 changes: 3 additions & 3 deletions League/Areas/Admin/Controllers/Impersonation.cs
Original file line number Diff line number Diff line change
Expand Up @@ -15,11 +15,11 @@ namespace League.Areas.Admin.Controllers;
[Route(TenantRouteConstraint.Template + "/[area]/[controller]")]
public class Impersonation : AbstractController
{
private readonly ILogger<Language> _logger;
private readonly ILogger<Impersonation> _logger;
private readonly SignInManager<ApplicationUser> _signInManager;
private readonly ITenantContext _tenantContext;

public Impersonation(SignInManager<ApplicationUser> signInManager, ITenantContext tenantContext, ILogger<Language> logger)
public Impersonation(SignInManager<ApplicationUser> signInManager, ITenantContext tenantContext, ILogger<Impersonation> logger)
{
_signInManager = signInManager;
_tenantContext = tenantContext;
Expand Down Expand Up @@ -65,7 +65,7 @@ public async Task<IActionResult> Start(long id)

// impersonate the target user
await _signInManager.Context.SignInAsync(IdentityConstants.ApplicationScheme, targetClaimsPrincipal);
_logger.LogInformation("User '{user}' now impersonates user '{targetUser}'.",
_logger.LogInformation("User '{User}' now impersonates user '{TargetUser}'.",
currentUser.Claims.FirstOrDefault(c => c.Type == ClaimTypes.NameIdentifier)?.Value,
targetClaimsPrincipal?.Claims.FirstOrDefault(c => c.Type == ClaimTypes.NameIdentifier)?.Value);

Expand Down
21 changes: 13 additions & 8 deletions League/BackgroundTasks/SendEmailTask.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
using Axuno.TextTemplating;
using League.Emailing.Creators;
using League.Templates.Email.Localization;
using MailMergeLib;
using MailMergeLib.AspNet;
using TournamentManager.MultiTenancy;

Expand Down Expand Up @@ -53,7 +54,7 @@ public void SetMessageCreator(IMailMessageCreator mailMessageCreator)
{
_mailMessageCreator = mailMessageCreator;
}

/// <summary>
/// Invokes the <see cref="IMailMessageCreator"/> and sends the mail messages.
/// </summary>
Expand All @@ -69,18 +70,22 @@ public async Task RunAsync(CancellationToken cancellationToken)
{
await _mailMergeService.Sender.SendAsync(mmm, null);
}
catch (Exception e) when (e is TaskCanceledException || e is OperationCanceledException)
catch (Exception e) when (e is TaskCanceledException)
{
_mailMergeService.Sender.SendCancel();
throw new TaskCanceledException(
$"Sending mail canceled. {mmm.MailMergeAddresses}\nSubject: {mmm.Subject}\nMessage: {mmm.PlainText}", e, cancellationToken);
}
catch (Exception e) when (e is OperationCanceledException)
{
_logger.LogError(e, "Sending mail canceled. {recipients}\nSubject: {subject}\nMessage: {message}",
mmm.MailMergeAddresses, mmm.Subject, mmm.PlainText);
_mailMergeService.Sender.SendCancel();
throw;
throw new OperationCanceledException(
$"Sending mail canceled. {mmm.MailMergeAddresses}\nSubject: {mmm.Subject}\nMessage: {mmm.PlainText}", e, cancellationToken);
}
catch (Exception e)
{
_logger.LogError(e, "Mail sender failure. {recipients}\nSubject: {subject}\nMessage: {message}",
mmm.MailMergeAddresses, mmm.Subject, mmm.PlainText);
throw;
throw new MailMergeMessage.MailMergeMessageException(
$"Mail sender failure. {mmm.MailMergeAddresses}\nSubject: {mmm.Subject}\nMessage: {mmm.PlainText}", new []{e}, null);
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion League/Controllers/Contact.cs
Original file line number Diff line number Diff line change
Expand Up @@ -61,7 +61,7 @@ public IActionResult Index(ContactViewModel model)
}

SendEmail(model);
_logger.LogDebug("Mail sent: {@model}", model);
_logger.LogDebug("Mail sent: {Model}", model);

return _tenantContext.IsDefault
? RedirectToRoute(RouteNames.GeneralContactConfirmation)
Expand Down
8 changes: 4 additions & 4 deletions League/Controllers/Error.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ namespace League.Controllers;
public class Error : AbstractController
{
private readonly ILogger _logger;
private readonly ILogger _notFoundLogger;
private readonly ILogger _loggerNotFound; //NOSONAR
private readonly IStringLocalizer<Error> _localizer;
private readonly ITenantContext _tenantContext;

Expand All @@ -17,7 +17,7 @@ public Error(ILogger<Error> logger, IStringLocalizer<Error> localizer, ILoggerFa
_logger = logger;
_tenantContext = tenantContext;
_localizer = localizer;
_notFoundLogger = loggerFactory.CreateLogger(nameof(League) + ".NotFound");
_loggerNotFound = loggerFactory.CreateLogger(nameof(League) + ".NotFound");
}

[Route("{id?}")]
Expand All @@ -40,15 +40,15 @@ public IActionResult Index(string? id)
{
viewModel.OrigPath = exceptionFeature?.Path;
viewModel.Exception = exceptionFeature?.Error;
_logger.LogError(viewModel.Exception, "Path: {origPath}", viewModel.OrigPath);
_logger.LogError(viewModel.Exception, "Path: {OrigPath}", viewModel.OrigPath);
}
else
{
viewModel.OrigPath = HttpContext.Features
.Get<Microsoft.AspNetCore.Diagnostics.IStatusCodeReExecuteFeature>()?.OriginalPath ?? string.Empty;

if (Response.StatusCode == 404)
_notFoundLogger.LogInformation("{NotFound}", new {Status = Response.StatusCode, Ip = HttpContext.Connection.RemoteIpAddress?.ToString() ?? "127.0.0.1", Path = viewModel.OrigPath});
_loggerNotFound.LogInformation("{NotFound}", new {Status = Response.StatusCode, Ip = HttpContext.Connection.RemoteIpAddress?.ToString() ?? "127.0.0.1", Path = viewModel.OrigPath});
else
_logger.LogWarning("StatusCode: {StatusCode}, Path: {OrigPath}", Response.StatusCode, viewModel.OrigPath);
}
Expand Down
Loading

0 comments on commit 048729e

Please sign in to comment.