Serilog logging web-api methods, adding context properties inside middleware

Question

I've been struggling to log response body payload data with serilog, logging from middleware. I'm working on WEB API Core application, with swagger added to endpoints, and my goal is to log every endpoint call to a .json file with serilog (both request and response data).

For GET requests, body of the response should be logged (added to serilog context as a property), and for POST requests, both body of request and response should be logged. I have created middleware and managed to properly retrieve data from request and response stream, and getting it as a string, but only the "RequestBody" is being logged properly.

When debugging, I can see that reading request/response body works fine.

Following is the code excerpt from Program->Main method:

Log.Logger = new LoggerConfiguration()
    .ReadFrom.Configuration(configuration)
    .Enrich.FromLogContext()
    .CreateLogger();

and code in the middleware:

public async Task Invoke(HttpContext context)
{
    // Read and log request body data
    string requestBodyPayload = await ReadRequestBody(context.Request);

    LogContext.PushProperty("RequestBody", requestBodyPayload);

    // Read and log response body data
    var originalBodyStream = context.Response.Body;
    using (var responseBody = new MemoryStream())
    {
        context.Response.Body = responseBody;
        await _next(context);
        string responseBodyPayload = await ReadResponseBody(context.Response);

        if (!context.Request.Path.ToString().EndsWith("swagger.json") && !context.Request.Path.ToString().EndsWith("index.html"))
        {
            LogContext.PushProperty("ResponseBody", responseBodyPayload);
        }

        await responseBody.CopyToAsync(originalBodyStream);
    }
}

private async Task<string> ReadRequestBody(HttpRequest request)
{
    HttpRequestRewindExtensions.EnableBuffering(request);

    var body = request.Body;
    var buffer = new byte[Convert.ToInt32(request.ContentLength)];
    await request.Body.ReadAsync(buffer, 0, buffer.Length);
    string requestBody = Encoding.UTF8.GetString(buffer);
    body.Seek(0, SeekOrigin.Begin);
    request.Body = body;

    return $"{requestBody}";
}

private async Task<string> ReadResponseBody(HttpResponse response)
{
    response.Body.Seek(0, SeekOrigin.Begin);
    string responseBody = await new StreamReader(response.Body).ReadToEndAsync();
    response.Body.Seek(0, SeekOrigin.Begin);

    return $"{responseBody}";
}

As I mentioned, "RequestBody" is properly logged to file, but nothing for "ResponseBody" (not even added as a property) Appreciate any help.

Answer 1

After collecting informations from several posts, and customizing it to my needs, I have found a way to log both request and response body data as properties of serilog log structure.

I didn't find a way to log both request and response body in one place only (in the Invoke method of the middleware), but I found a workaround. Because of the nature of the request processing pipeline, here is what I had to do:

Code in the Startup.cs:

app.UseMiddleware<RequestResponseLoggingMiddleware>();
app.UseSerilogRequestLogging(opts => opts.EnrichDiagnosticContext = LogHelper.EnrichFromRequest);

• I have used LogHelper class for enriching request properties, just as described in the Andrew Locks post.

• when request processing hits the middleware, in the middleware's Invoke method I am reading only request body data, and setting this value to a static string property that I've added to LogHelper class. This way I have read and stored request body data as string, and can add it as enricher when LogHelper.EnrichFromRequest method gets called

• after reading request body data, I am copying a pointer to the original response body stream

• await _next(context); gets called next, context.Response is populated, and request processing exits out from middleware's Invoke method, and goes to LogHelper.EnrichFromRequest

• at this moment LogHelper.EnrichFromRequest is executing, reading response body data now, and setting it as enricher, as well as previously stored request body data and some additional properties

• processing returns to middleware Invoke method (right after await _next(context);), and copying the contents of the new memory stream (which contains the response) to the original stream,

Following is the code described above in LogHelper.cs and RequestResponseLoggingMiddleware.cs classes:

LogHelper.cs:

public static class LogHelper
{
    public static string RequestPayload = "";

    public static async void EnrichFromRequest(IDiagnosticContext diagnosticContext, HttpContext httpContext)
    {
        var request = httpContext.Request;

        diagnosticContext.Set("RequestBody", RequestPayload);

        string responseBodyPayload = await ReadResponseBody(httpContext.Response);
        diagnosticContext.Set("ResponseBody", responseBodyPayload);

        // Set all the common properties available for every request
        diagnosticContext.Set("Host", request.Host);
        diagnosticContext.Set("Protocol", request.Protocol);
        diagnosticContext.Set("Scheme", request.Scheme);

        // Only set it if available. You're not sending sensitive data in a querystring right?!
        if (request.QueryString.HasValue)
        {
            diagnosticContext.Set("QueryString", request.QueryString.Value);
        }

        // Set the content-type of the Response at this point
        diagnosticContext.Set("ContentType", httpContext.Response.ContentType);

        // Retrieve the IEndpointFeature selected for the request
        var endpoint = httpContext.GetEndpoint();
        if (endpoint is object) // endpoint != null
        {
            diagnosticContext.Set("EndpointName", endpoint.DisplayName);
        }
    }

    private static async Task<string> ReadResponseBody(HttpResponse response)
    {
        response.Body.Seek(0, SeekOrigin.Begin);
        string responseBody = await new StreamReader(response.Body).ReadToEndAsync();
        response.Body.Seek(0, SeekOrigin.Begin);

        return $"{responseBody}";
    }
}

RequestResponseLoggingMiddleware.cs:

public class RequestResponseLoggingMiddleware
{
    private readonly RequestDelegate _next;

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

    public async Task Invoke(HttpContext context)
    {
        // Read and log request body data
        string requestBodyPayload = await ReadRequestBody(context.Request);
        LogHelper.RequestPayload = requestBodyPayload;

        // Read and log response body data
        // Copy a pointer to the original response body stream
        var originalResponseBodyStream = context.Response.Body;

        // Create a new memory stream...
        using (var responseBody = new MemoryStream())
        {
            // ...and use that for the temporary response body
            context.Response.Body = responseBody;

            // Continue down the Middleware pipeline, eventually returning to this class
            await _next(context);

            // Copy the contents of the new memory stream (which contains the response) to the original stream, which is then returned to the client.
            await responseBody.CopyToAsync(originalResponseBodyStream);
        }
    }

    private async Task<string> ReadRequestBody(HttpRequest request)
    {
        HttpRequestRewindExtensions.EnableBuffering(request);

        var body = request.Body;
        var buffer = new byte[Convert.ToInt32(request.ContentLength)];
        await request.Body.ReadAsync(buffer, 0, buffer.Length);
        string requestBody = Encoding.UTF8.GetString(buffer);
        body.Seek(0, SeekOrigin.Begin);
        request.Body = body;

        return $"{requestBody}";
    }
}