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

x/net/http2: flaky TestServer_Rejects_HeadersSelfDependence #18235

Closed
bradfitz opened this issue Dec 7, 2016 · 8 comments
Closed

x/net/http2: flaky TestServer_Rejects_HeadersSelfDependence #18235

bradfitz opened this issue Dec 7, 2016 · 8 comments
Assignees
Milestone

Comments

@bradfitz
Copy link
Contributor

@bradfitz bradfitz commented Dec 7, 2016

@tombergan, another test flake I just saw on OpenBSD during a trybot run:

openbsd-amd64-gce58 at d4177877c6d6e710d77dd8c94b91f8567f1aaa87 building net at 3e1ed1d52e454d78e90962ee54c440d41bc4d25d

--- FAIL: TestServer_Rejects_HeadersSelfDependence (2.04s)
	server_test.go:475: Error while expecting an RSTStream frame: timeout waiting for frame
FAIL
FAIL	golang.org/x/net/http2	43.217s

(from https://storage.googleapis.com/go-build-log/d4177877/openbsd-amd64-gce58_4c0035ad.log)

@bradfitz bradfitz added the Testing label Dec 7, 2016
@bradfitz bradfitz added this to the Go1.8Maybe milestone Dec 7, 2016
@tombergan

This comment has been minimized.

Copy link
Contributor

@tombergan tombergan commented Dec 7, 2016

It would be nice if we got full stack dumps on timeouts.

@bradfitz

This comment has been minimized.

Copy link
Contributor Author

@bradfitz bradfitz commented Dec 7, 2016

That's easy enough to add as a first step.

But often it's not enough, at least with the server half of things, if for example something isn't happening because the state machine isn't happy, as opposed to actually blocking on something like a channel or mutex. You often just see something blocked in the network waiting for something to arrive, but that's about it.

If it's not too noisy, though, it doesn't hurt to add.

@dsnet

This comment has been minimized.

Copy link
Member

@dsnet dsnet commented Dec 7, 2016

Related to #18111?

@tombergan

This comment has been minimized.

Copy link
Contributor

@tombergan tombergan commented Dec 7, 2016

I can't repro after 10s of 1000s of runs with various combinations of tsan and gomaxprocs. The ReadFrame timeout is 2s. Is it possible these machines are so busy that this test gets descheduled for 2s on rare occasions?

@bradfitz

This comment has been minimized.

Copy link
Contributor Author

@bradfitz bradfitz commented Dec 7, 2016

Our OpenBSD VMs have always been the slowest.

I need to update them anyway. Maybe new OpenBSD sucks less on GCE. (Or sucks less in general?)

@gopherbot

This comment has been minimized.

Copy link

@gopherbot gopherbot commented Dec 8, 2016

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

gopherbot pushed a commit to golang/net that referenced this issue Dec 8, 2016
To help debug rare nondeterministic server_test failures, log Framer
reads and writes. Sample output from an injected test failure:

$ go test golang.org/x/net/http2
--- FAIL: TestServer_Request_Reject_Pseudo_scheme_invalid (0.00s)
    server_test.go:998: server request made it to handler; should've been rejected
    server_test.go:514: got a *http2.HeadersFrame; want *RSTStreamFrame
    server_test.go:229: Framer read log:
        2016-12-07 17:06:11.907199013 Framer 0xc4212665b0: read SETTINGS len=18, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896
        2016-12-07 17:06:11.907523124 Framer 0xc4212665b0: read SETTINGS flags=ACK len=0
        2016-12-07 17:06:11.908090453 Framer 0xc4212665b0: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=48
    server_test.go:235: Framer write log:
        2016-12-07 17:06:11.907152927 Framer 0xc4212665b0: wrote SETTINGS len=0
        2016-12-07 17:06:11.907207016 Framer 0xc4212665b0: wrote SETTINGS flags=ACK len=0
        2016-12-07 17:06:11.907550525 Framer 0xc4212665b0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=16

Framer logs are written at the end of a test only if the test failed
and only if http2debug!=2. (If http2debug=2, then Framer logs are already
written to stdout.)

Hopefully this will help debug flaky tests. Or it might not.
The code is kind of ugly.

Updates golang/go#18235

Change-Id: I74c8ef82521d81f123663c98c883c71d9843964f
Reviewed-on: https://go-review.googlesource.com/34130
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@bradfitz

This comment has been minimized.

Copy link
Contributor Author

@bradfitz bradfitz commented Dec 8, 2016

Closing in favor of earlier dup #18111.

@gopherbot

This comment has been minimized.

Copy link

@gopherbot gopherbot commented Dec 15, 2016

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

gopherbot pushed a commit that referenced this issue Dec 15, 2016
Updates bundled x/net/http2 to git rev 1195a05d for:

    http2: fix incorrect panic
    https://golang.org/cl/34498

    http2: fix race in writePushPromise
    https://golang.org/cl/34493

    http2: speed up TestTransportFlowControl in short mode
    https://golang.org/cl/33241

    http2: don't flush a stream's write queue in sc.resetStream
    https://golang.org/cl/34238

    http2: allow Transport to connect to https://[v6literal]/ without port
    https://golang.org/cl/34143

    http2: log Framer reads and writes when a server test fails
    https://golang.org/cl/34130

Updates #18326
Updates #18273
Updates #18111
Updates #18248
Updates #18235

Change-Id: I18c7a297fc94d6a843284efcfc43e0fdab9b5f41
Reviewed-on: https://go-review.googlesource.com/34495
Run-TryBot: Chris Broadfoot <cbro@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@golang golang locked and limited conversation to collaborators Dec 15, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
4 participants
You can’t perform that action at this time.