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/2 request doesn't report the correct reason why request ends on connection GOAWAY #97128

Closed
JamesNK opened this issue Jan 18, 2024 · 2 comments · Fixed by #104707
Closed
Assignees
Labels
area-System.Net.Http bug in-pr There is an active PR which will close this issue when it is merged
Milestone

Comments

@JamesNK
Copy link
Member

JamesNK commented Jan 18, 2024

Description

A customer ran into a HTTP/2 error scenario and asked why the real failure reason wasn't in the error message: grpc/grpc-dotnet#2361 (comment). Seeing this error is important for debugging because the server can trigger a GOAWAY and knowing the error code is important for understanding why the server closed the connection.

Scenario:

  1. Response data from a HTTP/2 request is being read from the response stream
  2. The underlying HTTP/2 connection is killed because of a GOAWAY form the server
  3. The user sees an unhelpful/deceptive message:
System.Net.Http.HttpIOException: The response ended prematurely while waiting for the next frame from the server. (ResponseEnded)
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryReadFromBuffer(Span`1 buffer, Boolean partOfSyncRead)
   at System.Net.Http.Http2Connection.Http2Stream.ReadDataAsync(Memory`1 buffer, HttpResponseMessage responseMessage, CancellationToken cancellationToken)

The error gives the impression that the request ended because the server unexpectedly stopped sending response data. The real reason there are no more frames is because the server closed the connection with a GOAWAY. That information (GOAWAY + enhance your calm protocol code) should be bubbled up to this error message.

Something like:

The response ended because the server ended the HTTP/2 connection. Error code: ENHANCE_YOUR_CALM.

Today the only way to figure out why the HTTP/2 request failed is to attach an event source listener. That displays:

ProcessIncomingFramesAsync,Frame 15: StreamId=0; Type=GoAway; Flags=None; PayloadLength=22.
ReadGoAwayFrame,lastStreamId=1, errorCode=EnhanceYourCalm

Setting up an event source listener is advanced and shouldn't be required to find out important error information like this.

Reproduction Steps

  1. Client starts an HTTP/2 request and awaits response headers
  2. Server returns response headers
  3. Client reads from response stream
  4. Server sends a GOAWAY
  5. Client gets the unhelpful error

Here is an example in logs:

ping-goaway.txt

Expected behavior

A more useful error message. It should say the response ended because the connection ended. It should include the GOAWAY error code.

Something like:

The response ended because the server ended the HTTP/2 connection. Error code: ENHANCE_YOUR_CALM.

Actual behavior

Unhelpful error message.

Regression?

No response

Known Workarounds

No response

Configuration

No response

Other information

No response

@ghost
Copy link

ghost commented Jan 18, 2024

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

Issue Details

Description

If a HTTP/2 request is being read from the response stream and the underlying HTTP/2 connection is killed because of a GOAWAY form the server, the user sees a deceptive message:

System.Net.Http.HttpIOException: The response ended prematurely while waiting for the next frame from the server. (ResponseEnded)
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryReadFromBuffer(Span`1 buffer, Boolean partOfSyncRead)
   at System.Net.Http.Http2Connection.Http2Stream.ReadDataAsync(Memory`1 buffer, HttpResponseMessage responseMessage, CancellationToken cancellationToken)

It gives the impression that the request ended because the server unexpectedly stopped sending response data. The real reason the response ended and there are no more frames is because the server closed the connection with a GOAWAY. That information (GOAWAY + enhance your calm protocol code) should be bubbled up to this error message.

Something like:

The response ended because the server ended the HTTP/2 connection. Error code: ENHANCE_YOUR_CALM.

Today the only way to figure out why the HTTP/2 request failed is to attach an event source listener. That displays:

ProcessIncomingFramesAsync,Frame 15: StreamId=0; Type=GoAway; Flags=None; PayloadLength=22.
ReadGoAwayFrame,lastStreamId=1, errorCode=EnhanceYourCalm

Setting up an event source listener is advanced and shouldn't be required to find out important error information like this.

Reproduction Steps

  1. Client starts an HTTP/2 request and awaits response headers
  2. Server returns response headers
  3. Client reads from response stream
  4. Server sends a GOAWAY
  5. Client gets the unhelpful error

Here is an example in logs:

ping-goaway.txt

Expected behavior

A more useful error message. It should say the response ended because the connection ended. It should include the GOAWAY error code.

Something like:

The response ended because the server ended the HTTP/2 connection. Error code: ENHANCE_YOUR_CALM.

Actual behavior

Unhelpful error message.

Regression?

No response

Known Workarounds

No response

Configuration

No response

Other information

No response

Author: JamesNK
Assignees: -
Labels:

area-System.Net.Http

Milestone: -

@ghost ghost added the untriaged New issue has not been triaged by the area owner label Jan 18, 2024
@antonfirsov
Copy link
Member

This should be a HttpProtocolException with a proper error code embedded. It would be nice to fix this in 9.0.

@antonfirsov antonfirsov removed the untriaged New issue has not been triaged by the area owner label Jan 18, 2024
@antonfirsov antonfirsov added this to the 9.0.0 milestone Jan 18, 2024
@MihaZupan MihaZupan added the bug label Jun 5, 2024
@liveans liveans self-assigned this Jul 11, 2024
@dotnet-policy-service dotnet-policy-service bot added the in-pr There is an active PR which will close this issue when it is merged label Jul 11, 2024
@github-actions github-actions bot locked and limited conversation to collaborators Aug 11, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-System.Net.Http bug in-pr There is an active PR which will close this issue when it is merged
Projects
None yet
4 participants