Log Requests and Responses in ASP.NET Core

/ .NET Core, ASP.NET Core / .NET Core, ASP.NET Core, Logging, Middleware

Note: An updated version of this post for ASP.NET Core 3 and above is available.

As part of trying to do some debugging, I needed a way to log the requests and responses. Writing a piece of middleware seemed to be a good way to handle this problem. It also turned out to be more complicated that I had expected to deal with the request and response bodies.

Middleware

In ASP.NET Core middleware are the components that make up the pipeline that handles request and responses for the application. Each piece of middleware called has the option to do some processing on the request before calling next piece of middleware in line. After execution returns from the call to the next middleware, there is an opportunity to do processing on the response.

The pipeline for an application is set in the Configure function of the Startup class. Run, Map and Use are the three types of middleware. Run should only be used to terminate the pipeline. Map is used for pipeline branching. Use seems to be the most common type of middleware that does some processing and call the next middleware in line. For more detail see the official docs.

Creating Middleware

Middleware can be implemented as a lambda directly in the Configure function, but more typically it is implemented as a class that is added to the pipeline using an extension method on IApplicationBuilder. This example will be going the class route.

This example is a piece of middleware that using ASP.NET Cores built-in logging to log requests and responses. Create a class called RequestResponseLoggingMiddleware.

The class will need a constructor that takes to arguments both will be provided by ASP.NET Core’s dependency injection system. The first is a RequestDelegate for the next piece of middleware to be called. The second is an ILoggerFactory which will be used to create a logger. The RequestDelegate is stored to the class level _next variable and the loggerFactory is used to create a logger which is stored to the class level _logger variable.

public class RequestResponseLoggingMiddleware
{
    private readonly RequestDelegate _next;
    private readonly ILogger _logger;

    public RequestResponseLoggingMiddleware(RequestDelegate next,
                                            ILoggerFactory loggerFactory)
    {
        _next = next;
        _logger = loggerFactory
                  .CreateLogger<RequestResponseLoggingMiddleware>();
    }
}

Add an Invoke function which is the function that will be called when your middleware is run by the pipeline. The following is the function that does nothing other than call the next middleware in the pipeline.

public async Task Invoke(HttpContext context)
{
     //code dealing with request

     await _next(context);

     //code dealing with response
}

Next, add a static class to simplify adding the middleware to the application’s pipeline. This is the same pattern the built-in middleware uses.

public static class RequestResponseLoggingMiddlewareExtensions
{
    public static IApplicationBuilder UseRequestResponseLogging(this IApplicationBuilder builder)
    {
        return builder.UseMiddleware<RequestResponseLoggingMiddleware>();
    }
}

Adding to the pipeline

To add the new middleware to the pipeline open the Startup to the Configure function and add the following line.

app.UseRequestResponseLogging();

Keep in mind that the order in which middleware is added can make a difference in how the application behaves. Since the middleware this post is dealing with is logging I have placed it near the begging of the pipeline just before app.UseStaticFiles().

Logging requests and responses

Now that the setup work for our new middleware is done we will come back to its Invoke function. As I stated above this ended up being more complicated that I expected, but thankfully I found this by Sul Aga which really helped me work through the issues I was having.

I created a couple of helper functions that we will look at first. The following is the function call to create the string that will be logged for a request.

private 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;

    return $"{request.Scheme} {request.Host}{request.Path} {request.QueryString} {bodyAsText}";
}

The key to getting this function to work and allow reading of the request body was request.EnableRewind() which allows us to read from the beginning of the stream. The rest of the function is pretty straight forward.

The next function is used to get the string to that will be used to log the response body. This function looks simpler than it is and only works because of how it is called from the Invoke function.

private async Task<string> FormatResponse(HttpResponse response)
{
    response.Body.Seek(0, SeekOrigin.Begin);
    var text = await new StreamReader(response.Body).ReadToEndAsync(); 
    response.Body.Seek(0, SeekOrigin.Begin);

    return $"Response {text}";
}

Finally, the Invoke which does the logging and jumps through some hoops to allow the response body to be read.

public async Task Invoke(HttpContext context)
{
    _logger.LogInformation(await FormatRequest(context.Request));

    var originalBodyStream = context.Response.Body;

    using (var responseBody = new MemoryStream())
    {
        context.Response.Body = responseBody;

        await _next(context);

        _logger.LogInformation(await FormatResponse(context.Response));
        await responseBody.CopyToAsync(originalBodyStream);
    }
}

As you can see the trick to reading the response body is replacing the stream being used with a new MemoryStream and then copying the data back to the original body steam. This works and is a concept I found in Sul’s blog post. I don’t know how much the affect performance and would make sure to study how it scales or just avoid using it in production as much as possible.

Wrapping up

This entry didn’t turn out anything like I expected. I came into this looking to do a very simple post due to some time restrictions and it turned into something larger. I hope you find it helpful. I didn’t do a full repo for this week’s post, but you can a gist with the middleware classes here.

Also published on Medium.

37 thoughts on “Log Requests and Responses in ASP.NET Core”

  3. Lilan Sameera

    Sadly this does not work for post request and somehow it corrupts the request body and make it null. Bob can you pass the blog you found please?

    Reply
  6. asdsda

    Do some restrictions, because our API may have operations such as uploading files and downloading files. In theory, requests other than json format and form format can be recorded, but if it is uploading, requests for downloading files should not be recorded because The log is too big.

    Reply
    1. Eric

      In this case, I don’t believe I attached any identifier other than the route. If you need it you could add in a GUID. My guess is if you need something to make it unique you would also need something to associate multiple request/responses to a single user/session. That level of tracking would be much more involved than what this post covers.

      Reply
      2. George Kargakis

        You can use a transactionId for as attribute of your logged messages, so later on you can correlate all the events published in a transaction.
        The value of the transactionId can be determined by the Logging Service.

        Registering your Logging Service with once per transaction lifecycle so the transaction Id is unique per transaction.
        From Microsoft Docs:
        Because middleware is constructed at app startup, not per-request, scoped lifetime services used by middleware constructors are not shared with other dependency-injected types during each request. If you must share a scoped service between your middleware and other types, add these services to the Invoke method’s signature. The Invoke method can accept additional parameters that are populated by dependency injection.

        Reply
  9. Dean.ZHU

    Yes, it is a good realization, but there are still a few questions.

    1. Assuming that our API has a file upload and download function, we may not be able to log the contents of the file to the log.

    2, the general API will use swagger, so when you visit swagger, we may not like to record the interface content of the swagger.

    3. Maybe when we log the log, for some special password. A sensitive field can not be recorded. So you should do some special treatment of these fields, such as being recorded as * * *

    Reply
    1. Michael

      great post, but it throws an exception when you return a 204 NoContent. Because you change the response body which is not allowed on a 204.

      Reply

  10. Pingback: ASP.NET Core and Web API: A Custom Wrapper for Managing Exceptions and Consistent Responses – DEVELOPPARADISE

  11. George Kargakis

    Great solution Eric, thank you for sharing!
    However there is an issue developers might face using it.

    Avoid copy pasting code :smirk:

    The context.Request.Body forwarded from Middleware to lower layers can be corrupted (null). This drives to get an null body in the Controller actions(using [FromBody] attribute).

    I managed to fix it by using the right buffer initialization length in FormatRequest function:

    var buffer = new byte[Convert.ToInt32(request.Body.Length)];

    instead of

    var buffer = new byte[Convert.ToInt32(request.ContentLength)];

    Reply
    2. Eric Wo

      Hi,

      interestingly enough I first didnt get the tutorials solution working. had the POST problems like a lot of others. Then stumbled upon your comment. I already had your proposal

        var buffer = new byte[Convert.ToInt32(request.Body.Length)];

      implemented, but it didnt work for me. Instead the “old” way worked for POST requests

        var buffer = new byte[Convert.ToInt32(request.ContentLength)];

      I have to mention though that I also have the code

        request.Body = body;

      replaced with

        request.Body.Position = 0;

      Hope this helps somebody! ? [Tested with Core 2.1]

      Reply

  12. Pingback: [Core 2.1] HttpContext.Response.Body is empty when trying to read it - How to Code .NET

  13. George Kargakis

    Thank you for sharing the approach of using a middleware in order to log request/responses in an asp.netcore application. However the specific solution might cause memory leak in case of large body in request and response. Please check an alternative approach that might eradicate the risk of memory leak. Feel free to send your feedback so we can end up in a more elegant solution.

    Reply
  14. Craig Barrie

    Hi Eric,

    Thanks for taking the time to create this post. I’ve certainly been able to put this to good use.

    It should be noted that in the .net core 3.0, request.EnableRewind(); is no longer available.

    however, the following will work in the FormatRequest method.

    private async Task FormatRequest(HttpRequest request)
    {
    var body = request.Body;

        request.EnableBuffering();  //this is instead of 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.Position = 0; //rewind request to beginning

    request.Body = body;

    return $"{request.Scheme} {request.Host}{request.Path} {request.QueryString} {bodyAsText}";
}

    just wanted to post that in case it saves someone a bit of pain ?

    thanks

    Craig.

    Reply
  16. Daniel

    hey i have a problem here
    the fomratresponse method is ruturning empty string always.
    here is my code

    public async Task InvokeAsync(HttpContext httpContext)
    {
    httpContext.Request.EnableRewind();
    var req = RequestBody(httpContext);

            var originalBodyStream = httpContext.Response.Body;

        using (var responseBody = new MemoryStream())
        {

            httpContext.Response.Body = responseBody;

            await next(httpContext);

            string responseBodyAsString = await FormatResponseAsync(httpContext.Response);

            if (httpContext.Response.StatusCode != 204)
                await responseBody.CopyToAsync(originalBodyStream);
        }
    }

    public static string RequestBody(HttpContext httpContext)
    {
    string requestBody = string.Empty;
    httpContext.Request.EnableRewind();
    var stream = httpContext.Request.Body;

            var reader = new StreamReader(stream);

        requestBody = reader.ReadToEnd();

        if (stream.CanSeek)
            stream.Seek(0, SeekOrigin.Begin);

        return requestBody;
    }

    private async Task FormatResponseAsync(HttpResponse response)
    {

            response.Body.Seek(0, SeekOrigin.Begin);

        string text = await new StreamReader(response.Body).ReadToEndAsync();

        response.Body.Seek(0, SeekOrigin.Begin);

        return text;
    }

    the request method works fine but i cant get the response body

    Reply

Leave a Comment

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.