Logging invalid model state requests in Dot Net Core 6

I am working on a new project and needed to log invalid model state requests.

I am working on a new project and needed to log invalid model state requests.

This will be an open-source project and one thing I like to see when using a project or solution is why a request failed in the log files. It is extremely helpful in using an API.

The problem is that by default, ASP Net Core 6 does not log invalid model state requests in a controller decorated with [ApiController]. It silently returns a 400 response with an error to the caller looking something like this.

{
  "type": "https://tools.ietf.org/html/rfc7231#section-6.5.1",
  "title": "One or more validation errors occurred.",
  "status": 400,
  "traceId": "00-2c92a14cca05a90d0f57b83247d3fb3f-95802c41ffd43a18-00",
  "errors": {
    "Name": [
      "The Name field is required."
    ]
  }
}

I like the response with everything in it so I wanted to keep that in my solution to this problem.

The way I did this was to create a new action filter, add it to the list of action filters, and disable the default model state filter.

My new action filter checks to see if the ApiController attribute is on the controller. If it is, then it checks the ModelState. If it is invalid it logs the pertinent information from the model state, then calls the factory for generating the invalid result and finally, returns it to the caller.

Here is my code for the new filter:

using Microsoft.AspNetCore.Mvc;
using Microsoft.AspNetCore.Mvc.Filters;
using Microsoft.Extensions.Options;

namespace Cyclops.Head.Filters
{
    public class ModelStateBindingErrorActionFilter : IActionFilter
    {
        private readonly ILogger<ModelStateBindingErrorActionFilter> _logger;
        private readonly ApiBehaviorOptions _options;
        private readonly Type _apiControllerAttribute;

        public ModelStateBindingErrorActionFilter(ILogger<ModelStateBindingErrorActionFilter> logger, IOptions<ApiBehaviorOptions> options)
        {
            _logger = logger;
            _options = options.Value;
            _apiControllerAttribute = typeof(ApiControllerAttribute);
        }

        public void OnActionExecuted(ActionExecutedContext context)
        {
        }

        public void OnActionExecuting(ActionExecutingContext context)
        {
            if (context.Controller.GetType().CustomAttributes.Any(x => x.AttributeType == _apiControllerAttribute))
            {
                if (!context.ModelState.IsValid)
                {
                    _logger.LogWarning("Invalid model state: {@errors}", context.ModelState.Select(x =>
                    new
                    {
                        Key = x.Key,
                        Errors = x.Value?.Errors.Select(x=>new
                        {
                            x.ErrorMessage,
                            x.Exception
                        })
                    }));

                    context.Result = _options.InvalidModelStateResponseFactory(context);
                }
            }
        }
    }
}

To add the filter and disable the default filter, in program.cs, add this where you register your services.

builder.Services.AddSingleton<Cyclops.Head.Filters.ModelStateBindingErrorActionFilter>();
builder.Services.AddMvc(x =>
    {
        x.Filters.AddService<Cyclops.Head.Filters.ModelStateBindingErrorActionFilter>();
    })
    .ConfigureApiBehaviorOptions(x =>
    {
        x.SuppressModelStateInvalidFilter = true;
    });

After this small change, I now see this in my logs.

[15:14:55 WRN] Invalid model state: [{"Key": "Name", "Errors": [{"ErrorMessage": "The Name field is required.", "Exception": null}]}]

Conclusion

This took a few hours to figure out, but nothing to crazy to work through. The hardest part was figuring out why Dot Net Core was skipping my API actions. Once that was figured out, the rest was relatively easy.

I took the stack overflow issue and expanded on some of the approaches that were mentioned. It was really, so it needed to be converted to core 6.

.NET Core: access request data on bad request when ApiController shortcuts the pipeline
For all those stumbling accross logging issues I created a small public playground on Github. Feel free to join. I am still experimenting with the one hits all logging filter for my requests. The...