Using Attribute and ActionFilters for logging request and response of controller and actions

Question

I am trying to find an elegant way of logging every request and response in my Web API using Filters in Asp.net Core 3.1 rather than have them in each action and each controller.

Haven't found a nice solution that seems performable well to deploy in production.

I've been trying to do something like this (below) but no much success.

Any other suggestion would be appreciated.

public class LogFilter : IAsyncActionFilter
    {
        private readonly ILogger _logger;

        public LogFilter(ILogger logger)
        {
            _logger = logger;
        }
        
        public async Task OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
        {
            var requestBodyData = context.ActionArguments["request"];
            var responseBodyData = "";//how to get the response result
            
            _logger.LogInformation($"{AppDomain.CurrentDomain.FriendlyName} Endpoint: {nameof(context.ActionDescriptor.DisplayName)} - Request Body: {requestBodyData}");
            
            await next();
            
            _logger.LogInformation($"{AppDomain.CurrentDomain.FriendlyName} Endpoint: {nameof(context.ActionDescriptor.DisplayName)} - Response Body: {responseBodyData}");
            
        }
        
    }

King King · Accepted Answer · 2021-02-07 20:02:13Z

I think logging the response should be done in debugging mode only and really can be done at your service API (by using DI interception). That way you don't need to use IActionFilter which actually can provide you only a wrapper IActionResult which wraps the raw value from the action method (which is usually the result returned from your service API). Note that at the phase of action execution (starting & ending can be intercepted by using IActionFilter or IAsyncActionFilter), the HttpContext.Response may have not been fully written (because there are next phases that may write more data to it). So you cannot read the full response there. But here I suppose you mean reading the action result (later I'll show you how to read the actual full response body in a correct phase). When it comes to IActionResult, you have various kinds of IActionResult including custom ones. So it's hard to have a general solution to read the raw wrapped data (which may not even be exposed in some custom implementations). That means you need to target some specific well-known action results to handle it correctly. Here I introduce code to read JsonResult as an example:

public async Task OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
    {
        var requestBodyData = context.ActionArguments["request"];            
        _logger.LogInformation($"{AppDomain.CurrentDomain.FriendlyName} Endpoint: {nameof(context.ActionDescriptor.DisplayName)} - Request Body: {requestBodyData}");
        
        var actionExecutedContext = await next();
        var responseBodyData = "not supported result";
        //sample for JsonResult
        if(actionExecutedContext.Result is JsonResult jsonResult){
            responseBodyData = JsonSerializer.Serialize(jsonResult.Value);
        }
        //check for other kinds of IActionResult if any ...
        //...
        _logger.LogInformation($"{AppDomain.CurrentDomain.FriendlyName} Endpoint: {nameof(context.ActionDescriptor.DisplayName)} - Response Body: {responseBodyData}");
        
    }

IActionResult has a method called ExecuteResultAsync which can trigger the next processing phase (result execution). That's when the action result is fully written to the HttpContext.Response. So you can try creating a dummy pipeline (starting with a dummy ActionContext) on which to execute the action result and get the final data written to the response body. However that's what I can imagine in theory. It would be very complicated to go that way. Instead you can just use a custom IResultFilter or IAsyncResultFilter to try getting the response body there. Now there is one issue, the default HttpContext.Response.Body is an HttpResponseStream which does not support reading & seeking at all (CanRead & CanSeek are false), we can only write to that kind of stream. So there is a hacky way to help us mock in a readable stream (such as MemoryStream) before running the code that executes the result. After that we swap out the readable stream and swap back the original HttpResponseStream in after copying data from the readable stream to that stream. Here is an extension method to help achieve that:

public static class ResponseBodyCloningHttpContextExtensions
{
    public static async Task<Stream> CloneBodyAsync(this HttpContext context, Func<Task> writeBody)
    {
        var readableStream = new MemoryStream();
        var originalBody = context.Response.Body;
        context.Response.Body = readableStream;
        try
        {
            await writeBody();
            readableStream.Position = 0;
            await readableStream.CopyToAsync(originalBody);
            readableStream.Position = 0;                
        }                        
        finally
        {
            context.Response.Body = originalBody;
        }
        return readableStream;            
    }
}

Now we can use that extension method in an IAsyncResultFilter like this:

//this logs the result only, to write the log entry for starting/beginning the action 
//you can rely on the IAsyncActionFilter as how you use it.
public class LoggingAsyncResultFilterAttribute : Attribute, IAsyncResultFilter
{
    //missing code to inject _logger here ...

    public async Task OnResultExecutionAsync(ResultExecutingContext context, ResultExecutionDelegate next)
    {
        var readableStream = await context.HttpContext.CloneBodyAsync(() => next());
        //suppose the response body contains text-based content
        using (var sr = new StreamReader(readableStream))
        {
            var responseText = await sr.ReadToEndAsync();
            _logger.LogInformation($"{AppDomain.CurrentDomain.FriendlyName} Endpoint: {nameof(context.ActionDescriptor.DisplayName)} - Response Body: {responseText}");
        }
    }
}

You can also use an IAsyncResourceFilter instead, which can capture result written by IExceptionFilter. Or maybe the best, use an IAsyncAlwaysRunResultFilter which can capture the result in all cases.

I assume that you know how to register IAsyncActionFilter so you should know how to register IAsyncResultFilter as well as other kinds of filter. It's just the same.

Matt M · Accepted Answer · 2022-04-26 21:38:51Z

0

starting with dotnet 6 asp has HTTP logging built in. Microsoft has taken into account redacting information and other important concepts that need to be considered when logging requests.

var builder = WebApplication.CreateBuilder(args);
var app = builder.Build();
/*  enabled HttpLogging with this line  */
app.UseHttpLogging();
if (!app.Environment.IsDevelopment())
{
    app.UseExceptionHandler("/Error");
}
app.UseStaticFiles();
app.MapGet("/", () => "Hello World!");
app.Run();

https://learn.microsoft.com/en-us/aspnet/core/fundamentals/http-logging/?view=aspnetcore-6.0#enabling-http-logging

answered Apr 26, 2022 at 21:38

Matt M

6921 gold badge7 silver badges29 bronze badges

Comments

fededim · Accepted Answer · 2023-06-21 13:10:42Z

You can use this action filter

    public class LogActionFilter : IActionFilter {
    private readonly ILogger<LogActionFilter> _logger;

    public LogActionFilter(ILogger<LogActionFilter> logger)
    {
        _logger = logger;
    }

    public void OnActionExecuting(ActionExecutingContext context)
    {
       _logger.LogDebug($"REQ:{JsonConvert.SerializeObject(context.ActionArguments)}");
    }

    public void OnActionExecuted(ActionExecutedContext context)
    {
        if (context?.Result is ObjectResult objResult)
           _logger.LogDebug($"RESP:{JsonConvert.SerializeObject(objResult.Value)}");
    }

}

Basically an IActionResult can be casted to either StatusCodeResult (if the api does not return anything) or ObjectResult (if the api returns some data) from which you can get:

The status code from StatusCode property (both StatusCodeResult and ObjectResult implement the interface IStatusCodeActionResult)
The actual result from the Value property (only for ObjectResult)

All ControllerBase methods like Ok, BadRequest, NotFound, Conflict are helper methods to return OkObjectResult, BadRequestObjectResult, NotFoundObjectResult, ConflictObjectResult which are all derived classes from ObjectResult.

Remember to active globally the filter for all controllers of the api, e.g. add/change in ConfigureServices inside Startup.cs

    services.AddControllers(opt =>
        {
            opt.Filters.Add<LogActionFilter>();
        })

Collectives™ on Stack Overflow

Using Attribute and ActionFilters for logging request and response of controller and actions

3 Answers 3

Comments

Comments

Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

3 Answers 3

Comments

Comments

Comments

Your Answer

Sign up or log in

Post as a guest

Related