Add logging to tokenables (#2298)

* Add logging to token usages

* Add settings manipulation of log levels

* Maintain no logging for dev

* Log exception causing Token failure in TryUnprotect

* dotnet format 🤖

* Added deconstruction operator on new debug logs.

* Split off log level settings into separate files

* Improve log messages

* dotnet format 🤖

* Fix token serialization

* Final review notes

Co-authored-by: Todd Martin <>

src/Core/OrganizationFeatures/OrganizationServiceCollectionExtensions.cs

@@ -12,6 +12,7 @@ using Bit.Core.Settings;
 using Bit.Core.Tokens;
 using Microsoft.AspNetCore.DataProtection;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 
 namespace Bit.Core.OrganizationFeatures;
 
@@ -70,7 +71,8 @@ public static class OrganizationServiceCollectionExtensions
             new DataProtectorTokenFactory<OrganizationSponsorshipOfferTokenable>(
                 OrganizationSponsorshipOfferTokenable.ClearTextPrefix,
                 OrganizationSponsorshipOfferTokenable.DataProtectorPurpose,
-                serviceProvider.GetDataProtectionProvider())
+                serviceProvider.GetDataProtectionProvider(),
+                serviceProvider.GetRequiredService<ILogger<DataProtectorTokenFactory<OrganizationSponsorshipOfferTokenable>>>())
         );
     }
 }

src/Core/Settings/GlobalSettings.cs

@@ -1,4 +1,6 @@
-namespace Bit.Core.Settings;
+using Bit.Core.Settings.LoggingSettings;
+
+namespace Bit.Core.Settings;
 
 public class GlobalSettings : IGlobalSettings
 {
@@ -58,6 +60,7 @@ public class GlobalSettings : IGlobalSettings
     public virtual DocumentDbSettings DocumentDb { get; set; } = new DocumentDbSettings();
     public virtual SentrySettings Sentry { get; set; } = new SentrySettings();
     public virtual SyslogSettings Syslog { get; set; } = new SyslogSettings();
+    public virtual ILogLevelSettings MinLogLevel { get; set; } = new LogLevelSettings();
     public virtual NotificationHubSettings NotificationHub { get; set; } = new NotificationHubSettings();
     public virtual YubicoSettings Yubico { get; set; } = new YubicoSettings();
     public virtual DuoSettings Duo { get; set; } = new DuoSettings();

src/Core/Settings/IGlobalSettings.cs

@@ -15,5 +15,6 @@ public interface IGlobalSettings
     IBaseServiceUriSettings BaseServiceUri { get; set; }
     ITwoFactorAuthSettings TwoFactorAuth { get; set; }
     ISsoSettings Sso { get; set; }
+    ILogLevelSettings MinLogLevel { get; set; }
     IPasswordlessAuthSettings PasswordlessAuth { get; set; }
 }

src/Core/Settings/ILogLevelSettings.cs

@@ -0,0 +1,74 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings;
+
+public interface ILogLevelSettings
+{
+    IBillingLogLevelSettings BillingSettings { get; set; }
+    IApiLogLevelSettings ApiSettings { get; set; }
+    IIdentityLogLevelSettings IdentitySettings { get; set; }
+    IScimLogLevelSettings ScimSettings { get; set; }
+    ISsoLogLevelSettings SsoSettings { get; set; }
+    IAdminLogLevelSettings AdminSettings { get; set; }
+    IEventsLogLevelSettings EventsSettings { get; set; }
+    IEventsProcessorLogLevelSettings EventsProcessorSettings { get; set; }
+    IIconsLogLevelSettings IconsSettings { get; set; }
+    INotificationsLogLevelSettings NotificationsSettings { get; set; }
+}
+
+public interface IBillingLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+    LogEventLevel Jobs { get; set; }
+}
+
+public interface IApiLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+    LogEventLevel IdentityToken { get; set; }
+    LogEventLevel IpRateLimit { get; set; }
+}
+
+public interface IIdentityLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+    LogEventLevel IdentityToken { get; set; }
+    LogEventLevel IpRateLimit { get; set; }
+}
+
+public interface IScimLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+}
+
+public interface ISsoLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+}
+
+public interface IAdminLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+}
+
+public interface IEventsLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+    LogEventLevel IdentityToken { get; set; }
+}
+
+public interface IEventsProcessorLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+}
+
+public interface IIconsLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+}
+
+public interface INotificationsLogLevelSettings
+{
+    LogEventLevel Default { get; set; }
+    LogEventLevel IdentityToken { get; set; }
+}

src/Core/Settings/LoggingSettings/AdminLogLevelSettings.cs

@@ -0,0 +1,8 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class AdminLogLevelSettings : IAdminLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Error;
+}

src/Core/Settings/LoggingSettings/ApiLogLevelSettings.cs

@@ -0,0 +1,10 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class ApiLogLevelSettings : IApiLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Error;
+    public LogEventLevel IdentityToken { get; set; } = LogEventLevel.Fatal;
+    public LogEventLevel IpRateLimit { get; set; } = LogEventLevel.Information;
+}

src/Core/Settings/LoggingSettings/BillingLogLevelSettings.cs

@@ -0,0 +1,9 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class BillingLogLevelSettings : IBillingLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Warning;
+    public LogEventLevel Jobs { get; set; } = LogEventLevel.Information;
+}

src/Core/Settings/LoggingSettings/EventsLogLevelSettings.cs

@@ -0,0 +1,9 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class EventsLogLevelSettings : IEventsLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Error;
+    public LogEventLevel IdentityToken { get; set; } = LogEventLevel.Fatal;
+}

src/Core/Settings/LoggingSettings/EventsProcessorLogLevelSettings.cs

@@ -0,0 +1,8 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class EventsProcessorLogLevelSettings : IEventsProcessorLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Warning;
+}

src/Core/Settings/LoggingSettings/IconsLogLevelSettings.cs

@@ -0,0 +1,8 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class IconsLogLevelSettings : IIconsLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Error;
+}

src/Core/Settings/LoggingSettings/IdentityLogLevelSettings.cs

@@ -0,0 +1,10 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class IdentityLogLevelSettings : IIdentityLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Error;
+    public LogEventLevel IdentityToken { get; set; } = LogEventLevel.Fatal;
+    public LogEventLevel IpRateLimit { get; set; } = LogEventLevel.Information;
+}

src/Core/Settings/LoggingSettings/LogLevelSettings.cs

@@ -0,0 +1,16 @@
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class LogLevelSettings : ILogLevelSettings
+{
+    public IBillingLogLevelSettings BillingSettings { get; set; } = new BillingLogLevelSettings();
+    public IApiLogLevelSettings ApiSettings { get; set; } = new ApiLogLevelSettings();
+    public IIdentityLogLevelSettings IdentitySettings { get; set; } = new IdentityLogLevelSettings();
+    public IScimLogLevelSettings ScimSettings { get; set; } = new ScimLogLevelSettings();
+    public ISsoLogLevelSettings SsoSettings { get; set; } = new SsoLogLevelSettings();
+    public IAdminLogLevelSettings AdminSettings { get; set; } = new AdminLogLevelSettings();
+    public IEventsLogLevelSettings EventsSettings { get; set; } = new EventsLogLevelSettings();
+    public IEventsProcessorLogLevelSettings EventsProcessorSettings { get; set; } = new EventsProcessorLogLevelSettings();
+    public IIconsLogLevelSettings IconsSettings { get; set; } = new IconsLogLevelSettings();
+    public INotificationsLogLevelSettings NotificationsSettings { get; set; } = new NotificationsLogLevelSettings();
+}

src/Core/Settings/LoggingSettings/NotificationsLogLevelSettings.cs

@@ -0,0 +1,9 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class NotificationsLogLevelSettings : INotificationsLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Warning;
+    public LogEventLevel IdentityToken { get; set; } = LogEventLevel.Fatal;
+}

src/Core/Settings/LoggingSettings/ScimLogLevelSettings.cs

@@ -0,0 +1,8 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class ScimLogLevelSettings : IScimLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Warning;
+}

src/Core/Settings/LoggingSettings/SsoLogLevelSettings.cs

@@ -0,0 +1,8 @@
+using Serilog.Events;
+
+namespace Bit.Core.Settings.LoggingSettings;
+
+public class SsoLogLevelSettings : ISsoLogLevelSettings
+{
+    public LogEventLevel Default { get; set; } = LogEventLevel.Error;
+}

src/Core/Tokens/DataProtectorTokenFactory.cs

@@ -1,4 +1,5 @@
 using Microsoft.AspNetCore.DataProtection;
+using Microsoft.Extensions.Logging;
 
 namespace Bit.Core.Tokens;
 
@@ -6,15 +7,17 @@ public class DataProtectorTokenFactory<T> : IDataProtectorTokenFactory<T> where
 {
     private readonly IDataProtector _dataProtector;
     private readonly string _clearTextPrefix;
+    private readonly ILogger<DataProtectorTokenFactory<T>> _logger;
 
-    public DataProtectorTokenFactory(string clearTextPrefix, string purpose, IDataProtectionProvider dataProtectionProvider)
+    public DataProtectorTokenFactory(string clearTextPrefix, string purpose, IDataProtectionProvider dataProtectionProvider, ILogger<DataProtectorTokenFactory<T>> logger)
     {
         _dataProtector = dataProtectionProvider.CreateProtector(purpose);
         _clearTextPrefix = clearTextPrefix;
+        _logger = logger;
     }
 
     public string Protect(T data) =>
-        data.ToToken().ProtectWith(_dataProtector).WithPrefix(_clearTextPrefix).ToString();
+        data.ToToken().ProtectWith(_dataProtector, _logger).WithPrefix(_clearTextPrefix).ToString();
 
     /// <summary>
     /// Unprotect token
@@ -24,7 +27,7 @@ public class DataProtectorTokenFactory<T> : IDataProtectorTokenFactory<T> where
     /// <returns>The parsed tokenable</returns>
     /// <exception>Throws CryptographicException if fails to unprotect</exception>
     public T Unprotect(string token) =>
-        Tokenable.FromToken<T>(new Token(token).RemovePrefix(_clearTextPrefix).UnprotectWith(_dataProtector).ToString());
+        Tokenable.FromToken<T>(new Token(token).RemovePrefix(_clearTextPrefix).UnprotectWith(_dataProtector, _logger).ToString());
 
     public bool TokenValid(string token)
     {
@@ -45,8 +48,9 @@ public class DataProtectorTokenFactory<T> : IDataProtectorTokenFactory<T> where
             data = Unprotect(token);
             return true;
         }
-        catch
+        catch (Exception ex)
         {
+            _logger.LogInformation(ex, "Failed to unprotect token: {rawToken}", token);
             data = default;
             return false;
         }

src/Core/Tokens/Token.cs

@@ -1,4 +1,5 @@
 using Microsoft.AspNetCore.DataProtection;
+using Microsoft.Extensions.Logging;
 
 namespace Bit.Core.Tokens;
 
@@ -26,11 +27,28 @@ public class Token
         return new Token(_token[expectedPrefix.Length..]);
     }
 
-    public Token ProtectWith(IDataProtector dataProtector) =>
-        new(dataProtector.Protect(ToString()));
 
-    public Token UnprotectWith(IDataProtector dataProtector) =>
-        new(dataProtector.Unprotect(ToString()));
+    public Token ProtectWith(IDataProtector dataProtector, ILogger logger)
+    {
+        logger.LogDebug("Protecting token: {token}", this);
+        return new(dataProtector.Protect(ToString()));
+    }
+
+    public Token UnprotectWith(IDataProtector dataProtector, ILogger logger)
+    {
+        var unprotected = "";
+        try
+        {
+            unprotected = dataProtector.Unprotect(ToString());
+        }
+        catch (Exception e)
+        {
+            logger.LogInformation(e, "Failed to unprotect token: {token}", this);
+            throw;
+        }
+        logger.LogDebug("Unprotected token: {token} to {decryptedToken}", this, unprotected);
+        return new(unprotected);
+    }
 
     public override string ToString() => _token;
 }

src/Core/Utilities/LoggerFactoryExtensions.cs

@@ -31,13 +31,16 @@ public static class LoggerFactoryExtensions
     public static ILoggingBuilder AddSerilog(
         this ILoggingBuilder builder,
         WebHostBuilderContext context,
-        Func<LogEvent, bool> filter = null)
+        Func<LogEvent, IGlobalSettings, bool> filter = null)
     {
         if (context.HostingEnvironment.IsDevelopment())
         {
             return builder;
         }
 
+        var globalSettings = new GlobalSettings();
+        ConfigurationBinder.Bind(context.Configuration.GetSection("GlobalSettings"), globalSettings);
+
         bool inclusionPredicate(LogEvent e)
         {
             if (filter == null)
@@ -49,12 +52,9 @@ public static class LoggerFactoryExtensions
             {
                 return true;
             }
-            return filter(e);
+            return filter(e, globalSettings);
         }
 
-        var globalSettings = new GlobalSettings();
-        ConfigurationBinder.Bind(context.Configuration.GetSection("GlobalSettings"), globalSettings);
-
         var config = new LoggerConfiguration()
             .Enrich.FromLogContext()
             .Filter.ByIncludingOnly(inclusionPredicate);