/ .net

ASP.NET CORE 2 Request and Response logging

Recently I was working on a project that had a requirement to log both the incoming request and the outgoing response.

Example Excerpt from a Startup.cs with Logging Middleware added

public void Configure(IApplicationBuilder app, IHostingEnvironment env)
{
  if (env.IsDevelopment())
  {
    app.UseDeveloperExceptionPage();
  }
      
  app.UseMiddleware<ExceptionHandlingMiddlware>();
  app.UseMiddleware<LoggingMiddleWare>();
  app.UseMvc();
}

Logging the request seemed to be pretty easy. Logging of the response gets a little tricky because the pipeline assumes that it's a forward only output stream. So rewinding it to log what was written is implicitly not supported. Sometime depending on the pipeline you're using to test your middleware, you'll get behavior that looks like it should work but it won't when you deploy it or run it via a different pipeline where the streams are different.

LoggingMiddlware

public class LoggingMiddleware
{
  private readonly RequestDelegate _next;
  private readonly ILogger<LoggingMiddleware> _logger;
  
  public LoggingMiddleware(RequestDelegate next, ILogger<LoggingMiddleware> logger)
  {
    _next = next;
    _logger = logger;
  }

  public async Task Invoke(HttpContext context)
  {
    using (var loggableResponseStream = new MemoryStream())
    {
      var originalResponseStream = context.Response.Body;
      context.Response.Body = loggableResponseStream;
      
      try
      {
        // Log request
        _logger.LogInformation(await FormatRequest(context.Request));

        await _next(context);

        // Log response
       _logger.LogInformation(await FormatResponse(loggableResponseStream, context.Response.StatusCode));
       //reset the stream position to 0
       loggableResponseStream.Seek(0, SeekOrigin.Begin);
       await loggableResponseStream.CopyToAsync(originalResponseStream);
      }
      catch (Exception ex)
      {
        // Log error
        _logger.LogError(ex, ex.Message);

       //allows exception handling middleware to deal with things
       throw;
      }
      finally
      {
        //Reassign the original stream. If we are re-throwing an exception this is important as the exception handling middleware will need to write to the response stream.
        context.Response.Body = originalResponseStream;
      }
   }
}

  private static async Task<string> FormatRequest(HttpRequest request)
  {
    var body = request.Body;
    request.EnableRewind();
    var buffer = new byte[Convert.ToInt32(request.ContentLength)];
    await request.Body.ReadAsync(buffer, 0, buffer.Length);
    var bodyAsText = Encoding.UTF8.GetString(buffer);
    request.Body = body;

    var messageObjToLog = new { scheme = request.Scheme, host = request.Host, path = request.Path, queryString = request.Query, requestBody = bodyAsText };

    return JsonConvert.SerializeObject(messageObjToLog);
  }

  private static async Task<string> FormatResponse(Stream loggableResponseStream,int statusCode)
  {
    var buffer = new byte[loggableResponseStream.Length];
    await loggableResponseStream.ReadAsync(buffer, 0, buffer.Length);

    var messageObjectToLog = new { responseBody = Encoding.UTF8.GetString(buffer), statusCode = statusCode};
            
    return JsonConvert.SerializeObject(messageObjectToLog);
  }
}

The long and the short of the situation is this:
If you want to get in the middle of the response process where you're rewinding the stream in order to get what was written to it, your middleware effectively needs to hold a reference to the original response stream, put in it's own MemoryStream, then copy it out to the original response stream and re-attaches it to the response. Simple huh?!

ASP.NET CORE 2 Request and Response logging
Share this