ASP.NET Core request logging middleware

I needed to debug an error logged through Microsoft.Extensions.Logging (MEL) on one of our ASP.NET Core-based services today. Usually, when getting errors logged through MEL, all of the HTTP context data is logged as part of the error, making it easy to spot why an error happened or at least making it a lot easier recreating the error. Today's error didn't include much more information than an error message and a request-id.

To help debug what is turning sideways, I created a quick request logging feature in ASP.NET Core. There are multiple posts on the subject already, but while most of them are really good posts, they often cover too much for my simple use case or leave out essential information about how to create the configuration. I simply want a log message for each request, with as little information as possible, but enough for me to be able to correlate the generated error with an HTTP request.

To log a message on every web request, start by creating a new class named RequestLoggingMiddleware:

public class RequestLoggingMiddleware
{
}

Add the following locals:

private readonly RequestDelegate _next;
private readonly ILogger _logger;

I'll explain what these are and what they are used for in a bit. Create a constructor on the class:

public RequestLoggingMiddleware(RequestDelegate next, ILoggerFactory loggerFactory)
{
    _next = next;
    _logger = loggerFactory.CreateLogger<RequestLoggingMiddleware>();
}

I set the RequestDelegate local added in the previous step and create a new MEL ILogger for my middleware class.

Finally, add a new Invoke method:

public async Task Invoke(HttpContext context)
{
    try
    {
        await _next(context);
    }
    finally
    {
        _logger.LogInformation(
            "Request {method} {url} => {statusCode}",
            context.Request?.Method,
            context.Request?.Path.Value,
            context.Response?.StatusCode);
    }
}

This is where the magic happens. The method invokes the next piece of ASP.NET Core middleware and logs an information message with the HTTP method, URL and status code. To avoid repeating myself, check out Error Logging Middleware for a detailed explanation of how ASP.NET Core middleware works.

Here's the source for the entire class:

using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using System.Threading.Tasks;

namespace My.Service.Logging
{
    public class RequestLoggingMiddleware
    {
        private readonly RequestDelegate _next;
        private readonly ILogger _logger;

        public RequestLoggingMiddleware(RequestDelegate next, ILoggerFactory loggerFactory)
        {
            _next = next;
            _logger = loggerFactory.CreateLogger<RequestLoggingMiddleware>();
        }

        public async Task Invoke(HttpContext context)
        {
            try
            {
                await _next(context);
            }
            finally
            {
                _logger.LogInformation(
                    "Request {method} {url} => {statusCode}",
                    context.Request?.Method,
                    context.Request?.Path.Value,
                    context.Response?.StatusCode);
            }
        }
    }
}

The only missing part now is configuring the middleware. You'd normally create an extension method to help, but in this case I'm taking the easy path and call the UseMiddleware method directly in my Startup.cs class:

public void Configure(IApplicationBuilder app, IHostingEnvironment env)
{
    ...
    app.UseMiddleware<RequestLoggingMiddleware>();
    ...
}

That's it. Every request now generates a log message in the configured log. In my case, I'm logging to elmah.io. I'm using the Elmah.Io.Extensions.Logging NuGet package to do the actual logging and the Elmah.Io.AspNetCore.ExtensionsLogging package to decorate all log messages with HTTP contextual information.

I normally don't log information messages from production, since ASP.NET Core generates a lot of info messages out of the box. In this example, I want to log all Warning, Error, and Fatal messages, but also the new Information messages generated from the new middleware class. This can be set up by including the following config in appsettings.json:

{
  "Logging": {
    "ElmahIo": {
      "LogLevel": {
        "Default": "Warning",
        "My.Service.Logging": "Information"
      }
    }
  },
  ...
}

Inside the Logging section, I've included an ElmahIo section. If you are using Console or another logger, you will need to replace the section name with the correct one. By including a Default log level and setting the value to Warning, I make sure that only Warning messages and up are logged. For the specific namespace My.Service.Logging I also allow Information messages.

To use the configuration from the Logging section, call the AddConfiguration method as part of your logging initialization in the Program.cs file:

public static IWebHostBuilder CreateWebHostBuilder(string[] args) =>
    WebHost.CreateDefaultBuilder(args)
        .UseStartup<Startup>()
        .ConfigureLogging((ctx, logging) =>
        {
            logging.AddConfiguration(ctx.Configuration.GetSection("Logging"));
            ...
        });

Everything is done in less than 30 minutes and ready to go to production. Here's an example of a log message stored in elmah.io:

If you are using another logger, the view will be different but you will be able to see all of the same information.