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/httputil: apparent deadlock in TestReverseProxy_PanicBodyError #44783

Open
bcmills opened this issue Mar 4, 2021 · 1 comment
Open

net/http/httputil: apparent deadlock in TestReverseProxy_PanicBodyError #44783

bcmills opened this issue Mar 4, 2021 · 1 comment
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 Mar 4, 2021 

panic: test timed out after 3m0s

goroutine 425 [running]:
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:1701 +0xc8
created by time.goFunc
	/workdir/go/src/time/sleep.go:180 +0x40

goroutine 1 [chan receive, 2 minutes]:
testing.(*T).Run(0x400037f080, 0x32fafb, 0x1f, 0x341ec8, 0x60408201)
	/workdir/go/src/testing/testing.go:1240 +0x260
testing.runTests.func1(0x4000001980)
	/workdir/go/src/testing/testing.go:1512 +0x74
testing.tRunner(0x4000001980, 0x400008fdc8)
	/workdir/go/src/testing/testing.go:1194 +0xdc
testing.runTests(0x400000e0c0, 0x53c7e0, 0x1e, 0x1e, 0xc0083eb293ddaad1, 0x29e8f7ba7b, 0x542740, 0xffff876ca130)
	/workdir/go/src/testing/testing.go:1510 +0x29c
testing.(*M).Run(0x40000e4000, 0x0)
	/workdir/go/src/testing/testing.go:1418 +0x1b4
main.main()
	_testmain.go:113 +0x15c

goroutine 441 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0xffff6023cc90, 0x72, 0xffffffffffffffff)
	/workdir/go/src/runtime/netpoll.go:226 +0x44
internal/poll.(*pollDesc).wait(0x400013aa18, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:84 +0x38
internal/poll.(*pollDesc).waitRead(...)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0x400013aa00, 0x400013e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/workdir/go/src/internal/poll/fd_unix.go:167 +0x180
net.(*netFD).Read(0x400013aa00, 0x400013e000, 0x1000, 0x1000, 0x40004a4888, 0x287d8, 0xffff60bcac00)
	/workdir/go/src/net/fd_posix.go:56 +0x44
net.(*conn).Read(0x400032c0b0, 0x400013e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/workdir/go/src/net/net.go:183 +0x74
net/http.(*persistConn).Read(0x400022e900, 0x400013e000, 0x1000, 0x1000, 0xffff60242e70, 0x0, 0x0)
	/workdir/go/src/net/http/transport.go:1922 +0x60
bufio.(*Reader).Read(0x40003eae40, 0x4000638000, 0x29, 0x8000, 0x2b, 0x0, 0x0)
	/workdir/go/src/bufio/bufio.go:227 +0x214
io.(*LimitedReader).Read(0x40002a62d0, 0x4000638000, 0x8000, 0x8000, 0x2b, 0x4000280c00, 0x0)
	/workdir/go/src/io/io.go:473 +0x60
net/http.(*body).readLocked(0x400021c8c0, 0x4000638000, 0x8000, 0x8000, 0x2b8880, 0x2b, 0x40)
	/workdir/go/src/net/http/transfer.go:842 +0x54
net/http.(*body).Read(0x400021c8c0, 0x4000638000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/workdir/go/src/net/http/transfer.go:834 +0xec
net/http.(*bodyEOFSignal).Read(0x400021c900, 0x4000638000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/workdir/go/src/net/http/transport.go:2764 +0xd8
net/http/httputil.(*ReverseProxy).copyBuffer(0x4000343090, 0xffff586c8458, 0x400021c7c0, 0x390ee8, 0x400021c900, 0x4000638000, 0x8000, 0x8000, 0x40004a4bd8, 0x1bc70, ...)
	/workdir/go/src/net/http/httputil/reverseproxy.go:451 +0x74
net/http/httputil.(*ReverseProxy).copyResponse(0x4000343090, 0xffff586c8458, 0x400021c7c0, 0x390ee8, 0x400021c900, 0x0, 0x0, 0x0)
	/workdir/go/src/net/http/httputil/reverseproxy.go:439 +0xa4
net/http/httputil.(*ReverseProxy).ServeHTTP(0x4000343090, 0x396300, 0x400021c7c0, 0x400060eb00)
	/workdir/go/src/net/http/httputil/reverseproxy.go:328 +0x630
net/http/httputil.TestReverseProxy_PanicBodyError(0x400037f080)
	/workdir/go/src/net/http/httputil/reverseproxy_test.go:1062 +0x23c
testing.tRunner(0x400037f080, 0x341ec8)
	/workdir/go/src/testing/testing.go:1194 +0xdc
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:1239 +0x244

goroutine 423 [select, 2 minutes]:
net/http.(*persistConn).readLoop(0x400022e900)
	/workdir/go/src/net/http/transport.go:2203 +0x764
created by net/http.(*Transport).dialConn
	/workdir/go/src/net/http/transport.go:1743 +0x9a0

goroutine 406 [sync.Cond.Wait, 2 minutes]:
sync.runtime_notifyListWait(0x400021c890, 0x0)
	/workdir/go/src/runtime/sema.go:513 +0xf8
sync.(*Cond).Wait(0x400021c880)
	/workdir/go/src/sync/cond.go:56 +0xb8
net/http.(*connReader).abortPendingRead(0x40001a79b0)
	/workdir/go/src/net/http/server.go:740 +0xb8
net/http.(*response).finishRequest(0x400015e1c0)
	/workdir/go/src/net/http/server.go:1633 +0x8c
net/http.(*conn).serve(0x40001485a0, 0x3968e0, 0x400021c840)
	/workdir/go/src/net/http/server.go:1957 +0x74c
created by net/http.(*Server).Serve
	/workdir/go/src/net/http/server.go:3013 +0x310

goroutine 424 [select, 2 minutes]:
net/http.(*persistConn).writeLoop(0x400022e900)
	/workdir/go/src/net/http/transport.go:2382 +0xa8
created by net/http.(*Transport).dialConn
	/workdir/go/src/net/http/transport.go:1744 +0x9c0

goroutine 442 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0xffff6023cba8, 0x72, 0x0)
	/workdir/go/src/runtime/netpoll.go:226 +0x44
internal/poll.(*pollDesc).wait(0x400013a918, 0x72, 0x0, 0x0, 0x326215)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:84 +0x38
internal/poll.(*pollDesc).waitRead(...)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0x400013a900, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/workdir/go/src/internal/poll/fd_unix.go:402 +0x1b0
net.(*netFD).accept(0x400013a900, 0x245aac, 0x40003b235c, 0x400048f6b0)
	/workdir/go/src/net/fd_unix.go:173 +0x2c
net.(*TCPListener).accept(0x40002a6270, 0x40003b2310, 0x4000055e08, 0x53994)
	/workdir/go/src/net/tcpsock_posix.go:140 +0x2c
net.(*TCPListener).Accept(0x40002a6270, 0x4000055e70, 0x4000055e78, 0x18, 0x4000103c80)
	/workdir/go/src/net/tcpsock.go:261 +0x5c
net/http.(*Server).Serve(0x40003b4460, 0x3960f0, 0x40002a6270, 0x0, 0x0)
	/workdir/go/src/net/http/server.go:2981 +0x22c
net/http/httptest.(*Server).goServe.func1(0x40003b2310)
	/workdir/go/src/net/http/httptest/server.go:308 +0x68
created by net/http/httptest.(*Server).goServe
	/workdir/go/src/net/http/httptest/server.go:306 +0x58

goroutine 450 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0xffff6023cf48, 0x72, 0xffffffffffffffff)
	/workdir/go/src/runtime/netpoll.go:226 +0x44
internal/poll.(*pollDesc).wait(0x40002aca18, 0x72, 0x0, 0x1, 0xffffffffffffffff)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:84 +0x38
internal/poll.(*pollDesc).waitRead(...)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0x40002aca00, 0x40001a79c1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/workdir/go/src/internal/poll/fd_unix.go:167 +0x180
net.(*netFD).Read(0x40002aca00, 0x40001a79c1, 0x1, 0x1, 0x0, 0x7c084, 0x400011b860)
	/workdir/go/src/net/fd_posix.go:56 +0x44
net.(*conn).Read(0x400020a0b0, 0x40001a79c1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/workdir/go/src/net/net.go:183 +0x74
net/http.(*connReader).backgroundRead(0x40001a79b0)
	/workdir/go/src/net/http/server.go:692 +0x50
created by net/http.(*connReader).startBackgroundRead
	/workdir/go/src/net/http/server.go:688 +0xc4
FAIL	net/http/httputil	180.022s

2021-03-04T06:36:17-4b8b2c5/linux-arm64-packet
2020-04-29T22:40:20-a7e5396/plan9-arm
2020-04-13T20:38:15-300ed43/plan9-arm
2019-06-06T19:44:12-f5e5bc1/plan9-arm

Note that all of the goroutine are blocked in either IO wait or some kind of synchronization.

CC @bradfitz @empijei
@bcmills bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Mar 4, 2021
@bcmills bcmills added this to the Backlog milestone Mar 4, 2021
@bcmills
Copy link
Contributor Author

bcmills commented Dec 6, 2021

greplogs --dashboard -md -l -e 'goroutine \d+ \[IO wait, \d+ minutes\]:\n(?:.+\n\t.+\n)*net/http/httputil\.TestReverseProxy_PanicBodyError' --since=2021-03-05

2021-12-02T22:05:01-f9b2733/windows-arm64-10

@bcmills bcmills mentioned this issue Dec 6, 2021
Closed
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
None yet
Milestone
Backlog
Development

No branches or pull requests
1 participant
@bcmills