Improvements to HttpLoggingMiddleware in ASP.NET 8

Improvements in HttpLoggingMiddleware in ASP.NET 8

Intro

.NET 6 began to introduce an http logging middleware. We can use the http logging middleware to record request and response information, but the scalability is not very strong. In the .NET 8 version, some optimizations were made and some New configuration and HttpLoggingInterceptor make it easier to extend

New Config

[Flags]
public enum HttpLoggingFields : long
{
 + /// <summary>
 + /// Flag for logging how long it took to process the request and response in milliseconds.
 + /// </summary>
 + Duration = 0x1000,

- All = Request | Response
 + All = Request | Response | Duration
}

A new Duration enumeration value has been added to HttpLoggingFields, which will record the time taken for request processing and is included in All. The output log is as follows :

edc48ce45910bed24fd9dcd2c41e3062.png

http-logging-duration
public sealed class HttpLoggingOptions
{
 + /// <summary>
 + /// Gets or sets if the middleware will combine the request, request body, response, response body,
 + /// and duration logs into a single log entry. The default is <see langword="false"/>.
 + /// </summary>
 + public bool CombineLogs { get; set; }
}

Added a CombineLogs configuration in HttpLoggingOptions, the default is false, and the default request/response/duration logs are separated

For example:

04a845f8bd8bf2d17bd1a6256a263051.png

http-logging-non-combined

After configuring it to true, it will be merged into one log, as follows:

00eb960329113b104fd3d9f69538233a.png

HttpLoggingInterceptor

.NET 8 also introduced IHttpLoggingInterceptor, which can better extend http logging

public interface IHttpLoggingInterceptor
{
    /// <summary>
    /// A callback to customize the logging of the request and response.
    /// </summary>
    /// <remarks>
    /// This is called when the request is first received and can be used to configure both request and response options. All settings will carry over to
    /// <see cref="OnResponseAsync(HttpLoggingInterceptorContext)"/> except the <see cref="HttpLoggingInterceptorContext.Parameters"/>
    /// will be cleared after logging the request. <see cref="HttpLoggingInterceptorContext.LoggingFields"/> may be changed per request to control the logging behavior.
    /// If no request fields are enabled, and the <see cref="HttpLoggingInterceptorContext.Parameters"/> collection is empty, no request logging will occur.
    /// If <see cref="HttpLoggingOptions.CombineLogs"/> is enabled then <see cref="HttpLoggingInterceptorContext.Parameters"/> will carry over from the request to response
    /// and be logged together.
    /// </remarks>
    ValueTask OnRequestAsync(HttpLoggingInterceptorContext logContext);

    /// <summary>
    /// A callback to customize the logging of the response.
    /// </summary>
    /// <remarks>
    /// This is called when the first write to the response happens, or the response ends without a write, just before anything is sent to the client. Settings are carried
    /// over from <see cref="OnRequestAsync(HttpLoggingInterceptorContext)"/> (except the <see cref="HttpLoggingInterceptorContext.Parameters"/>) and response settings may
    /// still be modified. Changes to request settings will have no effect. If no response fields are enabled, and the <see cref="HttpLoggingInterceptorContext.Parameters"/>
    /// collection is empty, no response logging will occur.
    /// If <see cref="HttpLoggingOptions.CombineLogs"/> is enabled then <see cref="HttpLoggingInterceptorContext.Parameters"/> will carry over from the request to response
    /// and be logged together. <see cref="HttpLoggingFields.RequestBody"/> and <see cref="HttpLoggingFields.ResponseBody"/> can also be disabled in OnResponseAsync to prevent
    /// logging any buffered body data.
    /// </remarks>
    ValueTask OnResponseAsync(HttpLoggingInterceptorContext logContext);
}

HttpLoggingInterceptorContext is defined as follows:

public sealed class HttpLoggingInterceptorContext
{
    /// <summary>
    /// The request context.
    /// </summary>
    /// <remarks>
    /// This property should not be set by user code except for testing purposes.
    /// </remarks>
    public HttpContext HttpContext { get; set; }

    /// <summary>
    /// Gets or sets which parts of the request and response to log.
    /// </summary>
    /// <remarks>
    /// This is pre-populated with the value from <see cref="HttpLoggingOptions.LoggingFields"/>,
    /// <see cref="HttpLoggingAttribute.LoggingFields"/>, or
    /// <see cref="HttpLoggingEndpointConventionBuilderExtensions.WithHttpLogging{TBuilder}(TBuilder, HttpLoggingFields, int?, int?)"/>.
    /// </remarks>
    public HttpLoggingFields LoggingFields { get; set; }

    /// <summary>
    /// Gets or sets the maximum number of bytes of the request body to log.
    /// </summary>
    /// <remarks>
    /// This is pre-populated with the value from <see cref="HttpLoggingOptions.RequestBodyLogLimit"/>,
    /// <see cref="HttpLoggingAttribute.RequestBodyLogLimit"/>, or
    /// <see cref="HttpLoggingEndpointConventionBuilderExtensions.WithHttpLogging{TBuilder}(TBuilder, HttpLoggingFields, int?, int?)"/>.
    /// </remarks>
    public int RequestBodyLogLimit { get; set; }

    /// <summary>
    /// Gets or sets the maximum number of bytes of the response body to log.
    /// </summary>
    /// <remarks>
    /// This is pre-populated with the value from <see cref="HttpLoggingOptions.ResponseBodyLogLimit"/>,
    /// <see cref="HttpLoggingAttribute.ResponseBodyLogLimit"/>, or
    /// <see cref="HttpLoggingEndpointConventionBuilderExtensions.WithHttpLogging{TBuilder}(TBuilder, HttpLoggingFields, int?, int?)"/>.
    /// </remarks>
    public int ResponseBodyLogLimit { get; set; }

    /// <summary>
    /// Gets a list of parameters that will be logged as part of the request or response. Values specified in <see cref="LoggingFields"/>
    /// will be added automatically after all interceptors run. All values are cleared after logging the request.
    /// All other relevant settings will carry over to the response.
    /// </summary>
    /// <remarks>
    /// If <see cref="HttpLoggingOptions.CombineLogs"/> is enabled, the parameters will be logged as part of the combined log.
    /// </remarks>
    public IList<KeyValuePair<string, object?>> Parameters { get; }

    /// <summary>
    /// Adds data that will be logged as part of the request or response. See <see cref="Parameters"/>.
    /// </summary>
    /// <param name="key">The parameter name.</param>
    /// <param name="value">The parameter value.</param>
    public void AddParameter(string key, object? value);

    /// <summary>
    /// Adds the given fields to what's currently enabled in <see cref="LoggingFields"/>.
    /// </summary>
    /// <param name="fields">Additional fields to enable.</param>
    public void Enable(HttpLoggingFields fields);

    /// <summary>
    /// Checks if any of the given fields are currently enabled in <see cref="LoggingFields"/>.
    /// </summary>
    /// <param name="fields">One or more field flags to check.</param>
    public bool IsAnyEnabled(HttpLoggingFields fields);

    /// <summary>
    /// Removes the given fields from what's currently enabled in <see cref="LoggingFields"/>.
    /// </summary>
    /// <param name="fields">Fields to disable.</param>
    public void Disable(HttpLoggingFields fields);

    /// <summary>
    /// Disables the given fields if any are currently enabled in <see cref="LoggingFields"/>.
    /// </summary>
    /// <param name="fields">One or more field flags to disable if present.</param>
    /// <returns><see langword="true" /> if any of the fields were previously enabled.</returns>
    public bool TryDisable(HttpLoggingFields fields);
}

We can dynamically adjust the fields to be recorded based on the Request or Response information or dynamically adjust RequestBodyLogLimit/ResponseBodyLogLimit

Let’s look at an example of HttpLoggingInterceptor:

file sealed class MyHttpLoggingInterceptor: IHttpLoggingInterceptor
{
    public ValueTask OnRequestAsync(HttpLoggingInterceptorContext logContext)
    {
        if (logContext.HttpContext.Request.Path.Value?.StartsWith("/req-") == true)
        {
            logContext.LoggingFields = HttpLoggingFields.ResponsePropertiesAndHeaders;
            logContext.AddParameter("req-path", logContext.HttpContext.Request.Path.Value);
        }
        
        return ValueTask.CompletedTask;
    }

    public ValueTask OnResponseAsync(HttpLoggingInterceptorContext logContext)
    {
        if (logContext.HttpContext is { Response.StatusCode: >=200 and < 300, Request.Path.Value: "/hello" })
        {
            logContext.TryDisable(HttpLoggingFields.All);
        }
        return ValueTask.CompletedTask;
    }
}

The usage example is as follows, use AddHttpLoggingInterceptor() to register:

var builder = WebApplication.CreateSlimBuilder(args);
builder.Services.AddControllers();
builder.Services.AddHttpLogging(options =>
{
    options.LoggingFields = HttpLoggingFields.All;
    options.CombineLogs = true;
});
builder.Services.AddHttpLoggingInterceptor<MyHttpLoggingInterceptor>();

var app = builder.Build();
app.UseHttpLogging();
app.MapGet("/hello", () => "Hello");
app.MapGet("/crash", () => Results.BadRequest());
app.MapGet("/req-intercept", () => "Hello .NET 8");
app.MapControllers();
await app.RunAsync();

Visit the path of the example to see the contents of the log:

/hello

b5dc03290baf4a06c50efa1936d74414.png

/crash

d3a2b2ba23a0013829e32c74604342ee.png

/req-intercept

ce8173567c56781110898bdbc63fb54e.png

You can see that the log output results of each request are different. Although we set ogContext.TryDisable(HttpLoggingFields.All) for the first request, there are still output results. This is because httpLogging currently The implementation is like this. When processing in Response, the request information has been recorded. For details, please refer to the implementation of http logging middleware.

https://github.com/dotnet/aspnetcore/blob/main/src/Middleware/HttpLogging/src/HttpLoggingMiddleware.cs

If you want to completely disable it, you need to handle it in the OnRequestAsync method

public ValueTask OnRequestAsync(HttpLoggingInterceptorContext logContext)
{
    if ("/no-log".Equals(logContext.HttpContext.Request.Path.Value, StringComparison.OrdinalIgnoreCase))
    {
        logContext.LoggingFields = HttpLoggingFields.None;
    }
    //
    return ValueTask.CompletedTask;
}

In this way, there will be no log printing for the request.

The last req-intercept sets ResponsePropertiesAndHeaders in request processing and adds a custom Parameter. From the output results, you can see that there is output to the log.

More

You can try it yourself. It will be easier to use than before, but you still feel it is lacking.

For example, the log level is currently Information and the log level cannot be changed dynamically.

In addition, as mentioned earlier, even if you use CombineLogs and set it to HttpLoggingFields.None in the response, the request information will still be recorded. I hope it will continue to be optimized in the future.

References

  • ASP.NET Core updates in .NET 8 Release Candidate 2

  • https://github.com/dotnet/aspnetcore/pull/50163

  • https://github.com/dotnet/aspnetcore/issues/31844

  • https://github.com/WeihanLi/SamplesInPractice/blob/master/net8sample/AspNetCore8Sample/HttpLoggingInterceptorSample.cs

  • https://github.com/dotnet/aspnetcore/blob/main/src/Middleware/HttpLogging/src/HttpLoggingInterceptorContext.cs

  • https://github.com/dotnet/aspnetcore/blob/main/src/Middleware/HttpLogging/src/IHttpLoggingInterceptor.cs

  • https://github.com/dotnet/aspnetcore/blob/main/src/Middleware/HttpLogging/src/HttpLoggingMiddleware.cs