How should async logging to database be implemented in asp.net core application?

Question

There's an ILogger in asp.net core (or in other libraries too), and I can setup my code to write logs to azure or database or console etc, but what I'm wondering about is that this ILogger is synchronous. On docs.microsoft I read about this they said "logger should be synchronous, consider writing logs to some queue and have a background worker pulling these logs to your database". Now, I have a couple of questions.

Should I bother about my own implementation of async logging, or asp.net core does it for me already? because there are so many concerns about this and it's not an easy thing to do in terms of time.
How would you implement async logging, if I want to not use fire-and-forget methods and not make users wait for every logging task to complete? It would also be nice to implement it all in one separate aspect, to not make the code dirty, free it from cross-cutting concerns.

Maybe I'm asking a dumb question or a broad one but this is a broad topic to me that I don't really understand. Please help. Also I would like to see some code examples (some github repos or something)

I think your "own" implementation of async logging to db would be using _context.AddAsync and _context.SaveChangesAsync(). What I would do is creating a log class using EF, write the log to the class instance and when I am done, just run the Async operations above, unless I am totally misunderstood you... — Yaniv Amrami
ILogger is definitely synchronous. I am searching for async solution also — zoran

cmxl cmxl · Accepted Answer · 2021-03-06T17:53:05

What Microsoft is doing in their implementation of the ConsoleLogger is using a background thread which will write queued messages to the console. I just implemented something similar but with an EF Core context instead.

The original implementation can be found here: https://github.com/dotnet/runtime/blob/main/src/libraries/Microsoft.Extensions.Logging.Console/src/ConsoleLoggerProcessor.cs

My implementation looks something like this:

public class RequestLogProcessor : IDisposable
    {
        private readonly BlockingCollection<RequestLog> _queue;
        private readonly Thread _writingThread;
        private readonly DbContext _context;

        public RequestLogProcessor(DbContext context, RequestLoggerConfiguration configuration)
        {
            _queue = new BlockingCollection<RequestLog>(configuration.Buffer);
            _context = context;
            _writingThread = new Thread(WriteQueue)
            {
                IsBackground = true,
                Name = "RequestLogProcessor Thread"
            };
            _writingThread.Start();
        }

        private void WriteQueue()
        {
            try
            {
                foreach (var message in _queue.GetConsumingEnumerable())
                {
                    WriteMessage(message);
                }
            }
            catch
            {
                try
                {
                    _queue.CompleteAdding();
                }
                catch { }
            }
        }

        public void Enqueue(RequestLog log)
        {
            if (!_queue.IsAddingCompleted)
            {
                try
                {
                    _queue.Add(log);
                    return;
                }
                catch (InvalidOperationException) { }
            }

            try
            {
                WriteMessage(log);
            }
            catch (Exception) { }
        }

        private void WriteMessage(RequestLog log)
        {
            _context.RequestLogs.Add(log);
            _context.SaveChanges();
        }

        public void Dispose()
        {
            _queue.CompleteAdding();

            try
            {
                _writingThread.Join(1500);
            }
            catch (ThreadStateException) { }
        }
    }

You would use this class in your implementation of ILoggers Log<TState> function like so:

public class RequestLogger : ILogger
    {
        private readonly RequestLoggerConfiguration _config;
        private readonly RequestLogProcessor _processor;

        public RequestLogger(
            RequestLoggerConfiguration config,
            RequestLogProcessor processor)
        {
            _config = config;
            _processor = processor;
        }

        public IDisposable BeginScope<TState>(TState state)
            => default;

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

        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
        {
            if (!IsEnabled(logLevel))
                return;

            if (state is not RequestLog log)
                return;

            log.Exception ??= exception?.ToString();
            log.Level = logLevel.ToString();

            _processor.Enqueue(log); // this is the line
        }
    }

This works perfectly fine in my ASP.NET Core application, although you could tweak it's performance by batch inserting logs. I did call SaveChanges() for each entry which could possibly be pretty slow.

In your case you can just create the Thread with an async function delegate:

new Thread(async() => await WriteQueue()) and use _context.SaveChangesAsync().

EDIT(as per comment):

public class RequestLoggerConfiguration
{
    public LogLevel LogLevel { get; set; } = LogLevel.Error;
    public int Buffer { get; set; } = 1024;
}

How should async logging to database be implemented in asp.net core application?

1 Answers