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.

Sign up for GitHub

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

Jump to bottom

HTTP/2: Possible race when receiving HEADERS and RST_STREAM together #68373

Closed
JamesNK opened this issue Apr 22, 2022 · 16 comments · Fixed by #72932
Closed

HTTP/2: Possible race when receiving HEADERS and RST_STREAM together #68373

JamesNK opened this issue Apr 22, 2022 · 16 comments · Fixed by #72932
Assignees
@rzikm
Labels
area-System.Net.Http bug tenet-reliability Reliability/stability related issue (stress, load problems, etc.)
Milestone
7.0.0

Comments

@JamesNK
Copy link
Member

JamesNK commented Apr 22, 2022 •
edited
Loading

Description

Kestrel has recently updated how HTTP/2 is written. One of the changes is to what happens if a request is ended and then the request is immediately reset. At a frame-level, Kestrel is writing a HEADERS frame with an END_HEADERS flag, then writing a RST_STREAM. Before, Kestrel would pause after writing HEADERS, as the bytes are flushed to the client. After the update, Kestrel would write and send the two frames together.

In HttpClient, before, SendAsync would always return HttpResponseMessage. With the new server behavior, SendAsync continues to return HttpResponseMessage (about 90% of the time). Other times it throws an error:

System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The request was aborted.
 ---> System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 443

The HEADERS frame and RST_STREAM frame are always written in the right order. There appears to be a race between how they're processed.

If response headers are returned then SendAsync should always return HttpResponseMessage, regardless of the fact it is followed by RST_STREAM.

Reproduction Steps

HttpInvoker + SocketsHttpHandler + h2c makes call to server.
The server writes response headers with HEADERS frame and END_STREAM flag, together with RST_STREAM (NO_ERROR).The server

Expected behavior

HttpResponseMessage is always returned.

Actual behavior

HttpInvoker.SendAsync fails 10% of the time with an error.

Regression?

Probably not. Kestrel has changed in .NET 7, but I believe the timing of how it sends frames has exposed a race that has been in the client's HTTP/2 processing.

Known Workarounds

No response

Configuration

.NET SDK 7.0.100-preview.5.22221.9

Other information

Logs below. Truncated to just show the end of the request.

Logging of success (HttpResponseMessage returned):

0.523s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Request with timeout of 00:00:00.5000000 has exceeded its deadline.
0.523s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Resetting response stream with error code 0.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Debug: Trace id "0HMH40UT8UKOA:000000C9": HTTP/2 stream error "NO_ERROR". A Reset is being sent to the stream.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/2 stream was reset by the application with error code NO_ERROR.
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending HEADERS frame for stream ID 201 with length 40 and flags END_HEADERS.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending RST_STREAM frame for stream ID 201 with length 4 and flags 0x0.
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 231: StreamId=201; Type=Headers; Flags=EndHeaders; PayloadLength=40. ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessHeadersFrame,StreamId=201; Type=Headers; Flags=EndHeaders; PayloadLength=40 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnStatus,Status code is 200 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Content-Type: application/grpc ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Date: Fri, 22 Apr 2022 02:29:01 GMT ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Server: Kestrel ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Content-Length: 0 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,grpc-status: 4 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,grpc-message: Deadline Exceeded ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 232: StreamId=201; Type=RstStream; Flags=None; PayloadLength=4. ->
0.523s HttpEventSourceListener - Debug: <- Event System.Net.Http - ResponseHeadersStop :  ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,ProcessRstStreamFrame,protocolError=NoError ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,ReadResponseHeadersAsync,Received response: StatusCode: 200, ReasonPhrase: 'OK', Version: 2.0, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Date: Fri, 22 Apr 2022 02:29:01 GMT
  Server: Kestrel
  grpc-status: 4
  grpc-message: Deadline Exceeded
  Content-Type: application/grpc
  Content-Length: 0
} ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnReset,resetException=System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0)., resetStreamErrorCode=NoError ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,Cancel, ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,SendReset,Stream reset. Request=Completed, Response=Failed. ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,Complete,Stream complete. Request=Completed, Response=Failed. ->
0.523s HttpEventSourceListener - Debug: <- Event System.Net.Http - RequestStop :  ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,RemoveStream, ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReleaseStream,_streamsInUse=1 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
0.523s Grpc.Net.Client.Internal.GrpcCall - Trace: Response headers received.
0.523s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'DeadlineExceeded', Message: 'Deadline Exceeded'.
0.523s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.

Failure (error thrown):

0.523s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Request with timeout of 00:00:00.5000000 has exceeded its deadline.
0.523s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Resetting response stream with error code 0.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Debug: Trace id "0HMH40UT8UKOA:0000003B": HTTP/2 stream error "NO_ERROR". A Reset is being sent to the stream.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/2 stream was reset by the application with error code NO_ERROR.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending HEADERS frame for stream ID 59 with length 40 and flags END_HEADERS.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending RST_STREAM frame for stream ID 59 with length 4 and flags 0x0.
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 71: StreamId=59; Type=Headers; Flags=EndHeaders; PayloadLength=40. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessHeadersFrame,StreamId=59; Type=Headers; Flags=EndHeaders; PayloadLength=40 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnStatus,Status code is 200 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Content-Type: application/grpc ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Date: Fri, 22 Apr 2022 02:28:20 GMT ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Server: Kestrel ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Content-Length: 0 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,grpc-status: 4 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,grpc-message: Deadline Exceeded ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 72: StreamId=59; Type=RstStream; Flags=None; PayloadLength=4. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,ProcessRstStreamFrame,protocolError=NoError ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnReset,resetException=System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0)., resetStreamErrorCode=NoError ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,Cancel, ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,SendReset,Stream reset. Request=Completed, Response=Failed. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,Complete,Stream complete. Request=Completed, Response=Failed. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,RemoveStream, ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReleaseStream,_streamsInUse=1 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,Cancel, ->
0.524s HttpEventSourceListener - Debug: <- Event System.Net.Http - RequestFailed :  ->
0.525s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - ErrorMessage : HttpClient#57263895,HandleFailure,System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The request was aborted.
 ---> System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken) ->
0.525s HttpEventSourceListener - Debug: <- Event System.Net.Http - RequestStop :  ->
0.525s Grpc.Net.Client.Internal.GrpcCall - Error: Error starting gRPC call.
System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The request was aborted.
 ---> System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 443
0.526s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'Unavailable', Message: 'Error starting gRPC call. HttpRequestException: An error occurred while sending the request. IOException: The request was aborted. Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).'.
0.526s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.
0.526s Grpc.Net.Client.Internal.GrpcCall - Debug: gRPC call canceled.
@dotnet-issue-labeler dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Apr 22, 2022
@ghost
Copy link

ghost commented Apr 22, 2022

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

Issue Details

Description

Kestrel has recently updated how HTTP/2 is written. One of the changes is to what happens if a request is ended and then the request is immediately reset. At a frame-level, Kestrel is writing a HEADERS frame with an END_HEADERS flag, then writing a RST_STREAM. Before, Kestrel would pause after writing HEADERS, as the bytes are flushed to the client. After the update, Kestrel would write and send the two frames together.

In HttpClient, before, SendAsync would always return HttpResponseMessage. With the new server behavior, SendAsync continues to return HttpResponseMessage (about 90% of the time). Other times it throws an error:

System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The request was aborted.
 ---> System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 443

The HEADERS frame and RST_STREAM frame are always written in the right order. There appears to be a race between how they're processed.

If response headers are returned then SendAsync should always return HttpResponseMessage, regardless of the fact it is followed by RST_STREAM.

Reproduction Steps

HttpInvoker + SocketsHttpHandler + h2c makes call to server.
The server writes response headers with HEADERS frame and END_STREAM flag, together with RST_STREAM (NO_ERROR).The server

Expected behavior

HttpResponseMessage is always returned.

Actual behavior

HttpInvoker.SendAsync fails 10% of the time with an error.

Regression?

Probably not.

Known Workarounds

No response

Configuration

.NET SDK 7.0.100-preview.5.22221.9

Other information

Logging of success (HttpResponseMessage returned):

0.523s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Request with timeout of 00:00:00.5000000 has exceeded its deadline.
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Resetting response stream with error code 0.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Debug: Trace id "0HMH40UT8UKOA:000000C9": HTTP/2 stream error "NO_ERROR". A Reset is being sent to the stream.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/2 stream was reset by the application with error code NO_ERROR.
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending HEADERS frame for stream ID 201 with length 40 and flags END_HEADERS.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending RST_STREAM frame for stream ID 201 with length 4 and flags 0x0.
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.Net.Client - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 231: StreamId=201; Type=Headers; Flags=EndHeaders; PayloadLength=40. ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessHeadersFrame,StreamId=201; Type=Headers; Flags=EndHeaders; PayloadLength=40 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnStatus,Status code is 200 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Content-Type: application/grpc ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Date: Fri, 22 Apr 2022 02:29:01 GMT ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Server: Kestrel ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,Content-Length: 0 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,grpc-status: 4 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnHeader,grpc-message: Deadline Exceeded ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 232: StreamId=201; Type=RstStream; Flags=None; PayloadLength=4. ->
0.523s HttpEventSourceListener - Debug: <- Event System.Net.Http - ResponseHeadersStop :  ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,ProcessRstStreamFrame,protocolError=NoError ->
0.523s HttpEventSourceListener - Debug: <- Event Grpc.AspNetCore.Server - EventCounters : System.Diagnostics.Tracing.EventPayload ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,ReadResponseHeadersAsync,Received response: StatusCode: 200, ReasonPhrase: 'OK', Version: 2.0, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Date: Fri, 22 Apr 2022 02:29:01 GMT
  Server: Kestrel
  grpc-status: 4
  grpc-message: Deadline Exceeded
  Content-Type: application/grpc
  Content-Length: 0
} ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,OnReset,resetException=System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0)., resetStreamErrorCode=NoError ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,Cancel, ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,SendReset,Stream reset. Request=Completed, Response=Failed. ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,Complete,Stream complete. Request=Completed, Response=Failed. ->
0.523s HttpEventSourceListener - Debug: <- Event System.Net.Http - RequestStop :  ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,201,RemoveStream, ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReleaseStream,_streamsInUse=1 ->
0.523s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
0.523s Grpc.Net.Client.Internal.GrpcCall - Trace: Response headers received.
0.523s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'DeadlineExceeded', Message: 'Deadline Exceeded'.
0.523s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.

Failure (error thrown):

0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending HEADERS frame for stream ID 59 with length 40 and flags END_HEADERS.
0.523s SERVER Microsoft.AspNetCore.Server.Kestrel.Http2 - Trace: Connection id "0HMH40UT8UKOA" sending RST_STREAM frame for stream ID 59 with length 4 and flags 0x0.
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 71: StreamId=59; Type=Headers; Flags=EndHeaders; PayloadLength=40. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessHeadersFrame,StreamId=59; Type=Headers; Flags=EndHeaders; PayloadLength=40 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnStatus,Status code is 200 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Content-Type: application/grpc ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Date: Fri, 22 Apr 2022 02:28:20 GMT ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Server: Kestrel ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,Content-Length: 0 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,grpc-status: 4 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnHeader,grpc-message: Deadline Exceeded ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReadFrameAsync,initialFrame=False ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ProcessIncomingFramesAsync,Frame 72: StreamId=59; Type=RstStream; Flags=None; PayloadLength=4. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,ProcessRstStreamFrame,protocolError=NoError ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,OnReset,resetException=System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0)., resetStreamErrorCode=NoError ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,Cancel, ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,SendReset,Stream reset. Request=Completed, Response=Failed. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,Complete,Stream complete. Request=Completed, Response=Failed. ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,RemoveStream, ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,ReleaseStream,_streamsInUse=1 ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
0.524s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 17968358,64923656,59,Cancel, ->
0.524s HttpEventSourceListener - Debug: <- Event System.Net.Http - RequestFailed :  ->
0.525s HttpEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - ErrorMessage : HttpClient#57263895,HandleFailure,System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The request was aborted.
 ---> System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken) ->
0.525s HttpEventSourceListener - Debug: <- Event System.Net.Http - RequestStop :  ->
0.525s Grpc.Net.Client.Internal.GrpcCall - Error: Error starting gRPC call.
System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The request was aborted.
 ---> System.Net.Http.Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 443
0.526s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'Unavailable', Message: 'Error starting gRPC call. HttpRequestException: An error occurred while sending the request. IOException: The request was aborted. Http2StreamException: The HTTP/2 server reset the stream. HTTP/2 error code 'NO_ERROR' (0x0).'.
0.526s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.
0.526s Grpc.Net.Client.Internal.GrpcCall - Debug: gRPC call canceled.
Author: JamesNK
Assignees: -
Labels:

area-System.Net.Http
Milestone: -

@JamesNK
Copy link
Member Author

JamesNK commented Apr 22, 2022

cc @davidfowl

@JamesNK JamesNK mentioned this issue Apr 22, 2022
Closed
1 task
@Junjun-zhao
Copy link
Member

@JamesNK We are in process of .NET 7 Preview 4 Validation window, it should be signed off by 4/29. Our test cases failed by this bug. Could you please confirm whether this issue is a blocker for Preview 4? Thanks.

@JamesNK
Copy link
Member Author

JamesNK commented Apr 26, 2022 •
edited
Loading

Not a blocker. Anyone impacted can update to the latest version of gRPC which shouldn't be affected.

@MihaZupan MihaZupan added the bug label Apr 26, 2022
@MihaZupan
Copy link
Member

Yep, there's a race here:

I think this can be fixed by changing the order of checks in TryEnsureHeaders to check for header completion first, before calling into CheckResponseBodyState.

@MihaZupan MihaZupan added the tenet-reliability Reliability/stability related issue (stress, load problems, etc.) label Apr 26, 2022
@karelz
Copy link
Member

karelz commented May 5, 2022

Triage: Sounds reasonable to fix it and not throw in technically valid response.
It is simple, so 7.0, but can be pushed out.

@karelz karelz added this to the 7.0.0 milestone May 5, 2022
@karelz karelz removed the untriaged New issue has not been triaged by the area owner label May 5, 2022
@halter73 halter73 mentioned this issue May 26, 2022
Closed
@lklein53
Copy link

Hi together,

Could this issue also explain the following behaviour we observed using the grpc-dotnet client (version 2.46.0) ?

If a HTTP2 connection is closed by the server by sending a GOAWAY frame to the client we sometimes observe the following error in the logs:

2022-05-30 18:57:23.878 <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 56388208,0,0,SendWithVersionDetectionAndRetryAsync,Retry attempt 1 after connection failure. Connection exception: System.Net.Http.HttpRequestException: The request was aborted.
 ---> System.Net.Http.Http2ConnectionException: The HTTP/2 server sent invalid data on the connection. HTTP/2 error code 'NO_ERROR' (0x0).
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRetry(String message, Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryEnsureHeaders()
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken) ->

After this we get a "Incomplete message" response in the client

2022-05-30 18:57:24.724 <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 56388208,26131301,1,OnHeader,grpc-status: 13 ->                                                                                                                                                                                                                            
2022-05-30 18:57:24.725 <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 56388208,26131301,1,OnHeader,grpc-message: Incomplete message. ->

Sadly i haven't been able to create a reproducer as the issue occurs very seldom and only after some time of running the application.

@davidfowl
Copy link
Member

Happens on .NET 7?

@lklein53
Copy link

lklein53 commented May 30, 2022 •
edited
Loading

Sorry forgot to mention its happening on .NET 6 (6.0.202) SDK

@ManickaP
Copy link
Member

Does this particular message sends any content? Do you have custom content?

@lklein53
Copy link

lklein53 commented May 30, 2022 •
edited
Loading

The request is a unary grpc call sending a request containing some bytes
and gets back a response message containing two int32 values. The implementation seems to use the PushUnaryContent HttpContent.
Does this answer your question ?
Any advice on how to further debug the issue would also be appreciated as i haven't found more infos in the logs.

@ManickaP
Copy link
Member

@JamesNK is is possible that gRPC HttpContent doesn't handle well being retried? E.g. it might partially send some data, then we get GO_AWAY and start retrying the message, but the content starts sending data from where it was interrupted during the GO_AWAY?

@halter73
Copy link
Member

halter73 commented Jun 1, 2022

The client is reporting an "Incomplete message" which seems to indicate it's an incomplete response body (according to the client) rather than in incomplete request body.

@lklein53
Copy link

lklein53 commented Jun 1, 2022 •
edited
Loading

I think the client is receiving a response from the server with grpc-status 13 and the message Incomplete message.

2022-05-30 18:57:24.724 <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 56388208,26131301,1,OnHeader,grpc-status: 13 ->                                                                                                                                                                                                                            
2022-05-30 18:57:24.725 <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 56388208,26131301,1,OnHeader,grpc-message: Incomplete message. ->

so for me it looks like the server received an incomplete request and replied with an error or am i missing something ?

@lklein53
Copy link

Hi,
any update on this issue or guidance on how to provide further information that might help ?

@ManickaP
Copy link
Member

I'd suggest filing issue in grpc repo for your particular problem, doesn't seem to be directly related.

@rzikm rzikm self-assigned this Jul 27, 2022
@rzikm rzikm mentioned this issue Jul 27, 2022
Merged
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Jul 27, 2022
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Jul 28, 2022
@ghost ghost locked as resolved and limited conversation to collaborators Aug 27, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@rzikm rzikm

Labels
area-System.Net.Http bug tenet-reliability Reliability/stability related issue (stress, load problems, etc.)
Projects
None yet
Milestone
7.0.0
Development

Successfully merging a pull request may close this issue.

Fix race when receiving HEADERS and RST_STREAM in rapid succession. rzikm/dotnet-runtime
9 participants
@halter73 @davidfowl @JamesNK @karelz @ManickaP @MihaZupan @rzikm @lklein53 @Junjun-zhao