How to log the HTTP Response Body in ASP.NET Core 1.0

Question

I'm creating a public REST Api using ASP.NET Core 1.0 RC2 and like to log incoming requests and outgoing responses.

I have created a middleware class which is added to the pipeline before the call to app.UseMvc();

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
{            
        app.UseIOMiddleware();
        app.UseMvc();            
}

My Middleware class looks like this:

public class IOMiddleware
{
    private readonly RequestDelegate _next;

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

    public async Task Invoke(HttpContext context)
    {
        LogRequest(context.Request);

        await _next.Invoke(context);            
    }

    private async void LogRequest(HttpRequest request)
    {
        using (var bodyReader = new StreamReader(request.Body))
        {
            string body = await bodyReader.ReadToEndAsync();

            request.Body = new MemoryStream(Encoding.UTF8.GetBytes(body));

            System.Diagnostics.Debug.Print(body);
        }
    }
}

I can read the request body stream and rewind it using this example: Rewind request body stream, but I'm not sure how to read the response body as the stream is not readable.

In Web API 2.0 I could have used the HttpResponseMessage.Content.ReadAsByteArrayAsync() method, but how can I accomplish the same thing in ASP.Net Core 1.0 RC2?

Answer 1

The problem is that request.Body is not readable, only writable - typically the stream will periodically flushed to the client across the wire.

You can get round this by replacing the stream and buffering the content until the rest of the pipeline has completed.

public class IOMiddleware
{
    private readonly RequestDelegate _next;

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

    public async Task Invoke(HttpContext context)
    {
        await LogRequest(context.Request);

        await LogResponseAndInvokeNext(context);
    }

    private async Task LogRequest(HttpRequest request)
    {
        using (var bodyReader = new StreamReader(request.Body))
        {
            string body = await bodyReader.ReadToEndAsync();

            request.Body = new MemoryStream(Encoding.UTF8.GetBytes(body));
            System.Diagnostics.Debug.Print(body);
        }
    }

    private async Task LogResponseAndInvokeNext(HttpContext context)
    {
        using (var buffer = new MemoryStream())
        {
            //replace the context response with our buffer
            var stream = context.Response.Body;
            context.Response.Body = buffer;

            //invoke the rest of the pipeline
            await _next.Invoke(context);

            //reset the buffer and read out the contents
            buffer.Seek(0, SeekOrigin.Begin);
            var reader = new StreamReader(buffer);
            using (var bufferReader = new StreamReader(buffer))
            {
                string body = await bufferReader.ReadToEndAsync();

                //reset to start of stream
                buffer.Seek(0, SeekOrigin.Begin);

                //copy our content to the original stream and put it back
                await buffer.CopyToAsync(stream);
                context.Response.Body = stream;

                System.Diagnostics.Debug.Print($"Response: {body}");

            }
        }
    }
}

Answer 2

Unfortunately if you replace Request with MemoryStream, the same stream will be used for future calls. Here is the bug: https://github.com/aspnet/KestrelHttpServer/issues/940

The workaround is to copy Request.Body stream to local variable and set Body back to original stream in the end.

Like this:

  public async Task Invoke(HttpContext context)
    {
        //Workaround - copy original Stream
        var initalBody = context.Request.Body;

        using (var bodyReader = new StreamReader(request.Body))
        {
            string body = await bodyReader.ReadToEndAsync();
            //Do something with body
            //Replace write only request body with read/write memorystream so you can read from it later

               request.Body = new MemoryStream(Encoding.UTF8.GetBytes(body));

        //handle other middlewares
        await _next.Invoke(context);

        //Workaround - return back to original Stream
        context.Request.Body = initalBody;
    }

Answer 3

after searching everywhere this is the class I ended up with. it's working fine for me and handles the case where there is an exception [it used to not return any response but logs it successfully!!]. This is a collective products of so many posts online.

using Microsoft.AspNetCore.Http;
using System;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Threading.Tasks;
using Microsoft.AspNet.Http.Internal;
using Microsoft.AspNetCore.Http.Internal;



public class LoggerMiddleware
{
    private readonly RequestDelegate _next;

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

    public async Task Invoke(HttpContext context)
    {
        using (MemoryStream requestBodyStream = new MemoryStream())
        using (MemoryStream responseBodyStream = new MemoryStream())
        {
            Stream originalRequestBody = context.Request.Body;
            context.Request.EnableRewind();
            Stream originalResponseBody = context.Response.Body;

            try
            {
                await context.Request.Body.CopyToAsync(requestBodyStream);
                requestBodyStream.Seek(0, SeekOrigin.Begin);

                string requestBodyText = new StreamReader(requestBodyStream).ReadToEnd();

                requestBodyStream.Seek(0, SeekOrigin.Begin);
                context.Request.Body = requestBodyStream;

                string responseBody = "";

                context.Response.Body = responseBodyStream;

                Stopwatch watch = Stopwatch.StartNew();
                    await _next(context);
                    watch.Stop();

                responseBodyStream.Seek(0, SeekOrigin.Begin);
                responseBody = new StreamReader(responseBodyStream).ReadToEnd();
                AuditLogger.LogToAudit(context.Request.Host.Host,
                    context.Request.Path, context.Request.QueryString.ToString(), context.Connection.RemoteIpAddress.MapToIPv4().ToString(),
                        string.Join(",", context.Request.Headers.Select(he => he.Key + ":[" + he.Value + "]").ToList()),
                        requestBodyText, responseBody, DateTime.Now, watch.ElapsedMilliseconds);

                responseBodyStream.Seek(0, SeekOrigin.Begin);

                await responseBodyStream.CopyToAsync(originalResponseBody);
            }
            catch (Exception ex)
            {
                ExceptionLogger.LogToDatabse(ex);
                byte[] data = System.Text.Encoding.UTF8.GetBytes("Unhandled Error occured. Please, try again in a while.");
                originalResponseBody.Write(data, 0, data.Length);
            }
            finally
            {
                context.Request.Body = originalRequestBody;
                context.Response.Body = originalResponseBody;
            }
        }
    }
}