Four years ago I wrote about how to log request/response headers in ASP.NET Core. This functionality has now been built into the framework, let's have a look.

How I did it 4 years ago

We shipped an application that was running behind a pretty...obscure WAF. They promised us that their product would not interfere in anyway with our application. That was wrong. They stripped almost all of our "custom" headers. To "prove" this I built a middleware that stored all unique headers that we received and sent out. I then created an endpoint that dumped all the headers.

I created a custom middleware, LogHeadersMiddleware.

public class LogHeadersMiddleware 
{
    private readonly RequestDelegate _next;
    private readonly ILogger<LogHeadersMiddleware> _logger;
    public static readonly List<string> RequestHeaders = new List<string>();
    public static readonly List<string> ResponseHeaders = new List<string>();

    public LogHeadersMiddleware(RequestDelegate next, ILogger<LogHeadersMiddleware> logger)
    {
        _next = next;
        _logger = logger;
    }

    public async Task Invoke(HttpContext context)
    {
        var uniqueRequestHeaders = context.Request.Headers
			.Where(x => RequestHeaders.All(r => r != x.Key))
            .Select(x => x.Key);
        RequestHeaders.AddRange(uniqueRequestHeaders);

        await _next.Invoke(context);
        var uniqueResponseHeaders = context.Response.Headers
            .Where(x => ResponseHeaders.All(r => r != x.Key))
            .Select(x => x.Key);
        ResponseHeaders.AddRange(uniqueResponseHeaders);
        
        // Log unique headers with ILogger
        ...
    }
}

I then registered it like this early in the middleware pipeline

app.UseLogHeadersMiddleware();
app.Map("/show-headers", ShowHeaders);

So by going to /show-headers you would see a dump of all the (unique) headers that our application had recieved and sent out.

The new way

Microsoft has now added support for HTTP logging in ASP.NET Core.
They have created their own middleware, you can enable it like this:

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    // Important to have it as early as possible
    app.UseHttpLogging(); 
    ...
    ...
    ...
}

If you don't do any customization, the following stuff will be logged by default (both request and response):

  • Request path
  • Status code
  • Querystring
  • Headers

Example - default implementation

POST request to /user/login
Body

{
   "username": "josef",
   "password": "MyPassword"
}

Request

info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[1]
      Request:
      Protocol: HTTP/1.1
      Method: POST
      Scheme: http
      PathBase:
      Path: /user/login
      QueryString:
      Accept: */*
      Connection: keep-alive
      Host: localhost:5000
      User-Agent: PostmanRuntime/7.28.1
      Accept-Encoding: gzip, deflate, br
      Content-Type: application/json
      Content-Length: 60

Response

info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[2]
      Response:
      StatusCode: 200
      Content-Type: application/json; charset=utf-8
      Date: [Redacted]
      Server: [Redacted]
      Transfer-Encoding: chunked

As you can see, with the default configuration, nothing sensitive is logged.
Let's see how we can configure the middleware to log some sensitive data.

Example - logging request/response body

Request body (DANGEROUS)

This will log the request headers and body

services.AddHttpLogging(options =>
{
    options.LoggingFields = HttpLoggingFields.RequestPropertiesAndHeaders |
                            HttpLoggingFields.RequestBody;
});

Body

{
    "username": "josef",
    "password": "MyPassword"
}

Request

info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[1]
      Request:
      Protocol: HTTP/1.1
      Method: POST
      Scheme: http
      PathBase:
      Path: /user/login
      QueryString:
      Accept: */*
      Connection: keep-alive
      Host: localhost:5000
      User-Agent: PostmanRuntime/7.28.1
      Accept-Encoding: gzip, deflate, br
      Content-Type: application/json
      Content-Length: 60
info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[2]
      RequestBody: {
          "username": "josef",
          "password": "MyPassword"
      }

Response body (DANGEROUS)

This will log the response headers and body

services.AddHttpLogging(options =>
{
    options.LoggingFields = HttpLoggingFields.ResponsePropertiesAndHeaders |
                            HttpLoggingFields.ResponseBody;
});

Body

{
    "username": "josef",
    "password": "MyPassword"
}

Response

info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[1]
      Response:
      StatusCode: 200
      Content-Type: application/json; charset=utf-8
info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[2]
      ResponseBody: {"token":"very secret token"}

As you can see, we are now logging the request and response body. This can be very powerful during development/debugging but you would most likely never want to do this in production. By blindly logging the request/response headers/body you can (most likely will) log sensitive data. If you feel that you have the need to log headers and bodies, make sure that you use an opt-in strategy instead, something like this:

services.AddHttpLogging(options =>
{
    options.LoggingFields = HttpLoggingFields.RequestPropertiesAndHeaders |
                            HttpLoggingFields.ResponsePropertiesAndHeaders;
    options.ResponseHeaders.Add("Non-Sensitive");
});

When calling the following action...

[HttpGet("api/weather")]
public IActionResult Index()
{
    Response.Headers.Add("Sensitive", "034D4CD7-2FEB-4B19-86A3-CFCD5DB291AA");
    Response.Headers.Add("Non-Sensitive", "Hello");
    return new OkObjectResult(new
    {
        data = "Hello World"
    });
}

...only the Non-Sensitive header value will be logged
Request

info: Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware[2]
      Response:
      StatusCode: 200
      Content-Type: application/json; charset=utf-8
      Date: [Redacted]
      Server: [Redacted]
      Transfer-Encoding: chunked
      Sensitive: [Redacted]
      Non-Sensitive: Hello

Performance

It's also important to think about how the performance of your application can suffer when logging the request/response body.

GET

Without HttpLogging

❯ .\bombardier.exe -c 125 -n 100000 http://localhost:5000/api/weather
Bombarding http://localhost:5000/api/weather with 100000 request(s) using 125 connection(s)
 100000 / 100000 [==========================================] 100.00% 2287/s 43s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec      2292.70     326.38    7095.61
  Latency       54.52ms     2.29ms   109.00ms
  HTTP codes:
    1xx - 0, 2xx - 100000, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   727.39KB/s

Default settings for HttpLogging

❯ .\bombardier.exe -c 125 -n 100000 http://localhost:5000/api/weather
Bombarding http://localhost:5000/api/weather with 100000 request(s) using 125 connection(s)
 100000 / 100000 [==========================================] 100.00% 1492/s 1m6s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec      1496.73     287.61    4500.00
  Latency       83.52ms    15.73ms      0.86s
  HTTP codes:
    1xx - 0, 2xx - 100000, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   474.86KB/s

Request/Response body logging enabled

❯ .\bombardier.exe -c 125 -n 100000 http://localhost:5000/api/weather
Bombarding http://localhost:5000/api/weather with 100000 request(s) using 125 connection(s)
 100000 / 100000 [==========================================] 100.00% 1466/s 1m8s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec      1471.50     285.97    5090.86
  Latency       84.96ms    17.64ms      0.87s
  HTTP codes:
    1xx - 0, 2xx - 100000, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   466.79KB/s

When turning on HttpLogging the throughput goes from ~2300 req/s to ~1500 req/s.

POST

Without HttpLogging

❯ .\bombardier.exe -m POST http://localhost:5000/user/login -c 125 -n 100000 --duration 1s -l -H "Content-Type: application/json" -f "login.json"
Bombarding http://localhost:5000/user/login with 100000 request(s) using 125 connection(s)
 100000 / 100000 [==========================================] 100.00% 2112/s 47s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec      2118.76     444.32    6498.38
  Latency       59.03ms    14.41ms   576.00ms
  Latency Distribution
     50%    57.00ms
     75%    59.96ms
     90%    70.00ms
     95%    75.00ms
     99%    90.81ms
  HTTP codes:
    1xx - 0, 2xx - 100000, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   771.02KB/s

Default settings for HttpLogging

❯ .\bombardier.exe -m POST http://localhost:5000/user/login -c 125 -n 100000 --duration 1s -l -H "Content-Type: application/json" -f "login.json"
Bombarding http://localhost:5000/user/login with 100000 request(s) using 125 connection(s)
 100000 / 100000 [==========================================] 100.00% 1388/s 1m12s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec      1392.11     328.62    8995.50
  Latency       89.92ms    19.01ms      1.09s
  Latency Distribution
     50%    88.00ms
     75%    91.00ms
     90%    97.00ms
     95%   111.00ms
     99%   125.00ms
  HTTP codes:
    1xx - 0, 2xx - 100000, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   506.18KB/s

Request/Response body logging enabled

❯ .\bombardier.exe -m POST http://localhost:5000/user/login -c 125 -n 100000 --duration 1s -l -H "Content-Type: application/json" -f "login.json"
Bombarding http://localhost:5000/user/login with 100000 request(s) using 125 connection(s)
 100000 / 100000 [==========================================] 100.00% 1281/s 1m18s
Done!
Statistics        Avg      Stdev        Max
  Reqs/sec      1284.89     311.66    4550.25
  Latency       97.31ms    21.58ms      1.22s
  Latency Distribution
     50%    95.00ms
     75%    99.00ms
     90%   108.00ms
     95%   119.00ms
     99%   150.00ms
  HTTP codes:
    1xx - 0, 2xx - 100000, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   467.73KB/s

As we can see, by logging more stuff, the performance takes a toll. When logging the request/response body we are losing an additional ~100 req/s.