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: apparent deadlock in TestRequestWriteTransport via dumpRequestOut #44088

Open
bcmills opened this issue Feb 3, 2021 · 1 comment
Open

net/http: apparent deadlock in TestRequestWriteTransport via dumpRequestOut #44088

bcmills opened this issue Feb 3, 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 Feb 3, 2021

2021-02-01T15:52:59-26e29aa/solaris-amd64-oraclerel
2019-10-15T20:29:56-831e3cf/solaris-amd64-oraclerel

goroutine 70 [select, 2 minutes]:
net/http.(*persistConn).roundTrip(0xc000376d80, 0xc0007043c0, 0x0, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:2610 +0x765
net/http.(*Transport).roundTrip(0xc000386a00, 0xc0007e2b00, 0xc000254070, 0x0, 0xc0005d0288)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:592 +0xacb
net/http.(*Transport).RoundTrip(...)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/roundtrip.go:17
net/http.dumpRequestOut(0xc0007e2b00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:945 +0x305
net/http.TestRequestWriteTransport(0xc00024c300)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:788 +0x990
testing.tRunner(0xc00024c300, 0x948fd0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:1239 +0x2b3

…

goroutine 6197 [chan receive, 2 minutes]:
net/http.(*delegateReader).Read(0xc0005d0288, 0xc001273000, 0x1000, 0x1000, 0x8bfd00, 0x0, 0xc0003fd4d0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:961 +0xa9
net/http.(*persistConn).Read(0xc000376d80, 0xc001273000, 0x1000, 0x1000, 0x406cfd, 0x60, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:1922 +0x77
bufio.(*Reader).fill(0xc000498420)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/bufio/bufio.go:101 +0x108
bufio.(*Reader).Peek(0xc000498420, 0x1, 0xc0006f9b00, 0xc0003fd590, 0x44cfcc, 0xc000319078, 0x18)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/bufio/bufio.go:139 +0x4f
net/http.(*persistConn).readLoop(0xc000376d80)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:2083 +0x1a8
created by net/http.(*Transport).dialConn
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:1743 +0xc77

…

goroutine 6195 [select, 2 minutes]:
io.(*pipe).Read(0xc000498060, 0xc001279000, 0x1000, 0x1000, 0x6, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/pipe.go:57 +0xcb
io.(*PipeReader).Read(0xc000254070, 0xc001279000, 0x1000, 0x1000, 0x6, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/pipe.go:134 +0x4c
bufio.(*Reader).fill(0xc0004984e0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/bufio/bufio.go:101 +0x108
bufio.(*Reader).ReadSlice(0xc0004984e0, 0xc0002bc00a, 0xc001279004, 0x2, 0x1, 0x1000, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/bufio/bufio.go:360 +0x3d
net/http/internal.readChunkLine(0xc0004984e0, 0x2, 0x0, 0x0, 0x0, 0x2)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/internal/chunked.go:122 +0x34
net/http/internal.(*chunkedReader).beginChunk(0xc0002bc060)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/internal/chunked.go:48 +0x32
net/http/internal.(*chunkedReader).Read(0xc0002bc060, 0xc0011a8000, 0x2000, 0x2000, 0x1, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/internal/chunked.go:93 +0x134
net/http.(*body).readLocked(0xc0002d0100, 0xc0011a8000, 0x2000, 0x2000, 0x1, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transfer.go:842 +0x5f
net/http.(*body).Read(0xc0002d0100, 0xc0011a8000, 0x2000, 0x2000, 0x0, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transfer.go:834 +0xf9
io.discard.ReadFrom(0x7fffbf5a88d8, 0xc0002d0100, 0x8bf760, 0x1, 0x7fffbf5bd818)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/io.go:598 +0x95
io.copyBuffer(0x9c1a00, 0xc67440, 0x7fffbf5a88d8, 0xc0002d0100, 0x0, 0x0, 0x0, 0xc000806ec0, 0xc0007bc760, 0x100000001)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/io.go:409 +0x357
io.Copy(...)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/io.go:382
net/http.dumpRequestOut.func2(0xc000254070, 0x0, 0xc0005d0288)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:939 +0x24c
created by net/http.dumpRequestOut
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:931 +0x2e5

…

goroutine 6198 [chan receive, 2 minutes]:
net/http.finishAsyncByteRead.Read(0xc0002303c0, 0xc00088a000, 0x8000, 0x8000, 0x0, 0x0, 0x3)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transfer.go:1069 +0x65
io.(*multiReader).Read(0xc0001240d8, 0xc00088a000, 0x8000, 0x8000, 0x1, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/multi.go:26 +0xb2
io.copyBuffer(0x7fffbf5b2bf8, 0xc000b3a030, 0x9c0e00, 0xc0001240d8, 0xc00088a000, 0x8000, 0x8000, 0xc000c28c38, 0x40cee5, 0x8a5420)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/io.go:423 +0x12c
io.Copy(...)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/io/io.go:382
net/http.(*transferWriter).doBodyCopy(0xc0002303c0, 0x7fffbf5b2bf8, 0xc000b3a030, 0x9c0e00, 0xc0001240d8, 0x70b4b2, 0xc00079c3c0, 0xc001278000)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transfer.go:409 +0x6a
net/http.(*transferWriter).writeBody(0xc0002303c0, 0x9c1320, 0xc000010008, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transfer.go:356 +0x531
net/http.(*Request).write(0xc0007e2c00, 0x9c0a20, 0xc000704400, 0x0, 0xc0000b6d20, 0x0, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/request.go:697 +0x7c6
net/http.(*persistConn).writeLoop(0xc000376d80)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:2385 +0x1a7
created by net/http.(*Transport).dialConn
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport.go:1744 +0xc9c

Note that:

go/src/net/http/requestwrite_test.go

Line 906 in 1b09d43

// dumpRequestOut is a modified copy of net/http/httputil.DumpRequestOut.

I wonder if the deadlock fixed httputil.DumpRequestOut fixed in CL 232798 (#38352) needs to be backported to the copy in the net/http/requestwrite_test.go, or if this is an unrelated bug.

CC @stevenh @neild @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 Feb 3, 2021
@bcmills bcmills added this to the Backlog milestone Feb 3, 2021
@stevenh
Copy link
Contributor

stevenh commented Feb 4, 2021 •
edited

Without the quitReadCh and the fix from #38352 you can definitely trigger a deadlock in the delegate reader for which the following would be a sign:

goroutine 6197 [chan receive, 2 minutes]:
net/http.(*delegateReader).Read(0xc0005d0288, 0xc001273000, 0x1000, 0x1000, 0x8bfd00, 0x0, 0xc0003fd4d0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:961 +0xa9

However the main goroutine hasn't returned yet, which was the trigger for that deadlock.

net/http.dumpRequestOut(0xc0007e2b00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/requestwrite_test.go:945 +0x305

So while I think it's a good idea to replicate the require changes to dumpRequestOut it looks like this is something else.

@bcmills bcmills mentioned this issue Apr 26, 2022
Open
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
2 participants
@stevenh @bcmills