diff --git a/Catalogger.Backend/CataloggerMetrics.cs b/Catalogger.Backend/CataloggerMetrics.cs index 1dc0cf0..ce55805 100644 --- a/Catalogger.Backend/CataloggerMetrics.cs +++ b/Catalogger.Backend/CataloggerMetrics.cs @@ -29,6 +29,11 @@ public static class CataloggerMetrics public static long MessageRateMinute { get; set; } + public static readonly Gauge DatabaseConnections = Metrics.CreateGauge( + "catalogger_open_database_connections", + "Number of open database connections" + ); + public static readonly Gauge GuildsCached = Metrics.CreateGauge( "catalogger_cache_guilds", "Number of guilds in the cache" diff --git a/Catalogger.Backend/Database/DatabaseConnection.cs b/Catalogger.Backend/Database/DatabaseConnection.cs index 0c44667..f15c2c7 100644 --- a/Catalogger.Backend/Database/DatabaseConnection.cs +++ b/Catalogger.Backend/Database/DatabaseConnection.cs @@ -20,14 +20,9 @@ using Npgsql; namespace Catalogger.Backend.Database; -public class DatabaseConnection(Guid id, ILogger logger, NpgsqlConnection inner) - : DbConnection, - IDisposable +public class DatabaseConnection(NpgsqlConnection inner) : DbConnection, IDisposable { - public Guid ConnectionId => id; public NpgsqlConnection Inner => inner; - private readonly ILogger _logger = logger.ForContext(); - private readonly DateTimeOffset _openTime = DateTimeOffset.UtcNow; private bool _hasClosed; @@ -43,8 +38,6 @@ public class DatabaseConnection(Guid id, ILogger logger, NpgsqlConnection inner) } DatabasePool.DecrementConnections(); - var openFor = DateTimeOffset.UtcNow - _openTime; - _logger.Verbose("Closing connection {ConnId}, open for {OpenFor}", ConnectionId, openFor); _hasClosed = true; await inner.CloseAsync(); } @@ -52,11 +45,7 @@ public class DatabaseConnection(Guid id, ILogger logger, NpgsqlConnection inner) protected override async ValueTask BeginDbTransactionAsync( IsolationLevel isolationLevel, CancellationToken cancellationToken - ) - { - _logger.Verbose("Beginning transaction on connection {ConnId}", ConnectionId); - return await inner.BeginTransactionAsync(isolationLevel, cancellationToken); - } + ) => await inner.BeginTransactionAsync(isolationLevel, cancellationToken); public new void Dispose() { diff --git a/Catalogger.Backend/Database/DatabasePool.cs b/Catalogger.Backend/Database/DatabasePool.cs index fb266dd..7b23da1 100644 --- a/Catalogger.Backend/Database/DatabasePool.cs +++ b/Catalogger.Backend/Database/DatabasePool.cs @@ -24,18 +24,13 @@ namespace Catalogger.Backend.Database; public class DatabasePool { - private readonly ILogger _rootLogger; - private readonly ILogger _logger; private readonly NpgsqlDataSource _dataSource; private static int _openConnections; public static int OpenConnections => _openConnections; - public DatabasePool(Config config, ILogger logger, ILoggerFactory? loggerFactory) + public DatabasePool(Config config, ILoggerFactory? loggerFactory) { - _rootLogger = logger; - _logger = logger.ForContext(); - var connString = new NpgsqlConnectionStringBuilder(config.Database.Url) { Timeout = config.Database.Timeout ?? 5, @@ -49,27 +44,10 @@ public class DatabasePool _dataSource = dataSourceBuilder.Build(); } - public async Task AcquireAsync(CancellationToken ct = default) - { - return new DatabaseConnection( - LogOpen(), - _rootLogger, - await _dataSource.OpenConnectionAsync(ct) - ); - } + public async Task AcquireAsync(CancellationToken ct = default) => + new(await _dataSource.OpenConnectionAsync(ct)); - public DatabaseConnection Acquire() - { - return new DatabaseConnection(LogOpen(), _rootLogger, _dataSource.OpenConnection()); - } - - private Guid LogOpen() - { - var connId = Guid.NewGuid(); - _logger.Verbose("Opening database connection {ConnId}", connId); - IncrementConnections(); - return connId; - } + public DatabaseConnection Acquire() => new(_dataSource.OpenConnection()); public async Task ExecuteAsync( Func func, diff --git a/Catalogger.Backend/Extensions/StartupExtensions.cs b/Catalogger.Backend/Extensions/StartupExtensions.cs index c1af3ab..f9a226c 100644 --- a/Catalogger.Backend/Extensions/StartupExtensions.cs +++ b/Catalogger.Backend/Extensions/StartupExtensions.cs @@ -51,19 +51,22 @@ public static class StartupExtensions { var logCfg = new LoggerConfiguration() .Enrich.FromLogContext() - .MinimumLevel.Is(config.Logging.LogEventLevel) + .MinimumLevel.Verbose() + // Most Microsoft.* package logs are needlessly verbose, so we restrict them to INFO level and up + .MinimumLevel.Override("Microsoft", LogEventLevel.Information) // ASP.NET's built in request logs are extremely verbose, so we use Serilog's instead. // Serilog doesn't disable the built-in logs, so we do it here. - .MinimumLevel.Override("Microsoft", LogEventLevel.Information) - .MinimumLevel.Override( - "Microsoft.EntityFrameworkCore.Database.Command", - config.Logging.LogQueries ? LogEventLevel.Information : LogEventLevel.Fatal - ) .MinimumLevel.Override("Microsoft.AspNetCore.Hosting", LogEventLevel.Warning) .MinimumLevel.Override("Microsoft.AspNetCore.Mvc", LogEventLevel.Warning) .MinimumLevel.Override("Microsoft.AspNetCore.Routing", LogEventLevel.Warning) + // Let's not put webhook tokens and even *full bot tokens* in the logs, thank you + .MinimumLevel.Override("System.Net.Http.HttpClient", LogEventLevel.Warning) // The default theme doesn't support light mode - .WriteTo.Console(theme: AnsiConsoleTheme.Sixteen, applyThemeToRedirectedOutput: true); + .WriteTo.Console( + theme: AnsiConsoleTheme.Sixteen, + applyThemeToRedirectedOutput: true, + restrictedToMinimumLevel: config.Logging.LogEventLevel + ); if (config.Logging.SeqLogUrl != null) { diff --git a/Catalogger.Backend/Services/MetricsCollectionService.cs b/Catalogger.Backend/Services/MetricsCollectionService.cs index 5c003a0..afba829 100644 --- a/Catalogger.Backend/Services/MetricsCollectionService.cs +++ b/Catalogger.Backend/Services/MetricsCollectionService.cs @@ -43,6 +43,7 @@ public class MetricsCollectionService( var messageCount = await conn.ExecuteScalarAsync("select count(id) from messages"); + CataloggerMetrics.DatabaseConnections.Set(DatabasePool.OpenConnections); CataloggerMetrics.GuildsCached.Set(guildCache.Size); CataloggerMetrics.ChannelsCached.Set(channelCache.Size); CataloggerMetrics.RolesCached.Set(roleCache.Size); diff --git a/Catalogger.Backend/Services/WebhookExecutorService.cs b/Catalogger.Backend/Services/WebhookExecutorService.cs index f82ea75..78f12f5 100644 --- a/Catalogger.Backend/Services/WebhookExecutorService.cs +++ b/Catalogger.Backend/Services/WebhookExecutorService.cs @@ -315,6 +315,13 @@ public class WebhookExecutorService( Snowflake channelId ) { + _logger.Verbose( + "Getting log channel for event {Event} in guild {GuildId} and channel {ChannelId}", + logChannelType, + guild.Id, + channelId + ); + if (!channelCache.TryGet(channelId, out var channel)) return GetDefaultLogChannel(guild, logChannelType); @@ -329,7 +336,13 @@ public class WebhookExecutorService( // parent_id should always have a value for threads channelId = channel.ParentID.Value!.Value; if (!channelCache.TryGet(channelId, out var parentChannel)) + { + _logger.Verbose( + "Parent channel for thread {ChannelId} is not in cache, returning the default log channel", + channelId + ); return GetDefaultLogChannel(guild, logChannelType); + } categoryId = parentChannel.ParentID.Value; } else @@ -343,8 +356,16 @@ public class WebhookExecutorService( guild.IgnoredChannels.Contains(channelId.Value) || (categoryId != null && guild.IgnoredChannels.Contains(categoryId.Value.Value)) ) + { + _logger.Verbose( + "Channel {ChannelId} or its parent {CategoryId} is ignored", + channelId, + categoryId + ); return null; + } + _logger.Verbose("Returning default log channel for {EventType}", logChannelType); return GetDefaultLogChannel(guild, logChannelType); } @@ -355,13 +376,29 @@ public class WebhookExecutorService( ulong? userId = null ) { + _logger.Verbose( + "Getting log channel for event {Event}. Channel ID: {ChannelId}, user ID: {UserId}", + logChannelType, + channelId, + userId + ); + // Check if the user is ignored globally if (userId != null && guild.Messages.IgnoredUsers.Contains(userId.Value)) + { + _logger.Verbose("User {UserId} is ignored globally", userId); return null; + } // If the user isn't ignored and we didn't get a channel ID, return the default log channel if (channelId == null) + { + _logger.Verbose( + "No channel ID given so returning default channel for {Event}", + logChannelType + ); return GetDefaultLogChannel(guild, logChannelType); + } if (!channelCache.TryGet(channelId.Value, out var channel)) return null; @@ -377,7 +414,13 @@ public class WebhookExecutorService( // parent_id should always have a value for threads channelId = channel.ParentID.Value!.Value; if (!channelCache.TryGet(channelId.Value, out var parentChannel)) + { + _logger.Verbose( + "Parent channel for thread {ChannelId} is not in cache, returning the default log channel", + channelId + ); return GetDefaultLogChannel(guild, logChannelType); + } categoryId = parentChannel.ParentID.Value; } else @@ -391,7 +434,14 @@ public class WebhookExecutorService( guild.Messages.IgnoredChannels.Contains(channelId.Value.Value) || categoryId != null && guild.Messages.IgnoredChannels.Contains(categoryId.Value.Value) ) + { + _logger.Verbose( + "Channel {ChannelId} or its parent {CategoryId} is ignored", + channelId, + categoryId + ); return null; + } if (userId != null) { @@ -408,13 +458,27 @@ public class WebhookExecutorService( : [] ) ?? []; if (channelIgnoredUsers.Concat(categoryIgnoredUsers).Contains(userId.Value)) + { + _logger.Verbose( + "User {UserId} is ignored in {ChannelId} or its category {CategoryId}", + userId, + channelId, + categoryId + ); return null; + } } // These three events can be redirected to other channels. Redirects can be on a channel or category level. // The events are only redirected if they're supposed to be logged in the first place. if (GetDefaultLogChannel(guild, logChannelType) == 0) + { + _logger.Verbose( + "No default log channel for event {EventType}, ignoring event", + logChannelType + ); return null; + } var categoryRedirect = categoryId != null @@ -422,10 +486,29 @@ public class WebhookExecutorService( : 0; if (guild.Channels.Redirects.TryGetValue(channelId.Value.Value, out var channelRedirect)) + { + _logger.Verbose( + "Messages from channel {ChannelId} should be redirected to {RedirectId}", + channelId, + channelRedirect + ); return channelRedirect; - return categoryRedirect != 0 - ? categoryRedirect - : GetDefaultLogChannel(guild, logChannelType); + } + + if (categoryRedirect != 0) + { + _logger.Verbose( + "Messages from categoryId {CategoryId} should be redirected to {RedirectId}", + categoryId, + categoryRedirect + ); + } + + _logger.Verbose( + "No redirects or ignores for event {EventType}, returning default log channel", + logChannelType + ); + return GetDefaultLogChannel(guild, logChannelType); } public static ulong GetDefaultLogChannel(Guild guild, LogChannelType logChannelType) => diff --git a/Catalogger.GoImporter/Program.cs b/Catalogger.GoImporter/Program.cs index a34f08a..3746ef4 100644 --- a/Catalogger.GoImporter/Program.cs +++ b/Catalogger.GoImporter/Program.cs @@ -43,7 +43,7 @@ internal class Program return; } - var db = new DatabasePool(config, Log.Logger, null); + var db = new DatabasePool(config, null); DatabasePool.ConfigureDapper(); if (Environment.GetEnvironmentVariable("MIGRATE") == "true") {