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

Jump to bottom

net/http: TestServerKeepAlivesEnabled_h2 test flake #18083

Closed
bradfitz opened this issue Nov 28, 2016 · 6 comments
Closed

net/http: TestServerKeepAlivesEnabled_h2 test flake #18083

bradfitz opened this issue Nov 28, 2016 · 6 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone
Go1.8

Comments

@bradfitz
Copy link
Contributor

linux-amd64-race at 789e14c1aa487f83d6e99f369b22c4fa60bf6f4c

https://storage.googleapis.com/go-build-log/789e14c1/linux-amd64-race_7fc53188.log

2016/11/28 20:31:42 http: TLS handshake error from 127.0.0.1:42614: read tcp 127.0.0.1:35582->127.0.0.1:42614: use of closed network connection
--- FAIL: TestServerKeepAlivesEnabled_h2 (0.09s)
	clientserver_test.go:50: Get https://127.0.0.1:34653: http2: server sent GOAWAY and closed the connection; LastStreamID=1, ErrCode=NO_ERROR, debug=""
FAIL
FAIL	net/http	4.922s
```

/cc @tombergan (if you're bored)
@bradfitz bradfitz added the Testing An issue that has been verified to require only test changes, not just a test failure. label Nov 28, 2016
@bradfitz bradfitz added this to the Go1.8Maybe milestone Nov 28, 2016
@bradfitz bradfitz self-assigned this Nov 28, 2016
@tombergan
Copy link
Contributor

Wild guess:

The server becomes "idle" before it sends the GOAWAY:
https://github.com/golang/net/blob/1c5acb2c2d1df0409de556978dd628d90aee5cb3/http2/server.go#L1275

The test sends the second request after the server has transitioned to "idle":

go/src/net/http/serve_test.go

Line 5030 in 409a667

if !waitCondition(2*time.Second, 10*time.Millisecond, srv.ExportAllConnsIdle) {

The test can make the second getURL call before receiving the GOAWAY. However, the h2 transport doesn't retry a request when the following code executes before GOAWAY is actually received:
https://github.com/golang/net/blob/1c5acb2c2d1df0409de556978dd628d90aee5cb3/http2/transport.go#L679

There is a race: if the client sends a new request on stream n+2, then shortly afterwards receives GOAWAY(lastStream=n), the client won't auto-retry that request on a new connection. Auto-retry happens only if RoundTrip gets to line 679 after the GOAWAY is received.

There is arguably a second bug, though this isn't the root cause of the test flake: the server transitions to idle at the line below even though there may still be response frames queued in the write scheduler. (Is it really correct to consider the server "idle" at this point?)
https://github.com/golang/net/blob/1c5acb2c2d1df0409de556978dd628d90aee5cb3/http2/server.go#L1275

Finally, I noticed a third bug: the following code should check curClientStreams+curPushedStreams==0 rather than curClientStreams==0:
https://github.com/golang/net/blob/1c5acb2c2d1df0409de556978dd628d90aee5cb3/http2/server.go#L756

@quentinmit quentinmit added the NeedsFix The path to resolution is known, but the work has not been done. label Nov 29, 2016
@tombergan tombergan mentioned this issue Nov 30, 2016
Closed
@bradfitz bradfitz mentioned this issue Dec 1, 2016
Closed
@bradfitz bradfitz modified the milestones: Go1.8, Go1.8Maybe Dec 1, 2016
@gopherbot
Copy link

CL https://golang.org/cl/33972 mentions this issue.

@gopherbot
Copy link

CL https://golang.org/cl/33971 mentions this issue.

@tombergan
Copy link
Contributor

There is arguably a second bug, though this isn't the root cause of the test flake: the server transitions to idle at the line below even though there may still be response frames queued in the write scheduler. (Is it really correct to consider the server "idle" at this point?)
https://github.com/golang/net/blob/1c5acb2c2d1df0409de556978dd628d90aee5cb3/http2/server.go#L1275

This is not a problem. At the end of sc.closeStream, the call to writeSched.CloseStream will discard any frames queued for that stream.

Finally, I noticed a third bug: the following code should check curClientStreams+curPushedStreams==0 rather than curClientStreams==0:
https://github.com/golang/net/blob/1c5acb2c2d1df0409de556978dd628d90aee5cb3/http2/server.go#L756

This is a bug. Sending a CL.

@gopherbot
Copy link

CL https://golang.org/cl/33974 mentions this issue.

gopherbot pushed a commit to golang/net that referenced this issue Dec 6, 2016
@tombergan @bradfitz
http2: fix minor stream accounting bug
0c96df3 
Update golang/go#18083

Change-Id: I2600f8a7a0d3a630003c010496a7fceca1b9f660
Reviewed-on: https://go-review.googlesource.com/33974
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
gopherbot pushed a commit to golang/net that referenced this issue Dec 6, 2016
@bradfitz
http2: make Transport retry on server's GOAWAY graceful shutdown
8dab929 
Debugged & wrote with Tom Bergan.

Updates golang/go#18083

Change-Id: I00a1cb748fe9c0f01c5bd4b8d1ac4438b56f1f8c
Reviewed-on: https://go-review.googlesource.com/33971
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
@gopherbot
Copy link

CL https://golang.org/cl/34011 mentions this issue.

@golang golang locked and limited conversation to collaborators Dec 6, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
None yet
Milestone
Go1.8
Development

No branches or pull requests
4 participants
@bradfitz @quentinmit @gopherbot @tombergan