3

Closed

Unhandled exception is being logged when client cancels requests

description

Scenario:
When a user loads a page, it makes one or more ajax requests, which hit ASP.NET Web API 2 controllers. If the user navigates to another page, before these ajax requests complete, the requests are canceled by the browser. (from here)

Issue:
A long entry is made for each cancelled request.

Proposed:
Ignore the exceptions caused due to the cancellation request made by the client.

Workaround:
Create a custom message handler which the user could check if the request got cancelled and ignore the cancelled tasks (look here for more information):
config.MessageHandlers.Add(new CancelledTaskBugWorkaroundMessageHandler());

class CancelledTaskBugWorkaroundMessageHandler : DelegatingHandler
{
    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        HttpResponseMessage response = await base.SendAsync(request, cancellationToken);

        // Try to suppress response content when the cancellation token has fired; ASP.NET will log to the Application event log if there's content in this case.
        if (cancellationToken.IsCancellationRequested)
        {
            return new HttpResponseMessage(HttpStatusCode.InternalServerError);
        }

        return response;
    }
}
Attached a repro web application.

file attachments

Closed Apr 30, 2014 at 3:02 PM by kichalla
Verified.

comments

davidmatson wrote Mar 26, 2014 at 10:01 PM

There's a prototype fix changeset on a fork.

nowakra wrote Apr 24, 2014 at 10:38 PM

ec06c2ae494ebed624285a830852729d78c05ba0 contains a partial fix for this issue. This will be fully fixed when Codeplex-1789 is also fixed.

derekmt12 wrote Sep 5, 2014 at 12:53 PM

I recently upgraded my version of Web API to 5.2.2 to get rid of these cancellation exceptions. My project was pushed to production last night, and nothing has changed. Cancellation exceptions are still being thrown. I don't think this bug is totally fixed.

kichalla wrote Sep 8, 2014 at 2:37 PM

@derekmt12:
Can you provide more details regarding this? We have seen users mentioning that this has already fixed this problem, but would like to know if your application setup is different in which case you are still seeing this happen.

Could you share the exception stack trace and also do you have any exception filter registered etc?

Thanks,
Kiran

jnapier wrote Sep 12, 2014 at 11:54 PM

I upgraded as well. I put a thread.sleep in one of my api calls to simulate this. Basically call the api and navigate to a different url before the response is returned. We are using an ExceptionFilterAttribute to log errors and have not switched to an IExceptionLogger yet. The exception is still logged. If we switch to the IExceptionLogger will the exception not bubble up that high with this update?

kichalla wrote Sep 15, 2014 at 3:55 PM

@jnapier:
I have tried a scenario similar to yours (I used Task.Dely instead of Thread.Sleep in my case)but couldn't repro it...Can you share a standalone repro so that we can take a deeper look?

davidmatson wrote Sep 15, 2014 at 4:51 PM

@jnapier
Yes, exception filters will receive operation canceled exceptions while exception loggers will not. (Changing the exception filter behavior would be a breaking change, which is why there's this intentional behavior difference.)

If you're curious, you can see the difference in behavior fairly clearly in the source code:
http://aspnetwebstack.codeplex.com/SourceControl/latest#src/System.Web.Http/Controllers/ExceptionFilterResult.cs

BrockAllen wrote Apr 13, 2015 at 2:40 PM

Was this ever fixed in Web API? We're still seeing this issue on v5.2.3.

WayneBrantley wrote Apr 15, 2015 at 1:23 PM

I am getting this too in v5.2.3. Here is the detail.
I am using IExceptionLogger to log the error.
I have an ExceptionFilterAttribute also - as you see below. But the job of that is to wrap certain exceptions to the client. It does not log.
            httpConfig.Filters.Add(new ExceptionHandlingWebApiAttribute());
            httpConfig.Services.Add(typeof(IExceptionLogger), new SerilogExceptionLogger(container.Resolve<ILogger>()));
Exception:
System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowIfCancellationRequested()
   at System.Web.Http.Owin.HttpMessageHandlerAdapter.<BufferResponseContentAsync>d__13.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at System.Web.Http.Owin.HttpMessageHandlerAdapter.<InvokeCore>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Owin.OwinExtensions.<>c__DisplayClass2.<<UseAutofacMiddleware>b__0>d__7.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContextStage.<RunApp>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContext.<DoFinalWork>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContext.EndFinalWork(IAsyncResult ar)
   at System.Web.HttpApplication.AsyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

WayneBrantley wrote Oct 14, 2015 at 1:39 PM

manikyalarao wrote Apr 7, 2016 at 10:57 AM

I have this issue too with asp.net web api 5.2.3
Please prioritize this issue we are facing the same issue with asp.net web api 5.2.3 and Let me know in which release you are planning to fix this issue

bunceg wrote Apr 8, 2016 at 11:06 AM

I'm getting this too. In my case the Cancellation token is setup within the webapi controller method, and set to cancel after xx seconds. So, the webapi itself if cancelling the request if it's taking too long (we depend on downstream systems so cancel if they are not responding in time).

When the cancellation token fires, the webapi call is cancelled but the global exception handler (implementation of IExceptionHandler) is not fired at all. We get a 500 and then an unhandled ASP.NET exception in the Even Log.

WebApi 5.2.3

sbowe wrote Sep 29 at 12:56 PM

This is still not fixed in 5.2.3