Skip to content

Confused about unobserved exception #91100

@JamesNK

Description

@JamesNK

I have a unit test that checks for unobserved exceptions. I'm confused about a situation where an exception is being reported as unobserved:

The test successfully awaits an exception thrown from ResponseHeadersAsync, yet that exception is still being raised by the TaskScheduler.UnobservedTaskException event.

The PR with the new test is here: grpc/grpc-dotnet#2255. It also includes some fixes to suppress unobserved exceptions in some other situations. I can't figure out the one below, however.

Here is the log output:

 AsyncUnaryCall_CallFailed_NoUnobservedExceptions(0,False,ResponseHeadersAsync)
   Source: RetryTests.cs line 1081
   Duration: 340 ms

  Message: 
  Expected: 0
  But was:  1


  Stack Trace: 
<AsyncUnaryCall_CallFailed_NoUnobservedExceptions>d__28.MoveNext() line 1131
1)    at Grpc.Net.Client.Tests.Retry.RetryTests.<AsyncUnaryCall_CallFailed_NoUnobservedExceptions>d__28.MoveNext() in C:\Development\Source\grpc-dotnet\test\Grpc.Net.Client.Tests\Retry\RetryTests.cs:line 1131

  Standard Output: 
0.103s Grpc.Net.Client.Tests.CancellationTests - Debug: Starting call
0.132s Grpc.Net.Client.Internal.RetryCall - Trace: Starting retry worker.
0.134s Grpc.Net.Client.Internal.RetryCall - Debug: Starting attempt 1.
0.161s Grpc.Net.Client.Internal.GrpcCall - Debug: Starting gRPC call. Method type: 'Unary', URI: 'https://localhost/ServiceName/MethodName'.
0.173s Grpc.Net.Client.Internal.GrpcCall - Debug: Error starting gRPC call.
0.177s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'Internal', Message: 'Error starting gRPC call. Exception: Test error'.
System.Exception: Test error
   at Grpc.Net.Client.Tests.Retry.RetryTests.<>c.<AsyncUnaryCall_CallFailed_NoUnobservedExceptions>b__28_1(HttpRequestMessage request) in C:\Development\Source\grpc-dotnet\test\Grpc.Net.Client.Tests\Retry\RetryTests.cs:line 1104
   at Grpc.Tests.Shared.TestHttpMessageHandler.<>c__DisplayClass2_0.<<Create>b__0>d.MoveNext() in C:\Development\Source\grpc-dotnet\test\Shared\TestHttpMessageHandler.cs:line 38
--- 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 System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.GrpcCall`2.<RunCall>d__89.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 502
0.222s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.
0.225s Grpc.Net.Client.Internal.GrpcCall - Debug: gRPC call canceled.
0.229s Grpc.Net.Client.Internal.RetryCall - Debug: Evaluated retry for failed gRPC call. Status code: 'Internal', Attempt: 1, Retry: False
0.231s Grpc.Net.Client.Internal.RetryCall - Debug: Call commited. Reason: FatalStatusCode
0.232s Grpc.Net.Client.Internal.RetryCall - Trace: Stopping retry worker.
0.237s Grpc.Net.Client.Tests.CancellationTests - Debug: Waiting for finalizers
0.241s Grpc.Net.Client.Tests.CancellationTests - Critical: Unobserved task exception
System.AggregateException: A Task's exception(s) were not observed either by Waiting on the Task or accessing its Exception property. As a result, the unobserved exception was rethrown by the finalizer thread. ---> Grpc.Core.RpcException: Status(StatusCode="Internal", Detail="Error starting gRPC call. Exception: Test error", DebugException="System.Exception: Test error") ---> System.Exception: Test error
   at Grpc.Net.Client.Tests.Retry.RetryTests.<>c.<AsyncUnaryCall_CallFailed_NoUnobservedExceptions>b__28_1(HttpRequestMessage request) in C:\Development\Source\grpc-dotnet\test\Grpc.Net.Client.Tests\Retry\RetryTests.cs:line 1104
   at Grpc.Tests.Shared.TestHttpMessageHandler.<>c__DisplayClass2_0.<<Create>b__0>d.MoveNext() in C:\Development\Source\grpc-dotnet\test\Shared\TestHttpMessageHandler.cs:line 38
--- 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 System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.GrpcCall`2.<RunCall>d__89.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 502
   --- End of inner exception stack trace ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.GrpcCall`2.<GetResponseHeadersCoreAsync>d__79.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 333
--- 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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.Retry.RetryCallBase`2.<GetResponseHeadersCoreAsync>d__88.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\Retry\RetryCallBase.cs:line 141
--- 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 System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Grpc.Tests.Shared.ExceptionAssert.<ThrowsAsync>d__0`1.MoveNext() in C:\Development\Source\grpc-dotnet\test\Shared\ExceptionAssert.cs:line 36
   --- End of inner exception stack trace ---
---> (Inner Exception #0) Grpc.Core.RpcException: Status(StatusCode="Internal", Detail="Error starting gRPC call. Exception: Test error", DebugException="System.Exception: Test error") ---> System.Exception: Test error
   at Grpc.Net.Client.Tests.Retry.RetryTests.<>c.<AsyncUnaryCall_CallFailed_NoUnobservedExceptions>b__28_1(HttpRequestMessage request) in C:\Development\Source\grpc-dotnet\test\Grpc.Net.Client.Tests\Retry\RetryTests.cs:line 1104
   at Grpc.Tests.Shared.TestHttpMessageHandler.<>c__DisplayClass2_0.<<Create>b__0>d.MoveNext() in C:\Development\Source\grpc-dotnet\test\Shared\TestHttpMessageHandler.cs:line 38
--- 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 System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.GrpcCall`2.<RunCall>d__89.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 502
   --- End of inner exception stack trace ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.GrpcCall`2.<GetResponseHeadersCoreAsync>d__79.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 333
--- 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 System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
   at Grpc.Net.Client.Internal.Retry.RetryCallBase`2.<GetResponseHeadersCoreAsync>d__88.MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\Retry\RetryCallBase.cs:line 141
--- 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 System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Grpc.Tests.Shared.ExceptionAssert.<ThrowsAsync>d__0`1.MoveNext() in C:\Development\Source\grpc-dotnet\test\Shared\ExceptionAssert.cs:line 36<---

0.320s Grpc.Net.Client.Tests.CancellationTests - Debug: Observed exception was awaited by the test

The test:

  • Starts a fake gRPC call that immediately fails with an error.
  • Calls ResponseHeadersAsync on the gRPC client and catches the error thrown.
  • Runs GC/finalizes to trigger any unobserved exceptions.
  • Gets one unobserved exception and then verifies with Assert.AreSame that it is the same error that was thrown from ResponseHeadersAsync.

I don't know why the error is raised as unobserved when it was previously awaited and caught.

The behavior is consistent on .NET 4.x, .net6, .net7, .net8.

Metadata

Metadata

Assignees

No one assigned

    Labels

    area-System.Threading.TasksquestionAnswer questions and provide assistance, not an issue with source code or documentation.

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions