Temporary logging suppression for a scope in Serilog

Question

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.

Answer 1

I would like to add to ArXen42 answer.

The proposed Hashset to keep track of the the activesuppression keys is not threadsafe and will create issues when using multiple threads.

A solution would be to use the ConcurrentDictionary<T,T2> instead of the HashSet<T> or the solution as stated below without keeping track of GUIDs to supress the logs.

///     Provides helper extensions to Serilog logging.
/// </summary>
public static class SerilogExtensions
{
    private const string SuppressLoggingProperty
        = "SuppressLogging";

    /// <summary>
    ///     Get disposable token to supress logging for context.
    /// </summary>
    public static IDisposable SuppressLogging()
    {
        return LogContext.PushProperty(SuppressLoggingProperty, true);
    }

    /// <summary>
    ///     Determines whether the given log event suppressed.
    /// </summary>
    /// <remarks>
    ///     Also removes "SuppressLogging" property if present.
    /// </remarks>
    public static bool IsSuppressed(this LogEvent logEvent)
    {
        var containsProperty = logEvent.Properties
            .TryGetValue(SuppressLoggingProperty, out var val);

        if (!containsProperty)
            return false;

        // remove suppression property from logs
        logEvent.RemovePropertyIfPresent(SuppressLoggingProperty);

        if (val is ScalarValue scalar && scalar.Value is bool isSuppressed)
            return isSuppressed;

        return false;
    }
}

Answer 2

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?