Efcore: Add a way to suppress/filter logging of TaskCanceledExceptions thrown by user-triggered cancellation

[ascott18]

What problem are you trying to solve?
Right now, logs for exceptions thrown due to CancellationToken cancellation are categorized as Microsoft.EntityFrameworkCore.Query[10100]. I want to be able to keep logging all other kinds of query errors, but not ones for intentional cancellations. In my application, I'm passing aspnetcore's HttpContext.RequestedAborted token to my async EF query evaluations. If the client hangs up, there's no reason to keep querying the database working to evaluate what are in some cases quite complex search queries in an intranet application (e.g. if the client changed their search criteria, or just left the page).

We'd like to not pollute our logs with these exceptions that are fully expected. We have an ActionFilter where we handle the exception as far as aspnetcore is concerned, but EF itself still logs the error.

For example:

fail: Microsoft.EntityFrameworkCore.Query[10100]
      An exception occurred while iterating over the results of a query for context type 'My.App.AppDbContext'.
      System.Threading.Tasks.TaskCanceledException: A task was canceled.
         at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.BufferlessMoveNext(DbContext _, Boolean buffer, CancellationToken cancellationToken)
         at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func`4 operation, Func`4 verifySucceeded, CancellationToken cancellationToken)
         at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.MoveNext(CancellationToken cancellationToken)
         at System.Linq.AsyncEnumerable.SelectEnumerableAsyncIterator`2.MoveNextCore(CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\Select.cs:line 106
         at System.Linq.AsyncEnumerable.AsyncIterator`1.MoveNext(CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\AsyncIterator.cs:line 98
         at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext(CancellationToken cancellationToken)
System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.BufferlessMoveNext(DbContext _, Boolean buffer, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func`4 operation, Func`4 verifySucceeded, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncQueryingEnumerable`1.AsyncEnumerator.MoveNext(CancellationToken cancellationToken)
   at System.Linq.AsyncEnumerable.SelectEnumerableAsyncIterator`2.MoveNextCore(CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\Select.cs:line 106
   at System.Linq.AsyncEnumerable.AsyncIterator`1.MoveNext(CancellationToken cancellationToken) in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\AsyncIterator.cs:line 98
   at Microsoft.EntityFrameworkCore.Query.Internal.AsyncLinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext(CancellationToken cancellationToken)

Describe the solution you'd like

Create a dedicated log category for OperationCanceledExceptions that are caused by userspace-provided CancellationTokens that I can then setup a regular logging filter against.

Alternatively, just do not log OperationCanceledException at all if the CancellationToken has been triggered, since this is generally always an intentional outcome if the user has passed a CancellationToken to their query evaulations. This would be a much simpler path, but may have unintended consequences.

[ajcvickers]

Note from team discussion: putting this on the backlog to consider generating a different logging event when the exception is "TaskCanceledException".

[MattJacobi-ESO]

I'm having this problem as well. I would like to provide some additional context. Sometimes cancellation can actually generate multiple errors, some of which cannot be identified as being caused by cancellation.

For example, if you trigger the cancellation token before the database connection is made, you'll actually get two errors logged:

Error 1

Microsoft.EntityFrameworkCore.Database.Connection: An error occurred using the connection to database '<mydb>' on server '<myserver>'.

Error 2

Microsoft.EntityFrameworkCore.Query: An exception occurred while iterating over the results of a query for context type '<mydbcontext>'.
System.Threading.Tasks.TaskCanceledException: A task was canceled.
<callstack>

Error 2 is noise -- and I'd love to be able to suppress it -- but it is at least possible to conclude that the error is likely due to a cancellation token. You can use the presence of "TaskCanceledException" to filter it out.

However, if you look at Error 1, there is no indication that this was actually caused by cancellation. This can lead to unnecessary investigation. And there is also no way to filter it out as "noise".