Peter Szekeli
Peter Szekeli

Reputation: 2800

.NET Core 3.1 Exception thrown in controller is logged before hitting middleware

I added an exception handling middleware to my .net core 3.1 api, but it doesn't behave as expected. I see plenty of log messages of unhandled exceptions.

I made a simple skeleton to reproduce it. I don't have logging configured, but the behavior is the same.

Startup.cs

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    app.ConfigureExceptionHandler();

    app.UseRouting();

    app.UseAuthorization();

    app.UseEndpoints(endpoints =>
    {
        endpoints.MapControllers();
    });
}

ExceptionHandlerMiddleware.cs

public static class ExceptionHandlerMiddleware
{
    public static void ConfigureExceptionHandler(this IApplicationBuilder app)
    {
        app.UseExceptionHandler(applicationBuilder =>
        {
            applicationBuilder.Run(async httpContext => await ExceptionHandlerAsync(httpContext));
        });
    }

    private static async Task ExceptionHandlerAsync(HttpContext context)
    {
        var contextFeature = context.Features.Get<IExceptionHandlerFeature>();

        context.Response.StatusCode = (int)HttpStatusCode.InternalServerError;
        var message = contextFeature?.Error.Message ?? "Internal Server Error with no inner exception";

        await context.Response.WriteAsync(message);
    }
}

ExceptionController.cs

[ApiController]
[Route("api/[controller]")]    
public class ExceptionController : ControllerBase
{
    [Route("throw")]
    public IActionResult ThrowInController()
    {
        throw new Exception("Thrown in Controller");
    }
}

So if I debug it through, the flow is the following:

My issue is the intermediate "unhandled" exception message before the flow hits the middleware and the exception gets handled. In my real app, there's also logic to log as warning or info (and not as error) depending on the metadata of the exception. But currently every exception gets logged multiple times. First as Error (the unhandled exception) and secondly by the middleware with proper log level.

Any suggestions on what I'm doing wrong?

update

I found a workaround. If I use app.UseMiddleware<ExceptionHandlerMiddleware>(); instead of app.UseExceptionHandler(...), I no longer get the message about the unhandled exception.

ExceptionHandlerMiddleware.cs

public class ExceptionHandlerMiddleware
{
    private readonly RequestDelegate _next;

    public ExceptionHandlerMiddleware(RequestDelegate next)
    {
        _next = next;
    }

    public async Task InvokeAsync(HttpContext httpContext)
    {
        try
        {
            await _next(httpContext);
        }
        catch (Exception exception)
        {
            // handle exception, log it with the proper level, generate response, etc
        }
    }
}

I'd still be interested to know why though.

Upvotes: 5

Views: 2115

Answers (1)

Artur
Artur

Reputation: 5530

It happens because of this line

_logger.UnhandledException(edi.SourceException);

The ExceptionHandlerMiddleware is logging exception as error before running your handler.

I solved this by disabling all logs from Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware. If this solution is good enough for you just set this category logging level to None:

"Logging": {
    "LogLevel": {
    "Default": "Information",
    "Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware": "None"
  }
}

Upvotes: 1

Related Questions