From f93b177b86a5b7960fd0c8979fb48b9f0b31235b Mon Sep 17 00:00:00 2001 From: Alex Macocian Date: Thu, 15 Aug 2024 13:18:18 +0200 Subject: [PATCH] Logging improvements Log to file Add correlation vector to logs Add IP to logs Add API Key to logs --- GuildWarsPartySearch/Config.Debug.json | 16 ++++--- GuildWarsPartySearch/Config.Production.json | 16 ++++--- GuildWarsPartySearch/Endpoints/LiveFeed.cs | 4 +- .../Endpoints/PostPartySearch.cs | 2 +- .../Endpoints/WebSocketRouteBase.cs | 4 +- .../Extensions/HttpContextExtensions.cs | 40 +++++++++++++++++ .../WebApplicationBuilderExtensions.cs | 6 +++ .../GuildWarsPartySearch.Server.csproj | 3 ++ GuildWarsPartySearch/Launch/Program.cs | 13 +++--- .../Launch/ServerConfiguration.cs | 35 ++++++++++++--- .../Middleware/CorrelationVectorMiddleware.cs | 24 ++++++++++ .../Middleware/HeaderLoggingMiddleware.cs | 10 ++--- .../Middleware/IPExtractingMiddleware.cs | 9 +--- .../Middleware/LoggingEnrichmentMiddleware.cs | 18 ++++++++ .../Middleware/PermissioningMiddleware.cs | 5 ++- GuildWarsPartySearch/Options/ServerOptions.cs | 3 -- .../Services/BotStatus/BotStatusService.cs | 18 ++++---- .../Services/Database/ApiKeySqliteDatabase.cs | 45 ++++++++++++++----- .../Database/BotHistorySqliteDatabase.cs | 20 ++++++--- .../Database/PartySearchSqliteDatabase.cs | 14 ++++-- .../Services/Feed/LiveFeedService.cs | 2 +- .../Services/Permissions/PermissionService.cs | 8 ++-- 22 files changed, 238 insertions(+), 77 deletions(-) create mode 100644 GuildWarsPartySearch/Middleware/CorrelationVectorMiddleware.cs create mode 100644 GuildWarsPartySearch/Middleware/LoggingEnrichmentMiddleware.cs diff --git a/GuildWarsPartySearch/Config.Debug.json b/GuildWarsPartySearch/Config.Debug.json index 990db98..e11d9fd 100644 --- a/GuildWarsPartySearch/Config.Debug.json +++ b/GuildWarsPartySearch/Config.Debug.json @@ -1,9 +1,16 @@ { "Logging": { - "LogLevel": { + "MinimumLevel": { "Default": "Debug", - "Microsoft": "Warning", - "Microsoft.Hosting.Lifetime": "Information" + "Override": { + "Microsoft": "Warning", + "Microsoft.Hosting.Lifetime": "Information", + "GuildWarsPartySearch.Server.Middleware": "Information", + "GuildWarsPartySearch.Server.Services.Permissions.PermissionService": "Information", + "GuildWarsPartySearch.Server.Services.Database": "Information", + "GuildWarsPartySearch.Server.Endpoints.LiveFeed": "Information", + "GuildWarsPartySearch.Server.Endpoints.PostPartySearch": "Debug" + } } }, "EnvironmentOptions": { @@ -12,8 +19,7 @@ "ServerOptions": { "InactivityTimeout": "0:0:5", "HeartbeatFrequency": "0:0:1", - "Port": 80, - "LogHeaders": true + "Port": 80 }, "SQLiteDatabaseOptions": { "Path": "partysearches.db" diff --git a/GuildWarsPartySearch/Config.Production.json b/GuildWarsPartySearch/Config.Production.json index 67e4792..bb91d76 100644 --- a/GuildWarsPartySearch/Config.Production.json +++ b/GuildWarsPartySearch/Config.Production.json @@ -1,9 +1,16 @@ { "Logging": { - "LogLevel": { + "MinimumLevel": { "Default": "Debug", - "Microsoft": "Warning", - "Microsoft.Hosting.Lifetime": "Information" + "Override": { + "Microsoft": "Warning", + "Microsoft.Hosting.Lifetime": "Information", + "GuildWarsPartySearch.Server.Middleware": "Information", + "GuildWarsPartySearch.Server.Services.Permissions.PermissionService": "Information", + "GuildWarsPartySearch.Server.Services.Database": "Information", + "GuildWarsPartySearch.Server.Endpoints.LiveFeed": "Information", + "GuildWarsPartySearch.Server.Endpoints.PostPartySearch": "Debug" + } } }, "EnvironmentOptions": { @@ -12,8 +19,7 @@ "ServerOptions": { "InactivityTimeout": "0:0:5", "HeartbeatFrequency": "0:0:1", - "Port": 80, - "LogHeaders": false + "Port": 80 }, "SQLiteDatabaseOptions": { "Path": "partysearches.db" diff --git a/GuildWarsPartySearch/Endpoints/LiveFeed.cs b/GuildWarsPartySearch/Endpoints/LiveFeed.cs index 26c908d..98d4088 100644 --- a/GuildWarsPartySearch/Endpoints/LiveFeed.cs +++ b/GuildWarsPartySearch/Endpoints/LiveFeed.cs @@ -45,7 +45,7 @@ await this.SendMessage(new PartySearchList public override async Task SocketAccepted(CancellationToken cancellationToken) { var ipAddress = this.Context?.Request.HttpContext.GetClientIP(); - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.SocketAccepted), ipAddress ?? string.Empty); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.SocketAccepted), string.Empty); if (!await this.liveFeedService.AddClient(this.WebSocket!, ipAddress, this.Context?.GetPermissionLevel() ?? Models.PermissionLevel.None, cancellationToken)) { scopedLogger.LogError("Client rejected"); @@ -66,7 +66,7 @@ await this.SendMessage(new PartySearchList public override Task SocketClosed() { var ipAddress = this.Context?.Request.HttpContext.GetClientIP(); - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.SocketClosed), ipAddress ?? string.Empty); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.SocketClosed), string.Empty); this.liveFeedService.RemoveClient(this.WebSocket!, ipAddress); scopedLogger.LogDebug("Client removed from livefeed"); return Task.CompletedTask; diff --git a/GuildWarsPartySearch/Endpoints/PostPartySearch.cs b/GuildWarsPartySearch/Endpoints/PostPartySearch.cs index 69b02cc..bf67ce0 100644 --- a/GuildWarsPartySearch/Endpoints/PostPartySearch.cs +++ b/GuildWarsPartySearch/Endpoints/PostPartySearch.cs @@ -77,7 +77,7 @@ public override async Task ExecuteAsync(PostPartySearchRequest? message, Cancell throw new InvalidOperationException("Unable to extract user agent on client disconnect"); } - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.ExecuteAsync), userAgent); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.ExecuteAsync), string.Empty); try { var currentBot = await this.botStatusService.GetBot(userAgent, cancellationToken); diff --git a/GuildWarsPartySearch/Endpoints/WebSocketRouteBase.cs b/GuildWarsPartySearch/Endpoints/WebSocketRouteBase.cs index e47201b..2b88a5a 100644 --- a/GuildWarsPartySearch/Endpoints/WebSocketRouteBase.cs +++ b/GuildWarsPartySearch/Endpoints/WebSocketRouteBase.cs @@ -48,7 +48,7 @@ public sealed override Task ExecuteAsync(WebSocketMessageType type, byte[] data, } catch(Exception ex) { - var scoppedLogger = this.Context!.RequestServices.GetRequiredService>().CreateScopedLogger(nameof(this.ExecuteAsync), string.Empty); + var scoppedLogger = this.Context!.RequestServices.GetRequiredService>>().CreateScopedLogger(nameof(this.ExecuteAsync), string.Empty); scoppedLogger.LogError(ex, "Failed to process data"); throw; } @@ -109,7 +109,7 @@ public Task SendMessage(TSendType sendType, CancellationToken cancellationToken) } catch(Exception ex ) { - var scoppedLogger = this.Context!.RequestServices.GetRequiredService>().CreateScopedLogger(nameof(this.SendMessage), typeof(TSendType).Name); + var scoppedLogger = this.Context!.RequestServices.GetRequiredService>>().CreateScopedLogger(nameof(this.SendMessage), string.Empty); scoppedLogger.LogError(ex, "Failed to send data"); throw; } diff --git a/GuildWarsPartySearch/Extensions/HttpContextExtensions.cs b/GuildWarsPartySearch/Extensions/HttpContextExtensions.cs index d473ae0..d49472e 100644 --- a/GuildWarsPartySearch/Extensions/HttpContextExtensions.cs +++ b/GuildWarsPartySearch/Extensions/HttpContextExtensions.cs @@ -1,10 +1,14 @@ using GuildWarsPartySearch.Server.Models; +using Microsoft.CorrelationVector; +using Serilog.Context; using System.Core.Extensions; namespace GuildWarsPartySearch.Server.Extensions; public static class HttpContextExtensions { + private const string CorrelationVectorKey = "CorrelationVector"; + private const string ApiKey = "ApiKey"; private const string PermissionLevelKey = "PermissionLevel"; private const string PermissionReasonKey = "PermissionReason"; private const string ClientIPKey = "ClientIP"; @@ -57,4 +61,40 @@ public static string GetClientIP(this HttpContext context) return ipStr; } + + public static void SetApiKey(this HttpContext context, string apiKey) + { + context.ThrowIfNull() + .Items.Add(ApiKey, apiKey); + } + + public static string GetApiKey(this HttpContext context) + { + context.ThrowIfNull(); + if (!context.Items.TryGetValue(ApiKey, out var apiKey) || + apiKey is not string apiKeyStr) + { + throw new InvalidOperationException("Unable to extract API Key from context"); + } + + return apiKeyStr; + } + + public static void SetCorrelationVector(this HttpContext context, CorrelationVector cv) + { + context.ThrowIfNull() + .Items.Add(CorrelationVectorKey, cv); + } + + public static CorrelationVector GetCorrelationVector(this HttpContext context) + { + context.ThrowIfNull(); + if (!context.Items.TryGetValue(CorrelationVectorKey, out var cvVal) || + cvVal is not CorrelationVector cv) + { + throw new InvalidOperationException("Unable to extract API Key from context"); + } + + return cv; + } } diff --git a/GuildWarsPartySearch/Extensions/WebApplicationBuilderExtensions.cs b/GuildWarsPartySearch/Extensions/WebApplicationBuilderExtensions.cs index bf96684..039d753 100644 --- a/GuildWarsPartySearch/Extensions/WebApplicationBuilderExtensions.cs +++ b/GuildWarsPartySearch/Extensions/WebApplicationBuilderExtensions.cs @@ -14,6 +14,12 @@ public static WebApplicationBuilder ConfigureExtended(this WebApplicat return builder; } + public static IConfigurationSection GetRequiredSection(this ConfigurationManager configurationManager) + { + configurationManager.ThrowIfNull(); + return configurationManager.GetRequiredSection(GetOptionsName()); + } + private static string GetOptionsName() { var maybeAttribute = typeof(TOptions).GetCustomAttributes(false).OfType().FirstOrDefault(); diff --git a/GuildWarsPartySearch/GuildWarsPartySearch.Server.csproj b/GuildWarsPartySearch/GuildWarsPartySearch.Server.csproj index 1d239d4..c49e943 100644 --- a/GuildWarsPartySearch/GuildWarsPartySearch.Server.csproj +++ b/GuildWarsPartySearch/GuildWarsPartySearch.Server.csproj @@ -14,7 +14,10 @@ + + + diff --git a/GuildWarsPartySearch/Launch/Program.cs b/GuildWarsPartySearch/Launch/Program.cs index ec68aba..b7b6fbf 100644 --- a/GuildWarsPartySearch/Launch/Program.cs +++ b/GuildWarsPartySearch/Launch/Program.cs @@ -1,5 +1,6 @@ // See https://aka.ms/new-console-template for more information using App.Metrics; +using GuildWarsPartySearch.Server.Extensions; using GuildWarsPartySearch.Server.Middleware; using GuildWarsPartySearch.Server.Options; using Microsoft.Extensions.FileProviders; @@ -26,9 +27,9 @@ private static async Task Main() builder.Configuration.AddConfiguration(config); - var options = builder.Configuration.GetRequiredSection(nameof(ServerOptions)).Get(); - var environmentOptions = builder.Configuration.GetRequiredSection(nameof(EnvironmentOptions)).Get()!; - var contentOptions = builder.Configuration.GetRequiredSection(nameof(ContentOptions)).Get()!; + var options = builder.Configuration.GetRequiredSection().Get(); + var environmentOptions = builder.Configuration.GetRequiredSection().Get()!; + var contentOptions = builder.Configuration.GetRequiredSection().Get()!; builder.Environment.EnvironmentName = environmentOptions.Name?.ThrowIfNull()!; @@ -56,7 +57,7 @@ private static async Task Main() c.EnableAnnotations(); }); builder.Services.AddSingleton(jsonOptions); - builder.Logging.SetupLogging(); + builder.Logging.SetupLogging(config); builder.Services.SetupServices(); builder.Services.AddControllers(); builder.Services.AddMetrics(metrics); @@ -78,8 +79,10 @@ private static async Task Main() } var app = builder.Build(); - app.UseMiddleware() + app.UseMiddleware() + .UseMiddleware() .UseMiddleware() + .UseMiddleware() .UseMiddleware() .UseSwagger() .UseWebSockets() diff --git a/GuildWarsPartySearch/Launch/ServerConfiguration.cs b/GuildWarsPartySearch/Launch/ServerConfiguration.cs index 6c7c0a6..81b6d13 100644 --- a/GuildWarsPartySearch/Launch/ServerConfiguration.cs +++ b/GuildWarsPartySearch/Launch/ServerConfiguration.cs @@ -13,6 +13,9 @@ using GuildWarsPartySearch.Server.Services.Processing; using Microsoft.Data.Sqlite; using Microsoft.Extensions.Options; +using Serilog; +using Serilog.Settings.Configuration; +using Serilog.Sinks.File; using System.Core.Extensions; using System.Extensions; using System.Text.Json.Serialization; @@ -38,18 +41,34 @@ public static WebApplicationBuilder SetupHostedServices(this WebApplicationBuild public static IConfigurationBuilder SetupConfiguration(this IConfigurationBuilder builder) { builder.ThrowIfNull() - .SetBasePath(Path.GetDirectoryName(System.Reflection.Assembly.GetEntryAssembly()?.Location) ?? throw new InvalidOperationException("Unable to figure out base directory")) + .SetBasePath(GetBasePath()) .AddJsonFile("Config.json", false) .AddEnvironmentVariables(); return builder; } - public static ILoggingBuilder SetupLogging(this ILoggingBuilder builder) + public static ILoggingBuilder SetupLogging(this ILoggingBuilder builder, IConfigurationRoot config) { builder.ThrowIfNull() .ClearProviders() - .AddConsole(o => o.TimestampFormat = "[yyyy-MM-dd HH:mm:ss] "); + .AddSerilog(logger: new LoggerConfiguration() + .ReadFrom.Configuration(config, readerOptions: new ConfigurationReaderOptions + { + SectionName = "Logging" + }) + .Enrich.FromLogContext() + .WriteTo.Console( + outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss}] {Level:u4}: [{ClientIP}] [{ApiKey}] [{CorrelationVector}] [{SourceContext}]{NewLine}{Message:lj}{NewLine}{Exception}", + theme: Serilog.Sinks.SystemConsole.Themes.SystemConsoleTheme.Colored) + .WriteTo.File( + path: Path.Combine(GetBasePath(), "logs/log-.txt"), + rollingInterval: RollingInterval.Day, + retainedFileCountLimit: 7, + fileSizeLimitBytes: 10 * 1024 * 1024, + rollOnFileSizeLimit: true, + outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss}] {Level:u4}: [{ClientIP}] [{ApiKey}] [{CorrelationVector}] [{SourceContext}] - {Message:lj}{NewLine}{Exception}") + .CreateLogger()); return builder; } @@ -76,8 +95,7 @@ public static IServiceCollection SetupServices(this IServiceCollection services) services.AddSingleton(sp => { var options = sp.GetRequiredService>(); - var absolutePath = Path.Combine( - Path.GetDirectoryName(System.Reflection.Assembly.GetEntryAssembly()?.Location) ?? throw new InvalidOperationException("Unable to figure out base directory"), options.Value.Path); + var absolutePath = Path.Combine(GetBasePath(), options.Value.Path); SQLitePCL.raw.SetProvider(new SQLitePCL.SQLite3Provider_e_sqlite3()); var connection = new SqliteConnection($"Data Source={absolutePath}"); connection.Open(); @@ -90,9 +108,11 @@ public static IServiceCollection SetupServices(this IServiceCollection services) services.AddScoped(); services.AddScoped(); services.AddScoped(); + services.AddScoped(); services.AddScoped(); services.AddScoped(); services.AddScoped(); + services.AddScoped(); services.AddScoped(); services.AddScoped(); services.AddScoped(); @@ -107,4 +127,9 @@ public static WebApplication SetupRoutes(this WebApplication app) return app; } + + private static string GetBasePath() + { + return Path.GetDirectoryName(System.Reflection.Assembly.GetEntryAssembly()?.Location) ?? throw new InvalidOperationException("Unable to get base path"); + } } diff --git a/GuildWarsPartySearch/Middleware/CorrelationVectorMiddleware.cs b/GuildWarsPartySearch/Middleware/CorrelationVectorMiddleware.cs new file mode 100644 index 0000000..6052699 --- /dev/null +++ b/GuildWarsPartySearch/Middleware/CorrelationVectorMiddleware.cs @@ -0,0 +1,24 @@ + +using GuildWarsPartySearch.Server.Extensions; +using Microsoft.CorrelationVector; + +namespace GuildWarsPartySearch.Server.Middleware; + +public sealed class CorrelationVectorMiddleware : IMiddleware +{ + private const string CorrelationVectorHeader = "X-Correlation-Vector"; + + public Task InvokeAsync(HttpContext context, RequestDelegate next) + { + var cv = new CorrelationVector(); + if (context.Items.TryGetValue(CorrelationVectorHeader, out var correlationVectorVal) && + correlationVectorVal is string correlationVectorStr) + { + cv = CorrelationVector.Parse(correlationVectorStr); + cv.Increment(); + } + + context.SetCorrelationVector(cv); + return next(context); + } +} diff --git a/GuildWarsPartySearch/Middleware/HeaderLoggingMiddleware.cs b/GuildWarsPartySearch/Middleware/HeaderLoggingMiddleware.cs index 6eccbf0..d8f9414 100644 --- a/GuildWarsPartySearch/Middleware/HeaderLoggingMiddleware.cs +++ b/GuildWarsPartySearch/Middleware/HeaderLoggingMiddleware.cs @@ -21,13 +21,9 @@ public HeaderLoggingMiddleware( public async Task InvokeAsync(HttpContext context, RequestDelegate next) { - if (this.options.LogHeaders) - { - var clientIp = context.Request.HttpContext.GetClientIP(); - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InvokeAsync), clientIp); - scopedLogger.LogDebug(string.Join("\n", context.Request.Headers.Select(kvp => $"{kvp.Key}: {string.Join(",", kvp.Value.OfType())}"))); - } - + var clientIp = context.Request.HttpContext.GetClientIP(); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InvokeAsync), string.Empty); + scopedLogger.LogDebug(string.Join("\n", context.Request.Headers.Select(kvp => $"{kvp.Key}: {string.Join(",", kvp.Value.OfType())}"))); await next(context); } } diff --git a/GuildWarsPartySearch/Middleware/IPExtractingMiddleware.cs b/GuildWarsPartySearch/Middleware/IPExtractingMiddleware.cs index 8ef450e..165de90 100644 --- a/GuildWarsPartySearch/Middleware/IPExtractingMiddleware.cs +++ b/GuildWarsPartySearch/Middleware/IPExtractingMiddleware.cs @@ -1,6 +1,4 @@ using GuildWarsPartySearch.Server.Extensions; -using System.Core.Extensions; -using System.Extensions; namespace GuildWarsPartySearch.Server.Middleware; @@ -9,18 +7,13 @@ public sealed class IPExtractingMiddleware : IMiddleware private const string XForwardedForHeaderKey = "X-Forwarded-For"; private const string CFConnectingIPHeaderKey = "CF-Connecting-IP"; - private readonly ILogger logger; - - public IPExtractingMiddleware( - ILogger logger) + public IPExtractingMiddleware() { - this.logger = logger.ThrowIfNull(); } public async Task InvokeAsync(HttpContext context, RequestDelegate next) { var address = context.Connection.RemoteIpAddress?.ToString(); - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InvokeAsync), address ?? string.Empty); context.Request.Headers.TryGetValue(CFConnectingIPHeaderKey, out var cfConnectingIpValues); if (cfConnectingIpValues.FirstOrDefault() is string xCfIpAddress) { diff --git a/GuildWarsPartySearch/Middleware/LoggingEnrichmentMiddleware.cs b/GuildWarsPartySearch/Middleware/LoggingEnrichmentMiddleware.cs new file mode 100644 index 0000000..043ed15 --- /dev/null +++ b/GuildWarsPartySearch/Middleware/LoggingEnrichmentMiddleware.cs @@ -0,0 +1,18 @@ +using GuildWarsPartySearch.Server.Extensions; +using Serilog.Context; + +namespace GuildWarsPartySearch.Server.Middleware; + +public sealed class LoggingEnrichmentMiddleware : IMiddleware +{ + public Task InvokeAsync(HttpContext context, RequestDelegate next) + { + var ip = context.GetClientIP(); + var apiKey = context.GetApiKey(); + var cv = context.GetCorrelationVector(); + LogContext.PushProperty("ApiKey", apiKey); + LogContext.PushProperty("ClientIP", ip); + LogContext.PushProperty("CorrelationVector", cv); + return next(context); + } +} diff --git a/GuildWarsPartySearch/Middleware/PermissioningMiddleware.cs b/GuildWarsPartySearch/Middleware/PermissioningMiddleware.cs index 4833e89..c6b9dc4 100644 --- a/GuildWarsPartySearch/Middleware/PermissioningMiddleware.cs +++ b/GuildWarsPartySearch/Middleware/PermissioningMiddleware.cs @@ -7,6 +7,7 @@ namespace GuildWarsPartySearch.Server.Middleware; public sealed class PermissioningMiddleware : IMiddleware { + private const string EmptyApiKey = "-"; private const string XApiKeyHeaderKey = "X-Api-Key"; private readonly IPermissionService permissionService; @@ -23,7 +24,7 @@ public PermissioningMiddleware( public async Task InvokeAsync(HttpContext context, RequestDelegate next) { var address = context.Request.HttpContext.GetClientIP(); - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InvokeAsync), address ?? string.Empty); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InvokeAsync), string.Empty); if (context.Request.Headers.TryGetValue(XApiKeyHeaderKey, out var xApiKeyvalues)) { scopedLogger.LogDebug($"X-Api-Key {string.Join(',', xApiKeyvalues.Select(s => s))}"); @@ -32,11 +33,13 @@ public async Task InvokeAsync(HttpContext context, RequestDelegate next) if (xApiKeyvalues.FirstOrDefault() is not string apiKey) { context.SetPermissionLevel(Models.PermissionLevel.None, "No API Key found in X-Api-Key header"); + context.SetApiKey(EmptyApiKey); await next(context); return; } var permissionLevel = await this.permissionService.GetPermissionLevel(apiKey, context.RequestAborted); + context.SetApiKey(apiKey); context.SetPermissionLevel(permissionLevel, $"Api key {apiKey} is associated with {permissionLevel} permission level"); await next(context); } diff --git a/GuildWarsPartySearch/Options/ServerOptions.cs b/GuildWarsPartySearch/Options/ServerOptions.cs index 78be43b..f6a1ac1 100644 --- a/GuildWarsPartySearch/Options/ServerOptions.cs +++ b/GuildWarsPartySearch/Options/ServerOptions.cs @@ -12,7 +12,4 @@ public sealed class ServerOptions [JsonPropertyName(nameof(Port))] public int? Port { get; set; } - - [JsonPropertyName(nameof(LogHeaders))] - public bool LogHeaders { get; set; } = true; } diff --git a/GuildWarsPartySearch/Services/BotStatus/BotStatusService.cs b/GuildWarsPartySearch/Services/BotStatus/BotStatusService.cs index d89941d..5fab049 100644 --- a/GuildWarsPartySearch/Services/BotStatus/BotStatusService.cs +++ b/GuildWarsPartySearch/Services/BotStatus/BotStatusService.cs @@ -33,10 +33,10 @@ public BotStatusService( public async Task AddBot(string botId, WebSocket client, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.AddBot), botId); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.AddBot), string.Empty); if (botId.IsNullOrWhiteSpace()) { - scopedLogger.LogInformation("Unable to add bot. Null id"); + scopedLogger.LogError("Unable to add bot. Null id"); return false; } @@ -50,7 +50,7 @@ public async Task AddBot(string botId, WebSocket client, CancellationToken if (!this.connectedBots.TryAdd(botId, bot)) { - scopedLogger.LogInformation("Unable to add bot. Failed to add to cache"); + scopedLogger.LogError("Unable to add bot. Failed to add to cache"); return false; } @@ -77,7 +77,7 @@ public async Task> GetActivitiesForBot(string b public async Task> GetActivitiesForMap(int mapId, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetActivitiesForMap), mapId.ToString()); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetActivitiesForMap), string.Empty); if (!Map.TryParse(mapId, out var map)) { scopedLogger.LogError("Failed to parse map id"); @@ -100,7 +100,7 @@ public async Task> GetActivitiesForMap(int mapI public async Task> GetActivitiesForMap(string mapName, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetActivitiesForMap), mapName); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetActivitiesForMap), string.Empty); if (!Map.TryParse(mapName, out var map)) { scopedLogger.LogError("Failed to parse map id"); @@ -154,7 +154,7 @@ public async Task> GetAllActivities(Cancellatio public async Task RecordBotUpdateActivity(string botId, Map map, int district, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RecordBotUpdateActivity), botId); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RecordBotUpdateActivity), string.Empty); if (!this.connectedBots.TryGetValue(botId, out var bot)) { scopedLogger.LogError("Failed to find bot by id"); @@ -170,17 +170,17 @@ public async Task RecordBotUpdateActivity(string botId, Map map, int distr public async Task RemoveBot(string botId, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RemoveBot), botId); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RemoveBot), string.Empty); if (botId.IsNullOrEmpty()) { - scopedLogger.LogInformation("Unable to remove bot. Null id"); + scopedLogger.LogError("Unable to remove bot. Null id"); return false; } if (!this.connectedBots.TryRemove(botId, out var bot) || bot is null) { - scopedLogger.LogInformation("Unable to remove bot. Failed to remove bot from cache"); + scopedLogger.LogError("Unable to remove bot. Failed to remove bot from cache"); return false; } diff --git a/GuildWarsPartySearch/Services/Database/ApiKeySqliteDatabase.cs b/GuildWarsPartySearch/Services/Database/ApiKeySqliteDatabase.cs index 15f67b6..f51fe19 100644 --- a/GuildWarsPartySearch/Services/Database/ApiKeySqliteDatabase.cs +++ b/GuildWarsPartySearch/Services/Database/ApiKeySqliteDatabase.cs @@ -43,7 +43,7 @@ public async Task> GetApiKeys(CancellationToken cancellation public async Task GetApiKey(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetApiKey), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetApiKey), string.Empty); try { var key = await this.GetApiKeyInternal(apiKey, cancellationToken); @@ -74,7 +74,7 @@ public async Task StoreApiKey(string apiKey, PermissionLevel permissionLev Deletable = true }; - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.StoreApiKey), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.StoreApiKey), string.Empty); try { return await this.InsertApiKeyInternal(apiKeyModel, cancellationToken); @@ -88,7 +88,7 @@ public async Task StoreApiKey(string apiKey, PermissionLevel permissionLev public async Task RecordUsage(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RecordUsage), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RecordUsage), string.Empty); try { return await this.UpdateLastUsedTimeInternal(apiKey, cancellationToken); @@ -102,7 +102,7 @@ public async Task RecordUsage(string apiKey, CancellationToken cancellatio public async Task DeleteApiKey(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), string.Empty); try { return await this.DeleteApiKeyInternal(apiKey, cancellationToken); @@ -188,7 +188,7 @@ private async Task> GetApiKeysInternal(CancellationToken can private async Task UpdateLastUsedTimeInternal(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.UpdateLastUsedTimeInternal), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.UpdateLastUsedTimeInternal), string.Empty); try { using var command = this.connection.CreateCommand(); @@ -199,7 +199,15 @@ private async Task UpdateLastUsedTimeInternal(string apiKey, CancellationT "; command.Parameters.AddWithValue("key", apiKey); var result = await command.ExecuteNonQueryAsync(cancellationToken); - scopedLogger.LogInformation($"Updated last used time. Result {result}"); + if (result == 1) + { + scopedLogger.LogDebug($"Updated last used time. Result {result}"); + } + else + { + scopedLogger.LogError($"Updated last used time. Result {result}"); + } + return result == 1; } catch (Exception e) @@ -211,7 +219,7 @@ private async Task UpdateLastUsedTimeInternal(string apiKey, CancellationT private async Task DeleteApiKeyInternal(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKeyInternal), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKeyInternal), string.Empty); try { using var command = this.connection.CreateCommand(); @@ -221,7 +229,16 @@ DELETE FROM {this.options.TableName} "; command.Parameters.AddWithValue("key", apiKey); var result = await command.ExecuteNonQueryAsync(cancellationToken); - scopedLogger.LogInformation($"Deleted api key. Result {result}"); + + if (result == 1) + { + scopedLogger.LogDebug($"Deleted api key. Result {result}"); + } + else + { + scopedLogger.LogError($"Deleted api key. Result {result}"); + } + return result == 1; } catch (Exception e) @@ -241,7 +258,7 @@ private async Task InsertApiKeyInternal(ApiKey apiKey, CancellationToken c Description = apiKey.Description, LastUsedTime = apiKey.LastUsedTime }; - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InsertApiKeyInternal), apiKeyModel.Key ?? string.Empty); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InsertApiKeyInternal), string.Empty); try { using var command = this.connection.CreateCommand(); @@ -255,7 +272,15 @@ private async Task InsertApiKeyInternal(ApiKey apiKey, CancellationToken c command.Parameters.AddWithValue("creationTime", apiKeyModel.CreationTime); command.Parameters.AddWithValue("lastUsedTime", apiKeyModel.LastUsedTime); var result = await command.ExecuteNonQueryAsync(cancellationToken); - scopedLogger.LogInformation($"Inserting key. Result {result}"); + if (result == 1) + { + scopedLogger.LogDebug($"Inserting key. Result {result}"); + } + else + { + scopedLogger.LogInformation($"Inserting key. Result {result}"); + } + return result == 1; } catch (Exception e) diff --git a/GuildWarsPartySearch/Services/Database/BotHistorySqliteDatabase.cs b/GuildWarsPartySearch/Services/Database/BotHistorySqliteDatabase.cs index 8a5980e..19135bf 100644 --- a/GuildWarsPartySearch/Services/Database/BotHistorySqliteDatabase.cs +++ b/GuildWarsPartySearch/Services/Database/BotHistorySqliteDatabase.cs @@ -31,7 +31,7 @@ public BotHistorySqliteDatabase( public async Task RecordBotActivity(Bot bot, BotActivity.ActivityType activityType, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RecordBotActivity), bot.Name); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.RecordBotActivity), string.Empty); var activity = new BotActivity { Activity = activityType, @@ -51,7 +51,7 @@ public async Task RecordBotActivity(Bot bot, BotActivity.ActivityType acti public async Task> GetBotActivity(string botName, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllBotsActivity), botName); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllBotsActivity), string.Empty); try { return await this.GetBotActivityInternal(botName, cancellationToken); @@ -65,7 +65,7 @@ public async Task> GetBotActivity(string botName, Cance public async Task> GetBotActivity(Bot bot, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllBotsActivity), bot.Name); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllBotsActivity), string.Empty); try { return await this.GetBotActivityInternal(bot.Name, cancellationToken); @@ -79,7 +79,7 @@ public async Task> GetBotActivity(Bot bot, Cancellation public async Task> GetBotsActivityOnMap(Map map, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllBotsActivity), map.Id.ToString()); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllBotsActivity), string.Empty); try { return await this.GetBotsActivityOnMapInternal(map.Id, cancellationToken); @@ -130,7 +130,7 @@ private async Task> GetBotActivityInternal(string name, private async Task InsertActivity(BotActivity activity, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InsertActivity), activity.Name); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.InsertActivity), string.Empty); try { using var command = this.connection.CreateCommand(); @@ -143,7 +143,15 @@ private async Task InsertActivity(BotActivity activity, CancellationToken command.Parameters.AddWithValue("activity", (int)activity.Activity); command.Parameters.AddWithValue("timestamp", activity.TimeStamp); var result = await command.ExecuteNonQueryAsync(cancellationToken); - scopedLogger.LogInformation($"Logging bot activity. Result {result}"); + if (result == 1) + { + scopedLogger.LogDebug($"Logging bot activity. Result {result}"); + } + else + { + scopedLogger.LogError($"Logging bot activity. Result {result}"); + } + return result == 1; } catch (Exception e) diff --git a/GuildWarsPartySearch/Services/Database/PartySearchSqliteDatabase.cs b/GuildWarsPartySearch/Services/Database/PartySearchSqliteDatabase.cs index 4a06632..9e3f49a 100644 --- a/GuildWarsPartySearch/Services/Database/PartySearchSqliteDatabase.cs +++ b/GuildWarsPartySearch/Services/Database/PartySearchSqliteDatabase.cs @@ -184,7 +184,7 @@ ON CONFLICT(Sender) DO UPDATE SET })); if (actions.None()) { - scopedLogger.LogInformation("No change detected. Skipping operation"); + scopedLogger.LogDebug("No change detected. Skipping operation"); return true; } @@ -192,7 +192,15 @@ ON CONFLICT(Sender) DO UPDATE SET foreach(var command in actions) { var result = await command.ExecuteNonQueryAsync(cancellationToken); - scopedLogger.LogInformation($"Database operation returned {result}"); + if (result == 1) + { + scopedLogger.LogDebug($"Database operation returned {result}"); + } + else + { + scopedLogger.LogError($"Database operation returned {result}"); + } + results.Add(result); } @@ -232,7 +240,7 @@ ON CONFLICT(Sender) DO UPDATE SET var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetAllPartySearchesInternal), string.Empty); try { - scopedLogger.LogInformation("Refreshing party search cache"); + scopedLogger.LogDebug("Refreshing party search cache"); using var cts = new CancellationTokenSource(TimeSpan.FromSeconds(5)); return await this.GetSearchesInternal(cts.Token); } diff --git a/GuildWarsPartySearch/Services/Feed/LiveFeedService.cs b/GuildWarsPartySearch/Services/Feed/LiveFeedService.cs index f9d0b87..0bb7795 100644 --- a/GuildWarsPartySearch/Services/Feed/LiveFeedService.cs +++ b/GuildWarsPartySearch/Services/Feed/LiveFeedService.cs @@ -58,7 +58,7 @@ public void RemoveClient(WebSocket client, string? ipAddress) private async Task AddClientInternal(WebSocket client, string? ipAddress, PermissionLevel permissionLevel, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.AddClientInternal), ipAddress ?? string.Empty); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.AddClientInternal), string.Empty); await this.semaphore.WaitAsync(cancellationToken); try diff --git a/GuildWarsPartySearch/Services/Permissions/PermissionService.cs b/GuildWarsPartySearch/Services/Permissions/PermissionService.cs index 8494219..7d3fd6d 100644 --- a/GuildWarsPartySearch/Services/Permissions/PermissionService.cs +++ b/GuildWarsPartySearch/Services/Permissions/PermissionService.cs @@ -21,7 +21,7 @@ public PermissionService( public async Task CreateApiKey(string description, PermissionLevel permissionLevel, CancellationToken cancellationToken) { var key = GetNewApiKey(); - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.CreateApiKey), key); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.CreateApiKey), string.Empty); scopedLogger.LogDebug($"Creating API key with permission {permissionLevel}"); var result = await this.apiKeyDatabase.StoreApiKey(key, permissionLevel, description, cancellationToken); if (!result) @@ -34,7 +34,7 @@ public PermissionService( public async Task DeleteApiKey(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), string.Empty); scopedLogger.LogDebug($"Deleting API key"); var result = await this.apiKeyDatabase.DeleteApiKey(apiKey, cancellationToken); if (!result) @@ -47,7 +47,7 @@ public async Task DeleteApiKey(string apiKey, CancellationToken cancellati public async Task GetPermissionLevel(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.GetPermissionLevel), string.Empty); scopedLogger.LogDebug($"Retrieving API key"); var key = await this.apiKeyDatabase.GetApiKey(apiKey, cancellationToken); if (key is null) @@ -61,7 +61,7 @@ public async Task GetPermissionLevel(string apiKey, Cancellatio public async Task RecordUsage(string apiKey, CancellationToken cancellationToken) { - var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), apiKey); + var scopedLogger = this.logger.CreateScopedLogger(nameof(this.DeleteApiKey), string.Empty); scopedLogger.LogDebug($"Recording API key usage"); var result = await this.apiKeyDatabase.RecordUsage(apiKey, cancellationToken); if (!result)