Response body for request/response Logging

Question

I'm trying to write a Owin midleware component that would LOG every incoming request and response to the database.

Here's how far I managed to get.

I got stuck on reading the response.body. Says:

Stream does not support reading.

How can I read the Response.Body ?

 public class LoggingMiddleware : OwinMiddleware
 {
        private static Logger log = LogManager.GetLogger("WebApi");

        public LoggingMiddleware(OwinMiddleware next, IAppBuilder app)
            : base(next)
        {
        }

    public override async Task Invoke(IOwinContext context)
    {
        using (var db = new HermesEntities())
        {

            var sw = new Stopwatch();
            sw.Start();

            var logRequest = new log_Request
            {
                Body = new StreamReader(context.Request.Body).ReadToEndAsync().Result,
                Headers = Json.Encode(context.Request.Headers),
                IPTo = context.Request.LocalIpAddress,
                IpFrom = context.Request.RemoteIpAddress,
                Method = context.Request.Method,
                Service = "Api",
                Uri = context.Request.Uri.ToString(),
                UserName = context.Request.User.Identity.Name

            };
            db.log_Request.Add(logRequest);
            context.Request.Body.Position = 0;

            await Next.Invoke(context);

            var mem2 = new MemoryStream();
            await context.Response.Body.CopyToAsync(mem2);

            var logResponse = new log_Response
            {
                Headers = Json.Encode(context.Response.Headers),
                Body = new StreamReader(mem2).ReadToEndAsync().Result,
                ProcessingTime = sw.Elapsed,
                ResultCode = context.Response.StatusCode,
                log_Request = logRequest
            };

            db.log_Response.Add(logResponse);

            await db.SaveChangesAsync();
        }
    }
}

Answer 1

Response body is a write-only network stream by default for Katana hosts. You will need to replace it with a MemoryStream, read the stream, log the content and then copy the memory stream content back into the original network stream. BTW, if your middleware reads the request body, downstream components cannot, unless the request body is buffered. So, you might need to consider buffering the request body as well. If you want to look at some code, http://lbadri.wordpress.com/2013/08/03/owin-authentication-middleware-for-hawk-in-thinktecture-identitymodel-45/ could be a starting point. Look at the class HawkAuthenticationHandler.

Answer 2

Response Body can be logged in this manner:

public class LoggingMiddleware : OwinMiddleware
{
    private static Logger log = LogManager.GetLogger("WebApi");

    public LoggingMiddleware(OwinMiddleware next, IAppBuilder app)
        : base(next)
    {
    }

    public override async Task Invoke(IOwinContext context)
    {
        using (var db = new HermesEntities())
        {

           var sw = new Stopwatch();
           sw.Start();

           var logRequest = new log_Request
           {
               Body = new StreamReader(context.Request.Body).ReadToEndAsync().Result,
               Headers = Json.Encode(context.Request.Headers),
               IPTo = context.Request.LocalIpAddress,
               IpFrom = context.Request.RemoteIpAddress,
               Method = context.Request.Method,
               Service = "Api",
               Uri = context.Request.Uri.ToString(),
               UserName = context.Request.User.Identity.Name
           };

           db.log_Request.Add(logRequest);
           context.Request.Body.Position = 0;

           Stream stream = context.Response.Body;
           MemoryStream responseBuffer = new MemoryStream();
           context.Response.Body = responseBuffer;

           await Next.Invoke(context);

           responseBuffer.Seek(0, SeekOrigin.Begin);
           var responseBody = new StreamReader(responseBuffer).ReadToEnd();

           //do logging

           var logResponse = new log_Response
           {
               Headers = Json.Encode(context.Response.Headers),
               Body = responseBody,
               ProcessingTime = sw.Elapsed,
               ResultCode = context.Response.StatusCode,
               log_Request = logRequest
           };

           db.log_Response.Add(logResponse);

           responseBuffer.Seek(0, SeekOrigin.Begin);
           await responseBuffer.CopyToAsync(stream);

           await db.SaveChangesAsync();
        }
    }
}

Answer 3

I've solved the problem by applying an action attribute writing the request body to OWIN environment dictionary. After that, the logging middleware can access it by a key.

public class LogResponseBodyInterceptorAttribute : ActionFilterAttribute
{
    public override async Task OnActionExecutedAsync(HttpActionExecutedContext actionExecutedContext, CancellationToken cancellationToken)
    {
        if (actionExecutedContext?.Response?.Content is ObjectContent)
        {
            actionExecutedContext.Request.GetOwinContext().Environment["log-responseBody"] =
                await actionExecutedContext.Response.Content.ReadAsStringAsync();
        }
    }
}

And then in the middleware:

public class RequestLoggingMiddleware
{
    ...
    private void LogResponse(IOwinContext owinContext)
    {
        var message = new StringBuilder()
            .AppendLine($"{owinContext.Response.StatusCode}")
            .AppendLine(string.Join(Environment.NewLine, owinContext.Response.Headers.Select(x => $"{x.Key}: {string.Join("; ", x.Value)}")));

        if (owinContext.Environment.ContainsKey("log-responseBody"))
        {
            var responseBody = (string)owinContext.Environment["log-responseBody"];
            message.AppendLine()
                .AppendLine(responseBody);
        }

        var logEvent = new LogEventInfo
        {
            Level = LogLevel.Trace,
            Properties =
            {
                {"correlationId", owinContext.Environment["correlation-id"]},
                {"entryType", "Response"}
            },
            Message = message.ToString()
        };

        _logger.Log(logEvent);
    }
}

Answer 4

If you're facing the issue where the Stream does not support reading error occurs when trying to read the request body more than once, you can try the following workaround.

In your Startup.cs file, add the following middleware to enable buffering of the request body, which allows you to re-read the request body for logging purposes:

app.Use(async (context, next) =>
{
    using (var streamCopy = new MemoryStream())
    {
        await context.Request.Body.CopyToAsync(streamCopy);
        streamCopy.Position = 0;

        string body = new StreamReader(streamCopy).ReadToEnd();

        streamCopy.Position = 0;
        context.Request.Body = streamCopy;

        await next();
    }
});

This middleware creates a copy of the request body stream, reads the entire stream into a string, sets the stream position back to the beginning, sets the request body to the copied stream, and then calls the next middleware.

After this middleware, you can now use context.Request.Body.Position = 0; to set the position of the request body stream back to the beginning so you can re-read the request body.

I hope this helps!