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: TestTransportCloseResponseBody failing on Plan 9 #11476

Closed
0intro opened this issue Jun 29, 2015 · 4 comments
Closed

net/http: TestTransportCloseResponseBody failing on Plan 9 #11476

0intro opened this issue Jun 29, 2015 · 4 comments
Labels
FrozenDueToAge OS-Plan9
Milestone
Unplanned

Comments

@0intro
Copy link
Member

0intro commented Jun 29, 2015

In CL 11601, TestTransportCloseResponseBody is failing on Plan 9:

--- FAIL: TestTransportCloseResponseBody (0.10s)
    transport_test.go:1587: EOF
FAIL
FAIL    net/http    19.029s
2015/06/29 01:34:18 Failed: exit status: 'go 3306: 1'

See https://storage.googleapis.com/go-build-log/10feb7f2/plan9-386_6337f8ae.log.

It only fails when TestCancelRequestWithChannelBeforeDo and TestTransportCloseResponseBody are run consecutively, but not systematically.

Only TestCancelRequestWithChannelBeforeDo:

cpu% go test -v -run TestCancelRequestWithChannelBeforeDo
=== RUN   TestCancelRequestWithChannelBeforeDo
--- PASS: TestCancelRequestWithChannelBeforeDo (0.27s)
PASS
ok      net/http    0.334s

Only TestTransportCloseResponseBody:

cpu% go test -v -run TestTransportCloseResponseBody
=== RUN   TestTransportCloseResponseBody
--- PASS: TestTransportCloseResponseBody (0.34s)
PASS
ok      net/http    0.421s

TestCancelRequestWithChannelBeforeDo and TestTransportCloseResponseBody:

cpu% go test -v -run '(TestCancelRequestWithChannelBeforeDo|TestTransportCloseResponseBody)'
=== RUN   TestCancelRequestWithChannelBeforeDo
--- PASS: TestCancelRequestWithChannelBeforeDo (0.00s)
=== RUN   TestTransportCloseResponseBody
--- FAIL: TestTransportCloseResponseBody (0.12s)
    transport_test.go:1587: EOF
FAIL
exit status: 'http.test 124221: 1'
FAIL    net/http    0.197s

Here is the stack trace:

cpu% go test -v -run '(TestCancelRequestWithChannelBeforeDo|TestTransportCloseResponseBody)'
=== RUN   TestCancelRequestWithChannelBeforeDo
--- PASS: TestCancelRequestWithChannelBeforeDo (0.01s)
=== RUN   TestTransportCloseResponseBody
--- FAIL: TestTransportCloseResponseBody (0.13s)
panic:  [recovered]
    panic: 

goroutine 9 [running]:
testing.tRunner.func1(0x106e46c0)
    /usr/go/src/testing/testing.go:449 +0x130
net/http_test.TestTransportCloseResponseBody(0x106e46c0)
    /usr/go/src/net/http/transport_test.go:1587 +0x54a
testing.tRunner(0x106e46c0, 0x5430c0)
    /usr/go/src/testing/testing.go:455 +0x8e
created by testing.RunTests
    /usr/go/src/testing/testing.go:560 +0x6e8

goroutine 1 [chan receive]:
testing.RunTests(0x42edc4, 0x542700, 0xe5, 0xe5, 0x701)
    /usr/go/src/testing/testing.go:561 +0x71a
testing.(*M).Run(0x10709f5c, 0x14669c)
    /usr/go/src/testing/testing.go:493 +0x67
net/http_test.TestMain(0x10709f5c)
    /usr/go/src/net/http/main_test.go:19 +0x20
main.main()
    net/http/_test/_testmain.go:552 +0xff

goroutine 6 [runnable]:
syscall.Syscall(0x10679d00, 0x0, 0x0, 0x0, 0xffffffff, 0x0, 0x10676080, 0x22)
    /usr/go/src/syscall/asm_plan9_386.s:22 +0x5
syscall.open(0x10679ce0, 0x12, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/syscall/zsyscall_plan9_386.go:61 +0x81
syscall.Open(0x10679ce0, 0x12, 0x0, 0x12, 0x0, 0x0)
    /usr/go/src/syscall/syscall_plan9.go:321 +0x41
os.OpenFile(0x10679ce0, 0x12, 0x0, 0x0, 0x10680dd0, 0x0, 0x0)
    /usr/go/src/os/file_plan9.go:111 +0x35c
os.Open(0x10679ce0, 0x12, 0xb, 0x0, 0x0)
    /usr/go/src/os/file.go:246 +0x44
net.(*netFD).acceptPlan9(0x106a4ac0, 0x0, 0x0, 0x0)
    /usr/go/src/net/ipsock_plan9.go:222 +0x14c
net.(*TCPListener).AcceptTCP(0x106887e8, 0x106a72c0, 0x0, 0x0)
    /usr/go/src/net/tcpsock_plan9.go:144 +0x55
net.(*TCPListener).Accept(0x106887e8, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/net/tcpsock_plan9.go:157 +0x5d
net/http/httptest.(*historyListener).Accept(0x10679820, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/net/http/httptest/server.go:48 +0x52
net/http.(*Server).Serve(0x106a4b00, 0x307695f8, 0x10679820, 0x0, 0x0)
    /usr/go/src/net/http/server.go:1820 +0x97
created by net/http/httptest.(*Server).Start
    /usr/go/src/net/http/httptest/server.go:109 +0x2cc

goroutine 10 [syscall]:
syscall.Syscall(0x10679e40, 0x0, 0x0, 0x0, 0x0, 0x10664d00, 0x42f7c4, 0x10679da0)
    /usr/go/src/syscall/asm_plan9_386.s:22 +0x5
syscall.open(0x10679e00, 0x12, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/syscall/zsyscall_plan9_386.go:61 +0x81
syscall.Open(0x10679e00, 0x12, 0x0, 0x12, 0x0, 0x0)
    /usr/go/src/syscall/syscall_plan9.go:321 +0x41
os.OpenFile(0x10679e00, 0x12, 0x0, 0x0, 0x10683dd0, 0x0, 0x0)
    /usr/go/src/os/file_plan9.go:111 +0x35c
os.Open(0x10679e00, 0x12, 0xb, 0x0, 0x0)
    /usr/go/src/os/file.go:246 +0x44
net.(*netFD).acceptPlan9(0x106a4d00, 0x0, 0x0, 0x0)
    /usr/go/src/net/ipsock_plan9.go:222 +0x14c
net.(*TCPListener).AcceptTCP(0x10688860, 0x0, 0x0, 0x0)
    /usr/go/src/net/tcpsock_plan9.go:144 +0x55
net.(*TCPListener).Accept(0x10688860, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/net/tcpsock_plan9.go:157 +0x5d
net/http/httptest.(*historyListener).Accept(0x10679a00, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/net/http/httptest/server.go:48 +0x52
net/http.(*Server).Serve(0x106a4d40, 0x307695f8, 0x10679a00, 0x0, 0x0)
    /usr/go/src/net/http/server.go:1820 +0x97
created by net/http/httptest.(*Server).Start
    /usr/go/src/net/http/httptest/server.go:109 +0x2cc

goroutine 14 [syscall]:
syscall.Syscall6(0x7, 0x10730000, 0x1000, 0xffffffff, 0xffffffff, 0x0, 0x0, 0x19, 0x10731070, 0xf90, ...)
    /usr/go/src/syscall/asm_plan9_386.s:57 +0x5
syscall.Pread(0x7, 0x10730000, 0x1000, 0x1000, 0xffffffff, 0xffffffff, 0x1cee5b, 0x0, 0x0)
    /usr/go/src/syscall/zsyscall_plan9_386.go:228 +0x72
syscall.Read(0x7, 0x10730000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/go/src/syscall/syscall_plan9.go:123 +0x54
os.(*File).read(0x106888f0, 0x10730000, 0x1000, 0x1000, 0x46230, 0x0, 0x0)
    /usr/go/src/os/file_plan9.go:248 +0x49
os.(*File).Read(0x106888f0, 0x10730000, 0x1000, 0x1000, 0x1d, 0x0, 0x0)
    /usr/go/src/os/file.go:95 +0x6e
net.(*netFD).Read(0x106a5080, 0x10730000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/go/src/net/fd_plan9.go:134 +0xf6
net.(*conn).Read(0x10688900, 0x10730000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/go/src/net/net.go:124 +0x88
net/http.(*liveSwitchReader).Read(0x106e4804, 0x10730000, 0x1000, 0x1000, 0x1073005e, 0x0, 0x0)
    /usr/go/src/net/http/server.go:219 +0x83
io.(*LimitedReader).Read(0x106a72c0, 0x10730000, 0x1000, 0x1000, 0x30769818, 0x0, 0x0)
    /usr/go/src/io/io.go:427 +0xca
bufio.(*Reader).fill(0x106a84e0)
    /usr/go/src/bufio/bufio.go:97 +0x171
bufio.(*Reader).ReadSlice(0x106a84e0, 0x1065e80a, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/bufio/bufio.go:328 +0x1b3
bufio.(*Reader).ReadLine(0x106a84e0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/bufio/bufio.go:357 +0x4a
net/textproto.(*Reader).readLineSlice(0x10679d20, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/net/textproto/reader.go:55 +0x58
net/textproto.(*Reader).ReadLine(0x10679d20, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/net/textproto/reader.go:36 +0x38
net/http.ReadRequest(0x106a84e0, 0x106bb3b0, 0x0, 0x0)
    /usr/go/src/net/http/request.go:631 +0x99
net/http.(*conn).readRequest(0x106e47e0, 0x0, 0x0, 0x0)
    /usr/go/src/net/http/server.go:628 +0x367
net/http.(*conn).serve(0x106e47e0)
    /usr/go/src/net/http/server.go:1252 +0x7a8
created by net/http.(*Server).Serve
    /usr/go/src/net/http/server.go:1843 +0x342

goroutine 12 [syscall]:
syscall.Syscall6(0x5, 0x1072e000, 0x1000, 0xffffffff, 0xffffffff, 0x0, 0x0, 0x0, 0x1065c7eb, 0x0, ...)
    /usr/go/src/syscall/asm_plan9_386.s:57 +0x5
syscall.Pread(0x5, 0x1072e000, 0x1000, 0x1000, 0xffffffff, 0xffffffff, 0x1cee5b, 0x0, 0x0)
    /usr/go/src/syscall/zsyscall_plan9_386.go:228 +0x72
syscall.Read(0x5, 0x1072e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/go/src/syscall/syscall_plan9.go:123 +0x54
os.(*File).read(0x106888b8, 0x1072e000, 0x1000, 0x1000, 0x46230, 0x0, 0x0)
    /usr/go/src/os/file_plan9.go:248 +0x49
os.(*File).Read(0x106888b8, 0x1072e000, 0x1000, 0x1000, 0x2da300, 0x0, 0x0)
    /usr/go/src/os/file.go:95 +0x6e
net.(*netFD).Read(0x106a4fc0, 0x1072e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/go/src/net/fd_plan9.go:134 +0xf6
net.(*conn).Read(0x106888c8, 0x1072e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/go/src/net/net.go:124 +0x88
net/http.noteEOFReader.Read(0x30769680, 0x106888c8, 0x106e47ac, 0x1072e000, 0x1000, 0x1000, 0x2de180, 0x0, 0x0)
    /usr/go/src/net/http/transport.go:1352 +0x54
net/http.(*noteEOFReader).Read(0x106a71d0, 0x1072e000, 0x1000, 0x1000, 0x1, 0x0, 0x0)
    <autogenerated>:128 +0xad
bufio.(*Reader).fill(0x106a8480)
    /usr/go/src/bufio/bufio.go:97 +0x171
bufio.(*Reader).Peek(0x106a8480, 0x1, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/go/src/bufio/bufio.go:132 +0xac
net/http.(*persistConn).readLoop(0x106e4780)
    /usr/go/src/net/http/transport.go:883 +0xe2
created by net/http.(*Transport).dialConn
    /usr/go/src/net/http/transport.go:692 +0xa7c

goroutine 13 [runnable]:
net/http.(*persistConn).writeLoop(0x106e4780)
    /usr/go/src/net/http/transport.go:1009 +0x302
created by net/http.(*Transport).dialConn
    /usr/go/src/net/http/transport.go:693 +0xa9c
exit status: 'http.test 124488: 2'
FAIL    net/http    0.650s
@0intro 0intro mentioned this issue Jun 29, 2015
Closed
@jacobsa
Copy link
Contributor

jacobsa commented Jun 30, 2015

I've confirmed with printf debugging that this is due to the request from TestTransportCloseResponseBody being received by the handler set up in TestCancelRequestWithChannelBeforeDo. I haven't yet figured out why this happens, since it appears they should be on different ports.

@jacobsa
Copy link
Contributor

jacobsa commented Jun 30, 2015

Correction: httptest.NewServer binds to :0, so the port is irrelevant. But the handler from the first test still sees the request from the second, even though the second test issues the request only after httptest.Server.Close in the first test returns.

@jacobsa
Copy link
Contributor

jacobsa commented Jun 30, 2015

FYI, I worked around this in patch set 7 on the CL, so to reproduce you need to remove the plan9-specific sleep.

@0intro
Copy link
Member Author

0intro commented Jul 2, 2015

Thanks for your investigations. I'll try to figure out what's happening.

@ianlancetaylor ianlancetaylor added this to the Unplanned milestone Jul 11, 2015
@0intro 0intro self-assigned this Jul 30, 2015
@bradfitz bradfitz mentioned this issue Apr 27, 2016
Closed
@golang golang locked and limited conversation to collaborators Oct 18, 2017
@rsc rsc unassigned 0intro Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge OS-Plan9
Projects
None yet
Milestone
Unplanned
Development

No branches or pull requests
5 participants
@bradfitz @jacobsa @ianlancetaylor @0intro @gopherbot