Using Serilog with Concurrency Keys

In a previous article I wrote about using middleware to add concurrency keys into an Asp.Net Core project. I'd like to extend that and show how to integrate a logging platform with concurrency keys. Our .Net Core logging framework of choice is Serilog. They have great integration with common logging protocols, and there stuff is very extensible.

Logging with Serilog

Serilog allows a developer to inject properties into the LogContext. The LogContext This allows us to take properties and map them to the log templates. First, we'll create a piece of middleware to push the concurrency key into the LogContext for Serilog.

public class SerilogConcurrencyMiddleware
{
    private readonly RequestDelegate next;

    public SerilogConcurrencyMiddleware(RequestDelegate next)
    {
        this.next = next;
    }

    public Task Invoke(HttpContext context)
    {
        var key = context.Request.Headers["X-Concurrency-Key"];
        if (string.IsNullOrWhiteSpace(key))
            return next(context);

        using (LogContext.PushProperty("ConcurrencyKey", key.FirstOrDefault()))
        {
            return next(context);
        }
    }
}

The code is not complete without the tests. Make sure you include "Serilog.Sinks.TestCorrelator" NuGet package in your test project. This allows verifying the information in the LogContext.

public class SerilogConcurrencyMiddlewareTests
{
    public SerilogConcurrencyMiddlewareTests()
    {
    }

    private HttpContext BuildContext()
    {
        Log.Logger = new LoggerConfiguration()
            .Enrich.FromLogContext()
            .WriteTo.TestCorrelator().CreateLogger();

        var context = new DefaultHttpContext();
        return context;
    }

    private async Task<LogEvent> BuildAndRunMiddleware(HttpContext context)
    {
        LogEvent loggedEvent = null;
        var middleware = new SerilogConcurrencyMiddleware(next: (inner) =>
        {
            // Need to create a context specifically for this
            // request or properties disappear or move to other
            // unit tests (bad).
            using (TestCorrelator.CreateContext())
            {
                Log.Information("{ConcurrencyKey} Woo!");
                loggedEvent = TestCorrelator
                    .GetLogEventsFromCurrentContext()
                    .ToList().FirstOrDefault();
                return Task.FromResult(0);
            }
        });
        await middleware.Invoke(context);
        return loggedEvent;
    }

    [Fact]
    public async Task Invoke_NoHeader_DoesntThrowException()
    {
        var context = BuildContext();

        var result = await BuildAndRunMiddleware(context);

        Assert.True(result.Properties.Count < 1);
    }

    [Fact]
    public async Task Invoke_KeyHeader_LogHasKey()
    {
        var context = BuildContext();
        context.Request.Headers.Add("X-Concurrency-Key", "Bacon");

        var result = await BuildAndRunMiddleware(context);

        Assert.True(result.Properties.Count > 0);
        Assert.True(result.Properties.ContainsKey("ConcurrencyKey"));
        Assert.Contains("Bacon", result.RenderMessage());
    }
}

Once there is middleware and tests in place, simply add the middleware to the application pipeline.

app.UseMiddleware<SerilogConcurrencyMiddleware>();

Here is an example Serilog template in the appsettings.json to display the concurrency keys.

"Serilog": {
  "Using":  [
    "Serilog.Sinks.Console"
  ],
  "MinimumLevel": "Warning",
  "WriteTo": [
    {
      "Name": "Console",
      "Args":
          {
              "outputTemplate": "{Timestamp:MMM d HH:mm:ss} {ConcurrencyKey} {Level:u4}: {Message}{NewLine}{Exception}"
          }
    }
  ],
  "Enrich": ["FromLogContext"],
  "Properties": {
    "Application": "MyAwesomeApplication"
  }
}

I hope this helps.