Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HTTP/3: Cancellation causing ObjectDisposedException #56683

Closed
JamesNK opened this issue Aug 1, 2021 · 10 comments · Fixed by #57318
Closed

HTTP/3: Cancellation causing ObjectDisposedException #56683

JamesNK opened this issue Aug 1, 2021 · 10 comments · Fixed by #57318
Assignees
Milestone

Comments

@JamesNK
Copy link
Member

JamesNK commented Aug 1, 2021

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
@ghost
Copy link

ghost commented Aug 1, 2021

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

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);
response.Dispose();

var count = await readTask; // 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
Author: JamesNK
Assignees: -
Labels:

area-System.Net.Http

Milestone: -

@dotnet-issue-labeler dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Aug 1, 2021
@CarnaViire
Copy link
Member

I would say it's not cancellation per se, but using cancellation token together with Dispose - a race happens, so if disposal is faster, then cancellation token callback aborting the read will deal with stream already in disposed state.

I guess we might want to swallow the exception here but I still wonder if it's the right thing to do. I mean, if Dispose is called together with something, ODE could be expected? Or am I wrong?

case OperationCanceledException oce when oce.CancellationToken == cancellationToken:
_stream.AbortRead((long)Http3ErrorCode.RequestCancelled);

I would guess there still might be a race between IOException(HttpRequestException(QuicOperationAbortedException)) (Dispose stopped the waiter) and OperationCanceledException (CT callback stopped the waiter)

@wfurt
Copy link
Member

wfurt commented Aug 2, 2021

What would you expect @JamesNK ? It feels like ObjectDisposedException is reasonable if you call dispose.
AFAIK this is not specidfic to QUIC/H3. If you cancel, Dispose and possibly get error from peer it will be all race.

@JamesNK
Copy link
Member Author

JamesNK commented Aug 2, 2021

I expect HttpResponseMessage.Dispose() to cancel. A reminder that HttpResponseMessage.Dispose() is how you cancel a response that has returned headers. Dispose definitely shouldn't throw ObjectDisposedException.

#54294 @geoffkizer 😋

@CarnaViire
Copy link
Member

Dispose is a way to cancel. That is very much true.
Cancellation token also is a way to cancel.
Calling them together is a race.
Dispose is not throwing ODE. Cancellation token handling does.

There is no similar race in HTTP/2 currently only because Cancellation token is not a way to cancel there and we discussed previously that it's a bug.

By Cancellation token I mean the one passed to Content's ReadAsync. Meaning, it is also a response that has returned headers.


Remembering gRPC code, maybe you may not pass full gRPC call's CT to ReadAsync (and only pass user provided one) -- as you call Dispose on it's triggering, so reading would still be cancelled by full gRPC call's CT, but there would be no race discussed here? Or do I miss something?

@JamesNK
Copy link
Member Author

JamesNK commented Aug 4, 2021

Ok. I thought when you discussed a cancellation token you were referring to the one passed to invoker.SendAsync. I wasn't aware that responseStream.ReadAsync also disposed in HTTP/3. I'm used to HTTP/2 behavior where that wasn't the case.

Yes, gRPC will trigger both methods of cancellation together:

https://github.com/grpc/grpc-dotnet/blob/8db4604542f03d2d482d4b34c9950e19a1ba41d0/src/Grpc.Net.Client/Internal/GrpcCall.cs#L384-L391

@ManickaP
Copy link
Member

ManickaP commented Aug 5, 2021

@JamesNK is there something left for us to fix? If I get it right, this should be fixed in Grpc by not using the call's CT in ReadAsync.

@CarnaViire I remember we had a discussion saying that the problem is not the H/3 behavior but H/2 behavior which allows this to work. Do I remember it correctly or was it something else? If yes, is there any issue filed from that discussion?

@JamesNK
Copy link
Member Author

JamesNK commented Aug 5, 2021

@JamesNK is there something left for us to fix? If I get it right, this should be fixed in Grpc by not using the call's CT in ReadAsync.

gRPC isn't doing anything wrong. It's triggering a cancellation token - a perfectly normal thing to do - then calling HttpResponseMessage.Dispose() - also normal.

The problem is HttpClient turns these normal actions into a race that can explode. The race should be fixed in HttpClient.

@geoffkizer
Copy link
Contributor

Just to make sure I understand this properly:

There's a race between cancelling the ReadAsync on the response stream and disposing the response stream, as to which one causes the request to abort. Correct?

Which case is it where you get the ODE?

If Dispose happens first, it should cancel the read and the read should throw something like IOException("Request aborted").
If cancellation happens first, you should get OperationCanceledException.

Is that not what is happening today?

@ManickaP ManickaP removed the untriaged New issue has not been triaged by the area owner label Aug 10, 2021
@ManickaP ManickaP added this to the 6.0.0 milestone Aug 10, 2021
@ManickaP
Copy link
Member

Triage: we might get rid of the disposed check in abort methods on the stream. I'll talk with @CarnaViire about the exact place. Also she knows which test covers this, albeit not every time it runs. I might squash this with my work on #56129, which is related.

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Aug 12, 2021
CarnaViire added a commit that referenced this issue Aug 13, 2021
Allow calling Abort(Read|Write) after disposing. The only safe option to do so is to make them no-op in that case.

Fixes #56683
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Aug 13, 2021
@ghost ghost locked as resolved and limited conversation to collaborators Sep 12, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants