x/net/http2: flaky TestServer_Rejects_HeadersSelfDependence #18235
Comments
bradfitz
added
the
Testing
|
It would be nice if we got full stack dumps on timeouts. |
|
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. |
|
Related to #18111? |
|
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? |
|
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?) |
|
CL https://golang.org/cl/34130 mentions this issue. |
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>
|
Closing in favor of earlier dup #18111. |
|
CL https://golang.org/cl/34495 mentions this issue. |
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>
@tombergan, another test flake I just saw on OpenBSD during a trybot run:
(from https://storage.googleapis.com/go-build-log/d4177877/openbsd-amd64-gce58_4c0035ad.log)
The text was updated successfully, but these errors were encountered: