Search code examples
c#.netasp.net-coreconsoleserilog

Why the DictionaryValue is converted to ScalarValue in Serilog in ASP.NET Core


My Serilog configuration is the following:

    LevelSwitch.MinimumLevel = LogEventLevel.Verbose;

    var loggerConfiguration =
        new LoggerConfiguration()
            .MinimumLevel.ControlledBy(LevelSwitch)
            .Enrich.FromLogContext()
            .WriteTo.Conditional(
                IsDictionaryValue,
                cfg => cfg.Console());

    services.AddLogging(configure => configure.AddSerilog());

where the IsDictionaryValue is defined as:

    static bool IsDictionaryValue(LogEvent logEvent)
    {
        if (logEvent.Properties.TryGetValue("LOG_TEST", out LogEventPropertyValue value))
        {
            return value is DictionaryValue;
        }

        return false;
    }

trying to log trace and information message:

    var logger = loggerFactory.CreateLogger<Program>();

    var dict = new Dictionary<string, object>
    {
        { "val1", 1 },
        { "val2", 2 },
        { "val3", "_3" },
    };

    logger.LogTrace("{@LOG_TEST}", dict);

    logger.LogInformation("{@LOG_TEST}", dict);

The question is:
Why in ASP.NET Core web app the log trace message correctly creates DictionaryValue and the result of IsDictionaryValue is true, but when I log information message, the LogEventPropertyValue value is ScalarValue.

BUT
This "bug" is only in ASP.NET Core web app. When I use the same Serilog configuration in Console app, both LogTrace and LogInformation, correctly represents the dict dictionary as DictionaryValue.

Update:
type of LogEventPropertyValue in DictionaryValue

Log method Console App Web app
LogTrace DictionaryValue DictionaryValue
LogDebug DictionaryValue DictionaryValue
LogInformation DictionaryValue ScalarValue
LogWarning DictionaryValue ScalarValue
LogError DictionaryValue ScalarValue
LogCritical DictionaryValue ScalarValue

Solution

  • The problem:
    In ASP.NET Core are registered some default LoggerProviders like:

    1. Microsoft.Extensions.Logging.Console.ConsoleLogger
    2. Microsoft.Extensions.Logging.Debug.DebugLogger
    3. Microsoft.Extensions.Logging.EventSource.EventSourceLogger
    4. Microsoft.Extensions.Logging.EventLog.EventLogLogger
    

    and when you configure serilog

    services.AddLogging(configure => configure.AddSerilog());
    

    the fifth LoggerProvider was added:

    5. Serilog.Extensions.Logging.SerilogLogger
    

    The default configuration for other providers is LogLevel:Information. This is the reason why LogTrace and LogDebug works in Web app. So if you call LogInformation the first four logger providers hits the TState in

    namespace Microsoft.Extensions.Logging
    {
        internal class Logger : ILogger
        {
            public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
        }
    }
    

    and it converts the original dictionary to string. And when the fifth logger provider (out SerilogLogger) comes to play, it cannot resolve DictionaryValue because the TState is string

    The solution:
    Set the SerilogLogger as the first LoggerProvider:

        public class Program
        {
            public static void Main(string[] args)
            {
                CreateHostBuilder(args).Build().Run();
            }
    
            public static IHostBuilder CreateHostBuilder(string[] args) =>
                Host.CreateDefaultBuilder(args)
                    .ConfigureWebHostDefaults(webBuilder =>
                    {
                        webBuilder.UseStartup<Startup>();
                    })
                .ConfigureLogging(cfg => cfg
                    .ClearProviders()
                    .AddSerilog()
                    .AddConsole()
                    .AddDebug()
                    .AddEventSourceLogger()
                    .AddEventLog());
        }
    

    and because the SerilogLoggerProvider is registered in Program.cs within IHostBuilder, the AddSerilog() in services.AddLogging(configure => configure.AddSerilog()); is not necessary.

    services.AddLogging();