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.

Westbrook

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}";
    }
}

Westbrook

Hi, what is GetEndpoint() ? it does not seems to be available in Core 3.1 (also not when using IHttpContextAccessor). – Thinker

@Thinker Hi. GetEndpoint() is an extension method of HttpContext object. It comes from NuGet package Microsoft.AspNetCore.Http.Extensions 2.2.0 – Westbrook

See my comment for adding extensions app uses.net core 3.0 or later #61848321 – Pampas

Can anyone help to know where will the log is stored, I have tried this code. I am saving the logs in a text file using the serilog. But the log from here doesn't store in the text file. Is there any separate thing I have to add to this code? – Unguinous

@aakash as far as I remember, this should be configured in the appsettings.json of your project, see here – Westbrook

@Westbrook thanks i made this work by adding in the appsettings.json – Unguinous

httpContext.GetEndpoint() does not exist anywhere in .Net 7 even with the additional package installed. – Cwm

Answer 2

The accepted answer is not thread-safe.

LogHelper.RequestPayload = requestBodyPayload;

This assignment can lead to unexpected logging result when there are multiple concurrent requests.
Instead of using a static variable I pushed the request body directly in a LogContext property of Serilog.

Pungy

Answer 3

If logging in to the file we can add the following code with the answer from @Vladimir in .net core 5.0.

Add UseSerilog in Program.cs

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
        })
        .UseSerilog((hostingContext, services, loggerConfig) =>
         loggerConfig.ReadFrom.Configuration(hostingContext.Configuration)
             .WriteTo.Logger(lc => lc.Filter.ByIncludingOnly(Matching.FromSource("Serilog.AspNetCore.RequestLoggingMiddleware")).WriteTo.File(path: "Logs/WebHookLog_.log",
                 outputTemplate: "{Timestamp:o}-{RequestBody}-{ResponseBody}-{Host}-{ContentType}-{EndpointName} {NewLine}", rollingInterval: RollingInterval.Day))
        );

Fields to be added in the appsettings.json:

"Serilog": {
  "MinimumLevel": {
    "Default": "Information",
    "Override": {
      "Default": "Information",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  },
  "WriteTo": [
    { "Name": "Console" },
    {
      "Name": "File",
      "Args": {
        "path": "Logs/applog_.log",
        "outputTemplate": "{Timestamp:o} [{Level:u3}] ({SourceContext}) {Message}{NewLine}{Exception}",
        "rollingInterval": "Day",
        "retainedFileCountLimit": 7
      }
    }
  ],
  "Enrich": [ "FromLogContext", "WithMachineName" ],
  "Properties": {
    "Application": "AspNetCoreSerilogDemo"
  }
},

Unguinous