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

net/http: timeouts in TestResponseControllerSetPastReadDeadline #59447

Open
bcmills opened this issue Apr 5, 2023 · 7 comments
Open

net/http: timeouts in TestResponseControllerSetPastReadDeadline #59447

bcmills opened this issue Apr 5, 2023 · 7 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@bcmills
Copy link
Contributor

bcmills commented Apr 5, 2023 •
edited
Loading 

#!watchflakes
post <- (log ~ `panic: test timed out` && log ~ `TestResponseControllerSetPastReadDeadline \(\d+m\d+s\)`) || (pkg == "net/http" && test == "TestResponseControllerSetPastReadDeadline" && `server handler unexpectedly exited without closing readc`)
@bcmills bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 5, 2023
@bcmills bcmills added this to the Backlog milestone Apr 5, 2023
@bcmills bcmills mentioned this issue Apr 5, 2023
Closed
@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- log ~ `panic: test timed out` && log ~ `TestResponseControllerSetPastReadDeadline \(\d+m\d+s\)`
2023-04-04 03:37 darwin-amd64-11_0 go@ad87a124 net/http (log) 
2023/04/03 23:59:15 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc0001a1a50 127.0.0.1:50637 in state active
panic: test timed out after 3m0s
running tests:
	TestResponseControllerSetPastReadDeadline (2m59s)
	TestResponseControllerSetPastReadDeadline/h2 (2m50s)

goroutine 21387 [running]:
panic({0x1422c80?, 0xc00015f010?})
	/tmp/buildlet/go/src/runtime/panic.go:1016 +0x3ac fp=0xc000ca3f10 sp=0xc000ca3e60 pc=0x10345ac
testing.(*M).startAlarm.func1()
	/tmp/buildlet/go/src/testing/testing.go:2260 +0x3b9 fp=0xc000ca3fe0 sp=0xc000ca3f10 pc=0x10f7a39
runtime.goexit()
	/tmp/buildlet/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000ca3fe8 sp=0xc000ca3fe0 pc=0x1069701
created by time.goFunc
	/tmp/buildlet/go/src/time/sleep.go:176 +0x2d

— watchflakes

@bcmills
Copy link
Contributor Author

bcmills commented Apr 5, 2023

(CC @neild)

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/482935 mentions this issue: net/http: improve failure mode for TestResponseControllerSetPastReadDeadline

gopherbot pushed a commit that referenced this issue Apr 6, 2023
@neild @gopherbot
net/http: improve failure mode for TestResponseControllerSetPastReadD…
ef4b2fd 
…eadline

A test flake in #59447 seems to indicate that this test got stuck
waiting for the test handler to close the readc channel.
If the handler returns early due to an unexpected error, it might
fail to close this channel. Add a second channel to act as a
signal that the handler has given up and the test should stop.
This won't fix whatever happened in the flake, but might help
us debug it if it happens again.

For #59447

Change-Id: I05d84c6176aa938887d93126a6f3bb4dc941c90d
Reviewed-on: https://go-review.googlesource.com/c/go/+/482935
Reviewed-by: Bryan Mills <[email protected]>
TryBot-Result: Gopher Robot <[email protected]>
Auto-Submit: Damien Neil <[email protected]>
Run-TryBot: Damien Neil <[email protected]>
@gopherbot
Copy link
Contributor

Change https://go.dev/cl/483036 mentions this issue: net/http: fix a race in TestResponseControllerSetPastReadDeadline

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- (log ~ `panic: test timed out` && log ~ `TestResponseControllerSetPastReadDeadline \(\d+m\d+s\)`) || (pkg == "net/http" && test == "TestResponseControllerSetPastReadDeadline" && `server handler unexpectedly exited without closing readc`)
2023-04-07 11:34 linux-mips64-rtrk go@949fdd9f net/http.TestResponseControllerSetPastReadDeadline (log) 
--- FAIL: TestResponseControllerSetPastReadDeadline (0.00s)
    --- FAIL: TestResponseControllerSetPastReadDeadline/h2 (0.12s)
        responsecontroller_test.go:202: server handler unexpectedly exited without closing readc

— watchflakes

gopherbot pushed a commit that referenced this issue Apr 7, 2023
@gopherbot
net/http: fix a race in TestResponseControllerSetPastReadDeadline
38dadcc 
If the Write goroutine is delayed for long enough after its first
Write, the handler may have closed both the readc and donec channels
by the time it selects over them, and the donec case may be randomly
chosen. Handle that case by explicitly checking readc as well.

This fixes a race accidentally introduced in CL 482935 and observed in
https://build.golang.org/log/fa684750994d1fda409722f144b90c65b4c52cf9.

For #59447.

Change-Id: I5c87a599910cf8c1d037e5bbce68bf35afd55d61
Reviewed-on: https://go-review.googlesource.com/c/go/+/483036
TryBot-Result: Gopher Robot <[email protected]>
Auto-Submit: Bryan Mills <[email protected]>
Reviewed-by: Damien Neil <[email protected]>
Run-TryBot: Bryan Mills <[email protected]>
@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- (log ~ `panic: test timed out` && log ~ `TestResponseControllerSetPastReadDeadline \(\d+m\d+s\)`) || (pkg == "net/http" && test == "TestResponseControllerSetPastReadDeadline" && `server handler unexpectedly exited without closing readc`)
2023-09-12 17:45 plan9-arm go@36024659 net/http (log) 
http.test 35727: warning: process exceeds 100 file descriptors
panic: test timed out after 9m0s
running tests:
	TestResponseControllerSetPastReadDeadline (8m56s)
	TestResponseControllerSetPastReadDeadline/h2 (8m39s)

goroutine 56641 [running]:
panic({0x47b238, 0xad18060})
	/boot/workdir/go/src/runtime/panic.go:774 +0x12c fp=0x96b8f80 sp=0x96b8f2c pc=0x3f860
testing.(*M).startAlarm.func1()
	/boot/workdir/go/src/testing/testing.go:2259 +0x3ac fp=0x96b8fec sp=0x96b8f80 pc=0x10fa20
runtime.goexit({})
	/boot/workdir/go/src/runtime/asm_arm.s:859 +0x4 fp=0x96b8fec sp=0x96b8fec pc=0x77168
created by time.goFunc
	/boot/workdir/go/src/time/sleep.go:177 +0x2c

— watchflakes

@gopherbot
Copy link
Contributor

Found new dashboard test flakes for:

#!watchflakes
post <- (log ~ `panic: test timed out` && log ~ `TestResponseControllerSetPastReadDeadline \(\d+m\d+s\)`) || (pkg == "net/http" && test == "TestResponseControllerSetPastReadDeadline" && `server handler unexpectedly exited without closing readc`)
2024-04-03 15:35 android-386-emu go@d8392e69 net/http (log) 
panic: test timed out after 3m0s
running tests:
	Test304Responses (2m58s)
	TestBadResponseAfterReadingBody (2m58s)
	TestBidiStreamReverseProxy (2m58s)
	TestCancelRequestMidBody (2m58s)
	TestCancelRequestWhenSharingConnection (2m59s)
	TestCancelRequestWithChannel (2m59s)
	TestCancelRequestWithChannelBeforeDo_Cancel (2m59s)
	TestCancelRequestWithChannelBeforeDo_Context (2m59s)
...
	TestWriteHeader0 (2m58s)
	TestWriteHeaderNoCodeCheck (2m58s)
	TestWriteHeaderSwitchingProtocols (2m59s)
	TestZeroLengthPostAndResponse (2m59s)

goroutine 24228 [running]:
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2259 +0x3e1
created by time.goFunc
	/workdir/go/src/time/sleep.go:176 +0x35
2024-04-03 18:01 android-386-emu go@74501172 net/http (log) 
panic: test timed out after 3m0s
running tests:
	Test304Responses (2m58s)
	TestBadResponseAfterReadingBody (2m58s)
	TestBidiStreamReverseProxy (2m58s)
	TestCancelRequestMidBody (2m58s)
	TestChunkedResponseHeaders (2m58s)
	TestClient (2m58s)
	TestClientAltersCookiesOnRedirect (2m58s)
	TestClientCallsCloseOnlyOnce (2m58s)
...
	TestWriteDeadlineExtendedOnNewRequest (2m58s)
	TestWriteHeader0 (2m58s)
	TestWriteHeaderNoCodeCheck (2m58s)
	TestZeroLengthPostAndResponse (2m58s)

goroutine 31241 [running]:
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2259 +0x3e1
created by time.goFunc
	/workdir/go/src/time/sleep.go:176 +0x35

— watchflakes

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Test Flakes
Status: No status
Milestone
Backlog
Development

No branches or pull requests
2 participants
@bcmills @gopherbot