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();
        }
    }
}

Solution 1

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();
        }
    }
}

Solution 2

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.

Solution 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);
    }
}