Joshua Chini

One design pattern related to micro services that I have read about and wanted to try to implement is correlation id’s. Correlation id’s allow distributed tracing within complex service oriented platforms, where a single request into the application can often be dealt with by multiple downstream services. Without the ability to correlate downstream service requests it can be very difficult to understand how requests are being handled within your platform. Here is a diagram that depicts how the correlation Id initially gets created by the first service and how the correlation id is passed to each additional service and used by all services when logging.

In this article we will tackle the request handler which will

• Generate the correlation id if it is not found in the request headers
• Add the correlation id to the logging context so that each log entry contains the correlation id
• Append the correlation id to the response header so that upstream services can take advantage of it

In ASP.NET MVC 5 you would create a message handler to perform actions on each request. In ASP.NET MVC 6 this has been replaced with middleware. You can find documentation on middleware on the docs.asp.net site. After reading the documentation and following the CodeLabs middleware tutorial I was able to write this piece of middleware.

public class CorrelationIdMiddleware
{
    private readonly RequestDelegate _next;
    private readonly ILogger _logger;

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

    public async Task Invoke(HttpContext context)
    {
        string correlationId = null;
        var key = context.Request.Headers.Keys.FirstOrDefault(n =n.ToLower().Equals("x-correlation-id"));
        if (!string.IsNullOrWhiteSpace(key))
        {
            correlationId = context.Request.Headers[key];
            _logger.LogInformation("Header contained CorrelationId: {@CorrelationId}", correlationId);
        }
        else
        {
            correlationId = Guid.NewGuid().ToString();
            _logger.LogInformation("Generated new CorrelationId: {@CorrelationId}", correlationId);
        }
        context.Response.Headers.Append("x-correlation-id", correlationId);
        using (LogContext.PushProperty("CorrelationId", correlationId))
        {
            await _next.Invoke(context);
        }
    }
}

It checks to see if a correlation id was passed in and if not generates a new id. It then appends the correlation id to the response header and adds the correlation id to the log context. Now that we have the middleware written we want to create an extension method that we can call to register it in the Startup.cs configure method.

public static class CorrelationIdExtensions
{
    public static IApplicationBuilder UseCorrelationId(this IApplicationBuilder builder)
    {
        return builder.UseMiddleware<CorrelationIdMiddleware>();
    }
}

Here is what the Configure method looks like in the Startup.cs file where we register our new middleware.

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
{
    loggerFactory.AddConsole(Configuration.GetSection("Logging"));
    loggerFactory.AddDebug();
    loggerFactory.AddSerilog();
    app.UseCorrelationId();
    app.UseMvc();
}

And finally here is the constructor method in Startup.cs where we register Serilog and define the output template which contains the correlation id.

public Startup(IHostingEnvironment env)
{
    Log.Logger = new LoggerConfiguration()
        .MinimumLevel.Debug()
        .Enrich.With(new ThreadIdEnricher())
        .Enrich.FromLogContext()
        .WriteTo.LiterateConsole()
        .WriteTo.RollingFile(
        Environment.ExpandEnvironmentVariables(@"%southernroot%\logs\EmployeeDirectory.log"),
        outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fffzz} [{Level}] {ThreadId} ({CorrelationId}) {Message}{NewLine}{Exception}")
        .CreateLogger();

    var builder = new ConfigurationBuilder()
        .SetBasePath(env.ContentRootPath)
        .AddJsonFile("appsettings.json", true, true)
        .AddJsonFile($"appsettings.{env.EnvironmentName}.json", true)
        .AddEnvironmentVariables();
    Configuration = builder.Build();
}

Below is a sample from the log file showing the correlation id.

Here is a sample from the log file showing a multi-threaded operation where the thread id’s change, but the correlation id remains the same.

This final log sample shows multiple request coming in to our action that generates multiple threads and that each request has a different correlation id.

Now that we have our middleware built in part 2 of this series we will look at how to override the HTTP client calls to include the correlation id on every service call.