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: TestMaxBytesHandler failures #57612

Open
gopherbot opened this issue Jan 4, 2023 · 6 comments
Open

net/http: TestMaxBytesHandler failures #57612

gopherbot opened this issue Jan 4, 2023 · 6 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@gopherbot
Copy link

gopherbot commented Jan 4, 2023 •
edited by bcmills 

#!watchflakes
post <- pkg == "net/http" && ((test == "TestMaxBytesHandler" && `expected echo`) || (log ~ `panic: test timed out` && log ~ `TestMaxBytesHandler \(\d+m\d+s\)`))

Issue created automatically to collect these failures.

Example (log):

2022/12/28 09:45:59 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000014098 127.0.0.1:50424 in state active
2022/12/28 09:45:59 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00054a030 127.0.0.1:50422 in state active
--- FAIL: TestMaxBytesHandler (3.42s)
    --- FAIL: TestMaxBytesHandler/max_size_100_request_size_1000000 (2.33s)
        serve_test.go:6703: unexpected connection error: Post "http://127.0.0.1:50578": readfrom tcp 127.0.0.1:50579->127.0.0.1:50578: write tcp 127.0.0.1:50579->127.0.0.1:50578: write: connection reset by peer
        serve_test.go:6726: expected echo of size 100; got 0

— watchflakes
@gopherbot gopherbot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 4, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestMaxBytesHandler"
2022-12-28 16:57 darwin-amd64-12_0 go@24963e5c net/http.TestMaxBytesHandler (log) 
2022/12/28 09:45:59 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc000014098 127.0.0.1:50424 in state active
2022/12/28 09:45:59 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *net.TCPConn 0xc00054a030 127.0.0.1:50422 in state active
--- FAIL: TestMaxBytesHandler (3.42s)
    --- FAIL: TestMaxBytesHandler/max_size_100_request_size_1000000 (2.33s)
        serve_test.go:6703: unexpected connection error: Post "http://127.0.0.1:50578": readfrom tcp 127.0.0.1:50579->127.0.0.1:50578: write tcp 127.0.0.1:50579->127.0.0.1:50578: write: connection reset by peer
        serve_test.go:6726: expected echo of size 100; got 0

— watchflakes

@bcmills
Copy link
Contributor

bcmills commented Jan 6, 2023

(CC @neild)

@bcmills bcmills added this to the Backlog milestone Jan 6, 2023
@gopherbot

This comment was marked as off-topic.

Sign in to view
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && ((test == "TestMaxBytesHandler" && `expected echo`) || (log ~ `panic: test timed out` && log ~ `TestMaxBytesHandler \(\d+m\d+s\)`))
2023-04-11 17:02 darwin-amd64-10_15 go@6e8eec73 net/http (log) 
panic: test timed out after 3m0s
running tests:
	TestMaxBytesHandler (2m59s)
	TestMaxBytesHandler/max_size_1000000_request_size_100 (2m57s)
	TestMaxBytesHandler/max_size_1000000_request_size_100/h1 (2m50s)
	TestMaxBytesHandler/max_size_1000000_request_size_1000 (2m57s)
	TestMaxBytesHandler/max_size_1000000_request_size_1000/h1 (2m50s)
	TestMaxBytesHandler/max_size_1000000_request_size_1000000 (2m57s)
	TestMaxBytesHandler/max_size_1000000_request_size_1000000/h2 (2m50s)

goroutine 21286 [running]:
panic({0x1428280?, 0xc0001c60a0?})
	/tmp/buildlet/go/src/runtime/panic.go:1016 +0x3ac fp=0xc00036ff10 sp=0xc00036fe60 pc=0x1034a8c
testing.(*M).startAlarm.func1()
	/tmp/buildlet/go/src/testing/testing.go:2260 +0x3b9 fp=0xc00036ffe0 sp=0xc00036ff10 pc=0x10f8339
runtime.goexit()
	/tmp/buildlet/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00036ffe8 sp=0xc00036ffe0 pc=0x1069da1
created by time.goFunc
	/tmp/buildlet/go/src/time/sleep.go:176 +0x2d

— watchflakes

@bcmills bcmills mentioned this issue Apr 12, 2023
Closed
@gopherbot
Copy link
Author

Change https://go.dev/cl/483895 mentions this issue: net/http: avoid leaking writer goroutines in tests

gopherbot pushed a commit that referenced this issue Apr 12, 2023
@gopherbot
net/http: avoid leaking writer goroutines in tests
d91d832 
In TestTransportPrefersResponseOverWriteError and TestMaxBytesHandler,
the server may respond to an incoming request without ever reading the
request body. The client's Do method will return as soon as the
server's response headers are read, but the Transport will remain
active until it notices that the server has closed the connection,
which may be arbitrarily later.

When the server has closed the connection, it will call the Close
method on the request body (if it has such a method). So we can use
that method to find out when the Transport is close enough to done for
the test to complete without interfering too much with other tests.

For #57612.
For #59526.

Change-Id: Iddc7a3b7b09429113ad76ccc1c090ebc9e1835a1
Reviewed-on: https://go-review.googlesource.com/c/go/+/483895
Run-TryBot: Bryan Mills <bcmills@google.com>
Commit-Queue: Bryan Mills <bcmills@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Michael Pratt <mpratt@google.com>
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && ((test == "TestMaxBytesHandler" && `expected echo`) || (log ~ `panic: test timed out` && log ~ `TestMaxBytesHandler \(\d+m\d+s\)`))
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