Search code examples
c#loggingserilog

Temporary logging suppression for a scope in Serilog


I need to be able to temporarily disable logging for some scope. In my case there is a background task which periodically attempts to instantiate some device API for every available COM port in the system and sees if it fails. That API writes a lot of information to log in case of failure (exceptions, internal components Dispose calls, etc). As a result, the log is flooded with such unsuccessful attempts errors every second.

I came up with the solution that uses LogContext.PushProperty to identify the supressed log events. However, the following code won't log anything:

internal static class Program
{
    public static void Main(String[] args)
    {
        void StartListeningSomething()
        {
            Task.Factory.StartNew(() =>
            {
                while (true)
                {
                    Log.Information("Listening");
                    Thread.Sleep(500);
                }
            }, TaskCreationOptions.LongRunning);
        }

        Log.Logger = new LoggerConfiguration()
            .Enrich.WithThreadId()
            .Filter.ByExcluding(logEvent => logEvent.Properties.ContainsKey("SuppressLogging"))
            .Enrich.FromLogContext()
            .WriteTo.Console(new JsonFormatter())
            .CreateLogger();

        using (LogContext.PushProperty("SuppressLogging", true))
        {
            StartListeningSomething();
            Console.ReadKey(); // Will ignore background thread log messages until key enter
        }

        // We want to start logging events after exiting using block
        // But they won't be logged for listener thread at all

        Console.ReadKey();
    }
}

All log events inside listener task will be enriched with "SupressLogging" property even after popping it from the scope.


Solution

  • The only workaround I found (except the tedious passing customized ILogger throughout the entire API) consists of the following steps:

    • Assign some unique value to "SupressLogging" property
    • Add this value to internal static storage
    • When exiting scope, remove this value from storage (invalidate)
    • In Filter section of the logger configuration, check for property being attached and it's value being valid (contained in storage).

    The following code uses custom IDisposable token to make it seem like usual PushProperty

    internal static class Program
    {
        public static void Main(String[] args)
        {
            void StartListeningSomething()
            {
                Task.Factory.StartNew(() =>
                {
                    while (true)
                    {
                        Log.Information("Listening");
                        Thread.Sleep(500);
                    }
                }, TaskCreationOptions.LongRunning);
            }
    
            Log.Logger = new LoggerConfiguration()
                .Enrich.WithThreadId()
                .Filter.ByExcluding(logEvent => logEvent.IsSuppressed()) // Check if log event marked with supression property
                .Enrich.FromLogContext()
                .WriteTo.Console(new JsonFormatter())
                .CreateLogger();
    
            using (SerilogExtensions.SuppressLogging())
            {
                StartListeningSomething();
                Console.ReadKey(); // Will ignore background thread log messages until some key is entered
            }
    
            // Will start logging events after exiting the using block
    
            Console.ReadKey();
        }
    }
    

    And the actual SerilogExtensions:

    /// <summary>
    ///     Provides helper extensions to Serilog logging.
    /// </summary>
    public static class SerilogExtensions
    {
        private const           String        SuppressLoggingProperty = "SuppressLogging";
        private static readonly HashSet<Guid> ActiveSuppressions      = new HashSet<Guid>();
    
        /// <summary>
        ///     Get disposable token to supress logging for context.
        /// </summary>
        /// <remarks>
        ///     Pushes "SuppressLogging" property with unique value to SerilogContext.
        ///     When disposed, disposes Serilog property push token and invalidates stored value so new log messages are no longer
        ///     supressed.
        /// </remarks>
        public static IDisposable SuppressLogging()
        {
            return new SuppressLoggingDisposableToken();
        }
    
        /// <summary>
        ///     Determines whether the given log event suppressed.
        /// </summary>
        /// <remarks>
        ///     Also removes "SuppressLogging" property if present.
        /// </remarks>
        public static Boolean IsSuppressed(this LogEvent logEvent)
        {
            Boolean containsProperty = logEvent.Properties.TryGetValue(SuppressLoggingProperty, out var val);
            if (!containsProperty)
                return false;
    
            logEvent.RemovePropertyIfPresent(SuppressLoggingProperty); //No need for that in logs
    
            if (val is ScalarValue scalar && scalar.Value is Guid id)
                return ActiveSuppressions.Contains(id);
    
            return false;
        }
    
        /// <summary>
        ///     Disposable wrapper around logging supression property push/pop and value generation/invalidation.
        /// </summary>
        private class SuppressLoggingDisposableToken : IDisposable
        {
            private readonly IDisposable _pushPropertyDisposable;
            private readonly Guid        _guid;
    
            public SuppressLoggingDisposableToken()
            {
                _guid                   = Guid.NewGuid();
                _pushPropertyDisposable = LogContext.PushProperty(SuppressLoggingProperty, _guid);
    
                ActiveSuppressions.Add(_guid);
            }
    
            public void Dispose()
            {
                ActiveSuppressions.Remove(_guid);
                _pushPropertyDisposable.Dispose();
            }
        }
    }
    

    The complete example project can be found on github.

    I would like to leave this self-answered question here and also to ask more experienced Serilog users what their opinion of this problem is. May be there is some common approach to logging suppression I didn't find?