What is causing OperationCanceledException in OWIN pipeline?

Question

I'm finding a lot of OperationCanceledExceptions in my API log. I think it is related to high load conditions, but that could just be because under higher load there's a higher number of calls and therefore a higher number of exceptions. The stack trace of the exception does not reach any controller code; it passes through some of my OWIN middleware but dies before it reaches any controller. And it's the same stack trace for many calls to different API endpoints:

System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at System.Net.Http.HttpContentExtensions.<ReadAsAsyncCore>d__0`1.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.Web.Http.ModelBinding.FormatterParameterBinding.<ExecuteBindingAsyncCore>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.Web.Http.Controllers.HttpActionBinding.<ExecuteBindingAsyncCore>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 System.Web.Http.Controllers.ActionFilterResult.<ExecuteAsync>d__2.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.Web.Http.Filters.AuthorizationFilterAttribute.<ExecuteAuthorizationFilterAsyncCore>d__2.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.Web.Http.Dispatcher.HttpControllerDispatcher.<SendAsync>d__1.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 MyDomain.Api.Handlers.ApiCultureHandler.<SendAsync>d__0.MoveNext() in D:\Bamboo\xml-data\build-dir\API-R5V3-JOB1\src\Api\Handlers\ApiCultureHandler.cs:line 50
--- 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.Web.Http.HttpServer.<SendAsync>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 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 Microsoft.Owin.Cors.CorsMiddleware.<Invoke>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 Microsoft.Owin.Host.SystemWeb.IntegratedPipeline.IntegratedPipelineContextStage.<RunApp>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Owin.Security.Infrastructure.AuthenticationMiddleware`1.<Invoke>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 Microsoft.Owin.Security.Infrastructure.AuthenticationMiddleware`1.<Invoke>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 DependencyResolution.Api.Middleware.AuditLogMiddleware.<Invoke>d__1.MoveNext() in D:\Bamboo\xml-data\build-dir\API-R5V3-JOB1\src\DependencyResolution\Api\Middleware\AuditLogMiddleware.cs:line 23
--- 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 DependencyResolution.Api.Middleware.ShardingMiddleware.<Invoke>d__2.MoveNext() in D:\Bamboo\xml-data\build-dir\API-R5V3-JOB1\src\DependencyResolution\Api\Middleware\ShardingMiddleware.cs:line 77
--- 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 DependencyResolution.Api.Middleware.StructureMapMiddleware.<Invoke>d__2.MoveNext() in D:\Bamboo\xml-data\build-dir\API-R5V3-JOB1\src\DependencyResolution\Api\Middleware\StructureMapMiddleware.cs:line 29
--- 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 DependencyResolution.Api.Middleware.ExceptionHandlerMiddleware.<Invoke>d__3.MoveNext() in D:\Bamboo\xml-data\build-dir\API-R5V3-JOB1\src\DependencyResolution\Api\Middleware\ExceptionHandlerMiddleware.cs:line 33

This is very disturbing, as I'm not sure how to debug this.

Additional possibly useful information: at the time these errors were happening, one of my API servers was exhibiting what I call the "Bart Simpson" pattern in CPU usage. CPU would shoot up to the 95-100% range for about 20-30 seconds, then it would drop off to 5-10% for another 20-30 seconds, then back up again. The cycle repeated indefinitely. Because we were in production, I didn't have time to investigate much further, I killed that server and let our autoscaling rules bring up a new server, which then worked fine. But I have no guarantee that the Bart Simpson pattern won't affect any other API servers we bring up, and I have no idea what might cause it.

Any ideas?

Answer 1

Since there is no other error in your code in the call stack, this is likely a false alarm. If the client closes the connection before the server responds, the operation will be cancelled. Let's say, for example, that your client has a heartbeat endpoint that it invokes every 5 seconds, and the call takes 250 ms. Every time a client shuts down, there is a 5% chance of getting an operation cancelled. There are many normal scenarios where a connection may be cut off by the client before a response is received. OperationCanceledException by itself should not be a cause for alarm. However, do consider the frequency in relation to the number of clients and your specific application as well.

Answer 2

As discussed, it is possible that somewhere, in one of those custom middle-ware listed in the stack trace, there may be a mixing of async await and blocking calls (.Result or .Wait()) that may be leading to a deadlock that is causing the operation to hang, timeout and cancel.

The stack trace snippet has already provided a list of possible suspects.

It is suggested to start by inspecting the Invoke of the listed middle ware that handle the request pipeline.