Aspnetcore: Controller Action that throws an exception is invoked twice

[nrcventura]

Describe the bug

A controller action that throws an exception is invoked twice.

To Reproduce

Steps to reproduce the behavior:

1. Using version 3.0 preview 6 of ASP.NET Core and .NET Core
2. Create a new MVC project using the default template
3. Update the HomeController to add a method that throws an exception like the following public IActionResult ThrowException() { throw new Exception("Test exception"); }.
4. Build and run the application
5. Send a request to the /Home/ThrowException endpoint
6. Notice that the ThrowException method is invoked twice for this single request

Expected behavior

The ThrowException method should only be invoked once.

Sample Console Output

Here's some command line output which includes the number of times that ThrowException was invoked by a single request to /Home/ThrowException.

info: Microsoft.Hosting.Lifetime[0]
      Now listening on: http://localhost:5000
info: Microsoft.Hosting.Lifetime[0]
      Now listening on: https://localhost:5001
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Production
info: Microsoft.Hosting.Lifetime[0]
      Content root path: C:\dev\TestingStuff\NetCore3\Preview6Testing\AspNetCoreWebApp\bin\Debug\netcoreapp3.0
*************Exception # 1
fail: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[1]
      An unhandled exception has occurred while executing the request.
System.Exception: Test exception 1.
   at AspNetCoreWebApp.Controllers.HomeController.ThrowException() in C:\dev\TestingStuff\NetCore3\Preview6Testing\AspNetCoreWebApp\Controllers\HomeController.cs:line 35
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResourceFilter>g__Awaited|24_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)
*************Exception # 2
fail: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[3]
      An exception was thrown attempting to execute the error handler.
System.Exception: Test exception 2.
   at AspNetCoreWebApp.Controllers.HomeController.ThrowException() in C:\dev\TestingStuff\NetCore3\Preview6Testing\AspNetCoreWebApp\Controllers\HomeController.cs:line 35
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResourceFilter>g__Awaited|24_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.HandleException(HttpContext context, ExceptionDispatchInfo edi)
fail: Microsoft.AspNetCore.Server.Kestrel[13]
      Connection id "0HLNGUKLQIEU9", Request id "0HLNGUKLQIEU9:00000001": An unhandled exception was thrown by the application.
System.Exception: Test exception 1.
   at AspNetCoreWebApp.Controllers.HomeController.ThrowException() in C:\dev\TestingStuff\NetCore3\Preview6Testing\AspNetCoreWebApp\Controllers\HomeController.cs:line 35
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(Object target, Object[] parameters)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResourceFilter>g__Awaited|24_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.HandleException(HttpContext context, ExceptionDispatchInfo edi)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)

[mkArtakMSFT]

Thanks for contacting us, @nrcventura.
@pranavkm can you please look into this? Thanks!

[mkArtakMSFT]

@nrcventura, I am not able to repro this issue. Please provide a small repro project so we can investigate this further.

[pranavkm]

Looks like you've configured the action to be your error handler ::

fail: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[3]
      An exception was thrown attempting to execute the error handler.
System.Exception: Test exception 2.
   at AspNetCoreWebApp.Controllers.HomeController.ThrowException()

That would explain the second error.

[nrcventura]

Here's the sample project that I used to trigger the problem. The ThrowException method is not configured as the error handler. The error handler is configured to be app.UseExceptionHandler("/Home/Error") which is the default setting created by the new project template.

AspNetCoreWebApp.zip

[pranavkm]

@nrcventura I'm sorry for closing the issue earlier. This does look like a particularly nasty bug.

@rynowak here's what's happening:

1) Endpoint routing executes and sets the endpoint to an action
2) The action throws
3) Request unwinds to the error handler which updates the request path and re-executes: https://github.com/aspnet/AspNetCore/blob/f45250ce5e423dad083fe99967a4d65782c5301e/src/Middleware/Diagnostics/src/ExceptionHandler/ExceptionHandlerMiddleware.cs#L100-L104
4) Routing re-uses the endpoint from the previous iteration: https://github.com/aspnet/AspNetCore/blob/f45250ce5e423dad083fe99967a4d65782c5301e/src/Http/Routing/src/EndpointRoutingMiddleware.cs#L59-L64

My guess is that we should always clear endpoint metadata prior to returning from the middleware:
https://github.com/aspnet/AspNetCore/blob/f45250ce5e423dad083fe99967a4d65782c5301e/src/Http/Routing/src/EndpointRoutingMiddleware.cs#L112.

[rynowak]

Yeah, it sounds like we missed this. @davidfowl - should this be part of Reset()?

[davidfowl]

Yeah, it sounds like we missed this. @davidfowl - should this be part of Reset()?

Which reset?

It seems like we have conflicting behaviors:

• We want having an end point set to mean, noop for most middleware (like the matcher or static files)
• Anything that re-executes the pipeline really wants to clear the selected endpoint or route matching won't work.

Seems like we need to find the places that re-execute the pipeline to clear the endpoint.

[Tratcher]

It's cleanest if each middleware clears its own state in a finally block, or overwrites its state if re-executed.
Why is this check here?
https://github.com/aspnet/AspNetCore/blob/f45250ce5e423dad083fe99967a4d65782c5301e/src/Http/Routing/src/EndpointRoutingMiddleware.cs#L59-L64
In what scenarios would the endpoint be assigned before this?

[davidfowl]

In what scenarios would the endpoint be assigned before this?

Middleware can run before routing to skip the matching process, (like a future version of static files).

[Tratcher]

Note for static files the plan is to move it into the matching process, not before.

[davidfowl]

@Tratcher That's good, replace static files with a middleware that sets the endpoint metadata for a different reason.

[pranavkm]

I'm missing something here - why wouldn't clearing it after next has executed suffice?

[Tratcher]

@pranavkm that's fine, but you also need a finally block in case next throws.

[pranavkm]

Yup, that's what I'd done here. I'm not sure why the fix is being attempted to be made in other middlewares

[davidfowl]

The performance tho, measure plz

[pranavkm]

Verify https://github.com/aspnet/AspNetCore/issues/11555 is also fixed

[jtkech]

Just for infos and maybe more related to #11555

We are using the following that hit a custom diagnostics controller

app.UseStatusCodePagesWithReExecute("/Error", "?status={0}");

And we already have

app.Use(async (context, next) =>
{
    await next();

    if (context.Response.StatusCode < 200 || context.Response.StatusCode >= 400)
    {
        string contentType;
        if (_contentTypeProvider.TryGetContentType(context.Request.Path, out contentType))
        {
            var statusCodePagesFeature = context.Features.Get<IStatusCodePagesFeature>();
            if (statusCodePagesFeature != null)
            {
                statusCodePagesFeature.Enabled = false;
            }
        }
    }
});

routes.MapAreaControllerRoute(
    name: "Diagnostics.Error",
    areaName: "OrchardCore.Diagnostics",
    pattern: "Error",
    defaults: new { controller = "Diagnostics", action = "Error" }
);

Then, to hit again our Diagnostics controller i needed to explicitly set the route values and the endpoint, before the StatusCodePagesMiddleware will re-execute the pipeline.

app.Use(async (context, next) =>
{
    await next();

    if (context.Response.StatusCode < 200 || context.Response.StatusCode >= 400)
    {
        string contentType;
        if (_contentTypeProvider.TryGetContentType(context.Request.Path, out contentType))
        {
            var statusCodePagesFeature = context.Features.Get<IStatusCodePagesFeature>();
            if (statusCodePagesFeature != null)
            {
                statusCodePagesFeature.Enabled = false;
            }
        }
        else
        {
            // Workaround of c.f. https://github.com/aspnet/AspNetCore/issues/11555
            var endpointDataSource = context.RequestServices.GetRequiredService<EndpointDataSource>();

            var routeValues = new RouteValueDictionary(new
            {
                area = "OrchardCore.Diagnostics",
                controller = "Diagnostics",
                action = "Error"
            });

            var endpoint = endpointDataSource.Endpoints
                .Where(e => Match(e, routeValues))
                .FirstOrDefault();

            if (endpoint != null)
            {
                var routingFeature = new RoutingFeature()
                {
                    RouteData = new RouteData(routeValues)
                };

                var routeValuesFeature = new RouteValuesFeature()
                {
                    RouteValues = routeValues
                };

                var endpointFeature = new EndpointFeature()
                {
                    Endpoint = endpoint,
                };

                context.Features.Set<IRoutingFeature>(routingFeature);
                context.Features.Set<IRouteValuesFeature>(routeValuesFeature);
                context.Features.Set<IEndpointFeature>(endpointFeature);
            }
        }
    }
});

[nblumhardt]

We're working around this with:

    app.UseExceptionHandler("/error");
    app.Use(async (context, next) =>
    {
        try
        {
            await next();
        }
        catch
        {
            context.Features.Set<IEndpointFeature>(null);
            throw;
        }
    });

No idea whether there will be unpleasant consequences due to dropping out IEndpointFeature from the HttpContext, but it _seems_ to work just fine..... :D

[Tratcher]

@nblumhardt that's fine. Here's an even simpler variant:
https://github.com/dotnet/dotnet-core-website/pull/1360/files

[nblumhardt]

@Tratcher thanks 👍 - don't think I have the privs to view that PR, though.

[Tratcher]

Try this just after your exception handler:

            app.Use((context, next) => {
                context.SetEndpoint(null);
                return next();
            });

[nblumhardt]

Aha, makes sense, thanks!