Log REST-requests to file with unique request-id

Question

Lets say I have a simple REST-API written in .net 6 which logs to a log-file on the lokal disk. During the processing of the request, multiple log-entries are generated. For example, let's say we have a controller, which calls a service, which calls a repository which stores the passed data in the database:

public class FooController {
    [HttpPost]
    public Foo CreateFoo(FooDto fooDto) {
        _logger.Debug("Some logging in the controller");
        var foo = _mapper.Map<IFoo>(fooDto);
        _fooService.CreateFoo(foo);
    }
}

public class FooService {
    public void CreateFoo(IFoo foo) {
        _logger.Debug("Some logging in the service");
        _fooRepository.Create(foo);
    }
}

public class FooRepository {
    public void CreateFoo(IFoo foo) {
        _logger.Debug("Some logging in the repository");
    }
}

If there are multiple requests to process in parallel, reading the log-files will be a challenge. Some kind of unique id per request would help to keep the requests apart when reading the log-file.

Something like this for example:

2023-08-07 08:40:06.3280 DEBUG REQUEST-ID FooController Some logging in the controller
2023-08-07 08:40:06.3281 DEBUG REQUEST-ID FooService    Some logging in the service
2023-08-07 08:40:06.3282 DEBUG REQUEST-ID FooRepository Some logging in the repository

Is there a build-in way (or even 3rd-party Nugets) to archieve this? I have found solutions that log the thread id, but that I would prefer some kind of GUID or random string as the thread id could be reused after the thread has been stopped.

Answer 1

I finally got it working by using a middleware and a custom serilog enricher.

The middleware creates a new trace-ID and puts it into the response headers:

public class TraceIdMiddleware
{
    private readonly RequestDelegate _next;

    public TraceIdMiddleware(RequestDelegate next)
    {
        _next = next;
    }

    public async Task Invoke(HttpContext context)
    {
        context.TraceIdentifier = Guid.NewGuid().ToString();
            
        string id = context.TraceIdentifier;
        context.Response.Headers["X-Trace-Id"] = id;
        await _next(context);
    }
}

The log enricher reads this trace-ID and sets the TraceIdentifier property:

public class TraceIdentifierEnricher : ILogEventEnricher
{
    private readonly IHttpContextAccessor _httpContextAccessor;

    public const string TraceIdentifierPropertyName = "TraceIdentifier";
    public TraceIdentifierEnricher(IHttpContextAccessor httpContextAccessor)
    {
        _httpContextAccessor = httpContextAccessor;
    }

    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        var httpContext = _httpContextAccessor.HttpContext;

        if (httpContext is null)
        {
            return;
        }

        var property = propertyFactory.CreateProperty(TraceIdentifierPropertyName, httpContext.TraceIdentifier, false);
        logEvent.AddPropertyIfAbsent(property);
    }
}

Finally, the enricher and the middleware have to be registered in the Program.cs:

builder.Services.AddSingleton<TraceIdentifierEnricher>();

builder.Logging.ClearProviders();
builder.Host.UseSerilog((ctx, serviceProvider, cfg) => {

    var enricher = serviceProvider.GetRequiredService<TraceIdentifierEnricher>();

    cfg.ReadFrom.Configuration(ctx.Configuration).Enrich.With(enricher);
});

app.UseMiddleware<TraceIdMiddleware>();

This results in the following:

[10:25:45 DBG] [1e142e1b-fa5d-4a07-a8b2-2f09efaa8f43] Some logging in the controller
[10:25:46 DBG] [1e142e1b-fa5d-4a07-a8b2-2f09efaa8f43] Some logging in the service
[10:25:46 DBG] [1e142e1b-fa5d-4a07-a8b2-2f09efaa8f43] Some logging in the repository

Here, 1e142e1b-fa5d-4a07-a8b2-2f09efaa8f43 is the randomly generated trace-ID.