ASP.NET Core - JSON logger

  • Gérald Barré

ASP.NET Core supports a logging API that works with a variety of built-in and third-party logging providers. The built-in providers allow to log to the console, the debug output or as ETW messages. In my case I needed to output the messages and their associated data to console as JSON. This means I had to create a custom logger and integrate it in the ASP.NET Core application.

Let's define the structure of a message:

internal sealed class JsonLogEntry
{
    public DateTimeOffset Timestamp { get; set; }
    public int LogLevel { get; set; }
    public int EventId { get; set; }
    public string EventName { get; set; }
    public string Category { get; set; }
    public string Exception { get; set; }
    public string Message { get; set; }
    public IDictionary<string, object> Scope { get; } = new Dictionary<string, object>(StringComparer.Ordinal);
}

Then, the logger can be implemented. The idea is to create a JsonLogEntry with the data of the message and then convert it to json.

public sealed class JsonLogger : ILogger
{
    private readonly TextWriter _writer;
    private readonly string _categoryName;

    internal IExternalScopeProvider ScopeProvider { get; set; }

    public JsonLogger(TextWriter writer, string categoryName, IExternalScopeProvider scopeProvider)
    {
        _writer = writer;
        _categoryName = categoryName;
        ScopeProvider = scopeProvider;
    }

    public IDisposable BeginScope<TState>(TState state) => ScopeProvider?.Push(state) ?? NullScope.Instance;

    public bool IsEnabled(LogLevel logLevel) => logLevel != LogLevel.None;

    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
    {
        if (formatter is null)
            throw new ArgumentNullException(nameof(formatter));

        var message = new JsonLogEntry
        {
            Timestamp = DateTime.UtcNow,
            LogLevel = (int)logLevel,
            EventId = eventId.Id,
            EventName = eventId.Name,
            Category = _categoryName,
            Exception = exception?.ToString(),
            Message = formatter(state, exception),
        };

        // Append the data of all BeginScope and LogXXX parameters to the message dictionary
        AppendScope(message.Scope, state);
        AppendScope(message.Scope);

        _writer.WriteLine(JsonConvert.SerializeObject(message, Formatting.None));
    }

    private void AppendScope(IDictionary<string, object> dictionary)
    {
        ScopeProvider.ForEachScope((scope, state) => AppendScope(state, scope), dictionary);
    }

    private static void AppendScope(IDictionary<string, object> dictionary, object scope)
    {
        if (scope == null)
            return;

        // The scope can be defined using BeginScope or LogXXX methods.
        // - logger.BeginScope(new { Author = "meziantou" })
        // - logger.LogInformation("Hello {Author}", "meziaantou")
        // Using LogXXX, an object of type FormattedLogValues is created. This type is internal but it implements IReadOnlyList, so we can use it.
        // https://github.com/aspnet/Extensions/blob/cc9a033c6a8a4470984a4cc8395e42b887c07c2e/src/Logging/Logging.Abstractions/src/FormattedLogValues.cs
        if (scope is IReadOnlyList<KeyValuePair<string, object>> formattedLogValues)
        {
            if (formattedLogValues.Count > 0)
            {
                foreach (var value in formattedLogValues)
                {
                    // MethodInfo is set by ASP.NET Core when reaching a controller. This type cannot be serialized using JSON.NET, but I don't need it.
                    if (value.Value is MethodInfo)
                        continue;

                    dictionary[value.Key] = value.Value;
                }
            }
        }
        else
        {
            // The idea is to get the value of all properties of the object and add them to the dictionary.
            //      dictionary["Prop1"] = scope.Prop1;
            //      dictionary["Prop2"] = scope.Prop2;
            //      ...
            // We always log the same objects, so we can create a cache of compiled expressions to fill the dictionary.
            // Using reflection each time would slow down the logger.
            var appendToDictionaryMethod = ExpressionCache.GetOrCreateAppendToDictionaryMethod(scope.GetType());
            appendToDictionaryMethod(dictionary, scope);
        }
    }

    // In ASP.NET Core 3.0 this classes is now internal. This means you need to add it to your code.
    private sealed class NullScope : IDisposable
    {
        public static NullScope Instance { get; } = new NullScope();
        private NullScope() { }
        public void Dispose() { }
    }

    // Create and cache compiled expression to fill the dictionary from an object
    private static class ExpressionCache
    {
        public delegate void AppendToDictionary(IDictionary<string, object> dictionary, object o);

        private static readonly ConcurrentDictionary<Type, AppendToDictionary> s_typeCache = new ConcurrentDictionary<Type, AppendToDictionary>();
        private static readonly PropertyInfo _dictionaryIndexerProperty = GetDictionaryIndexer();

        public static AppendToDictionary GetOrCreateAppendToDictionaryMethod(Type type)
        {
            return s_typeCache.GetOrAdd(type, t => CreateAppendToDictionaryMethod(t));
        }

        private static AppendToDictionary CreateAppendToDictionaryMethod(Type type)
        {
            var dictionaryParameter = Expression.Parameter(typeof(IDictionary<string, object>), "dictionary");
            var objectParameter = Expression.Parameter(typeof(object), "o");

            var castedParameter = Expression.Convert(objectParameter, type); // cast o to the actual type

            // Create setter for each properties
            // dictionary["PropertyName"] = o.PropertyName;
            var properties = type.GetProperties(BindingFlags.Instance | BindingFlags.Public | BindingFlags.FlattenHierarchy);
            var setters =
                from prop in properties
                where prop.CanRead
                let indexerExpression = Expression.Property(dictionaryParameter, _dictionaryIndexerProperty, Expression.Constant(prop.Name))
                let getExpression = Expression.Property(castedParameter, prop.GetMethod)
                select Expression.Assign(indexerExpression, getExpression);

            var body = new List<Expression>(properties.Count + 1);
            body.Add(castedParameter);
            body.AddRange(setters);

            var lambdaExpression = Expression.Lambda<AppendToDictionary>(Expression.Block(body), dictionaryParameter, objectParameter);
            return lambdaExpression.Compile();
        }

        // Get the PropertyInfo for IDictionary<string, object>.this[string key]
        private static PropertyInfo GetDictionaryIndexer()
        {
            var indexers = from prop in typeof(IDictionary<string, object>).GetProperties(BindingFlags.Instance | BindingFlags.Public)
                           let indexParameters = prop.GetIndexParameters()
                           where indexParameters.Length == 1 && typeof(string).IsAssignableFrom(indexParameters[0].ParameterType)
                           select prop;

            return indexers.Single();
        }
    }
}

To integrate the logger in ASP.NET, you need to implement the ILoggerProvider interface. This interface contains only one method: CreateLogger(string categoryName). This method returns an instance of ILogger. To not instantiate to much objects, you can use a dictionary to store existing instances and reuse them when needed.

public sealed class JsonLoggerProvider : ILoggerProvider
{
    private readonly LoggerExternalScopeProvider _scopeProvider = new LoggerExternalScopeProvider();
    private readonly ConcurrentDictionary<string, JsonLogger> _loggers = new ConcurrentDictionary<string, JsonLogger>(StringComparer.Ordinal);

    public ILogger CreateLogger(string categoryName)
    {
        return _loggers.GetOrAdd(categoryName, category => new JsonLogger(Console.Out, category, _scopeProvider));
    }

    public void Dispose()
    {
    }
}

Finally, you can integrate the logger in the ASP.NET Core. Open the Program.cs file and edit the main method to replace existing loggers by the JSON logger.

// In ASP.NET Core 2
public static IWebHostBuilder CreateWebHostBuilder(string[] args) =>
    WebHost.CreateDefaultBuilder(args)
        .ConfigureLogging((host, builder) =>
        {
            // Register json logger in non-development environments only.
            if (!host.HostingEnvironment.IsDevelopment())
            {
                // Remove default loggers
                foreach (var s in builder.Services.Where(service => service.ServiceType == typeof(ILoggerProvider)).ToList())
                {
                    builder.Services.Remove(s);
                }

                builder.Services.AddSingleton<ILoggerProvider, JsonLoggerProvider>();
            }
        })
        .UseStartup<Startup>();

// In .NET Core 3.0
public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureLogging((host, builder) =>
        {
            // Register json logger in non-development environments only.
            if (!host.HostingEnvironment.IsDevelopment())
            {
                // Remove default loggers
                foreach (var s in builder.Services.Where(service => service.ServiceType == typeof(ILoggerProvider)).ToList())
                {
                    builder.Services.Remove(s);
                }

                builder.Services.AddSingleton<ILoggerProvider, JsonLoggerProvider>();
            }
        })
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
            webBuilder.UseKestrel(options => options.AddServerHeader = false);
        });

That's it. The application now outputs logs as JSON in the console.

Do you have a question or a suggestion about this post? Contact me!

Follow me:
Enjoy this blog?Buy Me A Coffee