Skip to content

HTTP/3: Cancellation causing ObjectDisposedException #56683

Closed
@JamesNK

Description

@JamesNK

Test: ServerStreaming_CancellationOnClientWhileMoveNext_CancellationSentToServer
Code: https://github.com/JamesNK/grpc-dotnet/tree/jamesnk/http3

I think this problem can be reproduced by:

var response = await client.SendAsync(request);
var responseStream = await response.Context.ReadAsStreamAsync();
var readTask = responseStream.ReadAsync(new byte[1024); // ReadAsync is waiting for content from the server
response.Dispose(); // Cancel request

var count = await readTask; // Error

Or it might be a CancellationToken passed to ReadAsync being canceled while waiting for content from the server. I think both are triggered when gRPC cancels a request.

Otherwise, debug using the gRPC test. It consistently throws this error.

Logs:

 ServerStreaming_CancellationOnClientWhileMoveNext_CancellationSentToServer
   Source: CancellationTests.cs line 353
   Duration: 696 ms

  Message: 
  Expected: Cancelled
  But was:  Internal

TearDown : System.Exception : 1 error(s) logged.
Grpc.Net.Client.Internal.GrpcCall - ErrorReadingMessage - Error reading message.
===================
System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'MsQuicStream'.
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.ThrowIfDisposed() in System.Net.Quic.dll:token 0x600015c+0x13
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.AbortRead(Int64 errorCode) in System.Net.Quic.dll:token 0x600013f+0x0
   at System.Net.Quic.QuicStream.AbortRead(Int64 errorCode) in System.Net.Quic.dll:token 0x60000b6+0x0
   at System.Net.Http.Http3RequestStream.HandleReadResponseContentException(Exception ex, CancellationToken cancellationToken) in System.Net.Http.dll:token 0x60006d7+0x9b
   at System.Net.Http.Http3RequestStream.ReadResponseContentAsync(HttpResponseMessage response, Memory`1 buffer, CancellationToken cancellationToken) in System.Net.Http.dll:token 0x60006d6+0x282
   at Grpc.Net.Client.StreamExtensions.ReadMessageAsync[TResponse](Stream responseStream, GrpcCall call, Func`2 deserializer, String grpcEncoding, Boolean singleMessage, CancellationToken cancellationToken) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\StreamExtensions.cs:line 78
   at Grpc.Net.Client.Internal.HttpContentClientStreamReader`2.MoveNextCore(CancellationToken cancellationToken) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\HttpContentClientStreamReader.cs:line 165
===================

  Stack Trace: 
CancellationTests.ServerStreaming_CancellationOnClientWhileMoveNext_CancellationSentToServer() line 397
framework.dll:token 0x6000d7a+0x7
framework.dll:token 0x6000d33+0x1
framework.dll:token 0x60003e4+0x34
framework.dll:token 0x6000839+0x3b
framework.dll:token 0x6000838+0x1
framework.dll:token 0x6000e09+0x18
framework.dll:token 0x6000815+0x2
--TearDown
VerifyNoErrorsScope.Dispose() line 82
GrpcTestContext.Dispose() line 106
FunctionalTestBase.TearDown() line 103

  Standard Output: 
0.003s GrpcTestContext - Information: Starting CancellationTests.ServerStreaming_CancellationOnClientWhileMoveNext_CancellationSentToServer
0.011s SERVER Grpc.AspNetCore.Server.Model.Internal.ServiceRouteBuilder - Trace: Discovering gRPC methods for FunctionalTestsWebsite.Infrastructure.DynamicService.
0.012s SERVER Grpc.AspNetCore.Server.Model.Internal.BinderServiceMethodProvider - Debug: Could not find bind method for FunctionalTestsWebsite.Infrastructure.DynamicService.
0.013s SERVER Grpc.AspNetCore.Server.Model.Internal.ServiceRouteBuilder - Trace: Added gRPC method 'bc027380-89ed-4d36-af62-03ac42508f54' to service 'DynamicService'. Method type: 'ServerStreaming', route pattern: '/DynamicService/bc027380-89ed-4d36-af62-03ac42508f54'.
0.049s Grpc.Net.Client.Internal.GrpcCall - Debug: Starting gRPC call. Method type: 'ServerStreaming', URI: 'https://127.0.0.1:50019/DynamicService/bc027380-89ed-4d36-af62-03ac42508f54'.
0.103s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Connection id "0HMAKJLM78N1T" accepted.
0.108s SERVER Microsoft.AspNetCore.Server.Kestrel.Connections - Debug: Connection id "0HMAKJLM78N1T" accepted.
0.109s SERVER Microsoft.AspNetCore.Server.Kestrel.Connections - Debug: Connection id "0HMAKJLM78N1T" started.
0.129s Grpc.Net.Client.Internal.GrpcCall - Debug: Sending message.
0.135s Grpc.Net.Client.Internal.GrpcCall - Trace: Serialized 'Streaming.DataMessage' to 0 byte message.
0.140s Grpc.Net.Client.Internal.GrpcCall - Trace: Message sent.
0.166s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMAKJLM78N1T:00000003" type Unidirectional connected.
0.183s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMAKJLM78N1T:00000002" type Unidirectional accepted.
0.183s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMAKJLM78N1T:00000000" type Bidirectional accepted.
0.189s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMAKJLM78N1T" received SETTINGS frame for stream ID 2 with length 5.
0.190s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMAKJLM78N1T" received HEADERS frame for stream ID 0 with length 260.
0.241s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMAKJLM78N1T" received DATA frame for stream ID 0 with length 5.
0.247s SERVER Microsoft.AspNetCore.Hosting.Diagnostics - Information: Request starting HTTP/3 POST https://127.0.0.1:50019/DynamicService/bc027380-89ed-4d36-af62-03ac42508f54 application/grpc -
0.274s SERVER Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware - Debug: Request matched endpoint 'gRPC - /DynamicService/bc027380-89ed-4d36-af62-03ac42508f54'
0.278s SERVER Microsoft.AspNetCore.Routing.EndpointMiddleware - Information: Executing endpoint 'gRPC - /DynamicService/bc027380-89ed-4d36-af62-03ac42508f54'
0.287s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Reading message.
0.287s SERVER Microsoft.AspNetCore.Server.Kestrel - Debug: Connection id "0HMAKJLM78N1T", Request id "0HMAKJLM78N1T:00000000": started reading request body.
0.287s SERVER Microsoft.AspNetCore.Server.Kestrel - Debug: Connection id "0HMAKJLM78N1T", Request id "0HMAKJLM78N1T:00000000": done reading request body.
0.290s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Deserializing 0 byte message to 'Streaming.DataMessage'.
0.293s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Received message.
0.301s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMAKJLM78N1T" sending HEADERS frame for stream ID 0 with length 84.
0.301s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Sending message.
0.301s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Serialized 'Streaming.DataMessage' to 0 byte message.
0.303s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMAKJLM78N1T" sending DATA frame for stream ID 0 with length 5.
0.304s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Message sent.
0.304s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Sending message.
0.304s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Serialized 'Streaming.DataMessage' to 0 byte message.
0.304s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMAKJLM78N1T" sending DATA frame for stream ID 0 with length 5.
0.304s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Message sent.
0.309s Grpc.Net.Client.Internal.GrpcCall - Trace: Response headers received.
0.313s Grpc.Net.Client.Internal.GrpcCall - Debug: Reading message.
0.315s Grpc.Net.Client.Internal.GrpcCall - Trace: Deserializing 0 byte message to 'Streaming.DataMessage'.
0.316s Grpc.Net.Client.Internal.GrpcCall - Trace: Received message.
0.317s Grpc.Net.Client.Internal.GrpcCall - Debug: Reading message.
0.317s Grpc.Net.Client.Internal.GrpcCall - Trace: Deserializing 0 byte message to 'Streaming.DataMessage'.
0.317s Grpc.Net.Client.Internal.GrpcCall - Trace: Received message.
0.319s Grpc.Net.Client.Internal.GrpcCall - Debug: Reading message.
0.522s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'Cancelled', Message: 'Call canceled by the client.'.
0.523s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.
0.523s Grpc.Net.Client.Internal.GrpcCall - Debug: gRPC call canceled.
0.631s Grpc.Net.Client.Internal.GrpcCall - Error: Error reading message.
System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'MsQuicStream'.
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.ThrowIfDisposed() in System.Net.Quic.dll:token 0x600015c+0x13
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.AbortRead(Int64 errorCode) in System.Net.Quic.dll:token 0x600013f+0x0
   at System.Net.Quic.QuicStream.AbortRead(Int64 errorCode) in System.Net.Quic.dll:token 0x60000b6+0x0
   at System.Net.Http.Http3RequestStream.HandleReadResponseContentException(Exception ex, CancellationToken cancellationToken) in System.Net.Http.dll:token 0x60006d7+0x9b
   at System.Net.Http.Http3RequestStream.ReadResponseContentAsync(HttpResponseMessage response, Memory`1 buffer, CancellationToken cancellationToken) in System.Net.Http.dll:token 0x60006d6+0x282
   at Grpc.Net.Client.StreamExtensions.ReadMessageAsync[TResponse](Stream responseStream, GrpcCall call, Func`2 deserializer, String grpcEncoding, Boolean singleMessage, CancellationToken cancellationToken) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\StreamExtensions.cs:line 78
0.683s GrpcTestContext - Information: Finishing CancellationTests.ServerStreaming_CancellationOnClientWhileMoveNext_CancellationSentToServer

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions