net/http: test failures on linux/386

[alberts]

What steps will reproduce the problem?

go test -v -cpu 1,2,4 -timeout=30m std

What do you see instead?

--- FAIL: TestStressSurpriseServerCloses-4 (38.60 seconds)
transport_test.go:447: presumed deadlock; no HTTP client activity seen in awhile

--- FAIL: TestGoroutinesRunning-4 (0.00 seconds)
    z_last_test.go:19: num goroutines = 40
    z_last_test.go:26: Too many goroutines:
        goroutine 132795 [running]:
        net/http_test.TestGoroutinesRunning(0x197f9180)
            /build/go.386/go/src/pkg/net/http/z_last_test.go:25 +0xed
        testing.tRunner(0x197f9180, 0x8435c10)
            /build/go.386/go/src/pkg/testing/testing.go:346 +0x87
        created by testing.RunTests
            /build/go.386/go/src/pkg/testing/testing.go:426 +0x684
        
        goroutine 1 [chan receive]:
        testing.RunTests(0x82ec398, 0x8435520, 0x95, 0x95, 0x185b3700, ...)
            /build/go.386/go/src/pkg/testing/testing.go:427 +0x69f
        testing.Main(0x82ec398, 0x8435520, 0x95, 0x95, 0x84309a0, ...)
            /build/go.386/go/src/pkg/testing/testing.go:358 +0x69
        main.main()
            net/http/_test/_testmain.go:361 +0x81
        
        goroutine 2 [syscall]:
        
        goroutine 37 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0x7, 0x185a20a8, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x185a20a0, 0x18626040, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x18626040)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 255 [finalizer wait]:
        
        goroutine 105289 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 51089 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0xf, 0x18ee1788, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x18ee1780, 0x19dcd0a0, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19dcd0a0)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 105267 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105233 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 51099 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0x18, 0x197a20a8, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x197a20a0, 0x19dcdf80, 0x0, 0x0, 0xffffffff, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19dcdf80)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 105238 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 51097 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0x17, 0x19d52008, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x19d52000, 0x19d72840, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19d72840)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 105236 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105263 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105243 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 51106 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0x20, 0x197a21e8, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x197a21e0, 0x19d72b40, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19d72b40)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 105285 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105281 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105247 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 51043 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0xa, 0x18ee1648, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x18ee1640, 0x19e1ede0, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19e1ede0)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 105252 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105260 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105234 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 51116 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0x29, 0x18ee1828, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x18ee1820, 0x19d105c0, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19d105c0)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 51123 [syscall]:
        syscall.Syscall6()
            /build/go.386/go/src/pkg/syscall/asm_linux_386.s:39 +0x5
        syscall.EpollWait(0x33, 0x18fa5008, 0xa, 0xa, 0xffffffff, ...)
            /build/go.386/go/src/pkg/syscall/zerrors_linux_386.go:1871 +0x7b
        net.(*pollster).WaitFD(0x18fa5000, 0x19c9e0e0, 0x0, 0x0, 0x0, ...)
            /build/go.386/go/src/pkg/net/fd_linux.go:151 +0x118
        net.(*pollServer).Run(0x19c9e0e0)
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:206 +0x138
        created by net.newPollServer
            /build/go.386/go/src/pkg/net/fd_poll_unix.go:55 +0x269
        
        goroutine 105241 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105240 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105258 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105266 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105269 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105288 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105237 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105268 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105261 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105286 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105283 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105271 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
        
        goroutine 105257 [chan send]:
        net/http_test.func·097()
            /build/go.386/go/src/pkg/net/http/transport_test.go:437 +0x93
        created by net/http_test.TestStressSurpriseServerCloses
            /build/go.386/go/src/pkg/net/http/transport_test.go:439 +0x209
FAIL
FAIL    net/http    109.792s

Which compiler are you using (5g, 6g, 8g, gccgo)?

8g

Which operating system are you using?

linux

Which version are you using?  (run 'go version')

go version devel +ed48ace1855b Thu Mar 07 20:11:37 2013 -0800 linux/386

Please provide any additional information below.

Haven't seen these on linux/amd64 before.

[alberts]

Comment 1:

see also issue #5007

[ianlancetaylor]

Comment 2:

Labels changed: added priority-soon, go1.1, removed priority-triage.

[alberts]

Comment 3:

it looks better after the 64-bit atomic fix, but there are still issues.
go version devel +6415ff684316 Sun Mar 10 19:07:16 2013 -0700 linux/386
a lot of this:
--- FAIL: TestTransportSocketLateBinding-2 (1.20 seconds)
    z_last_test.go:59: Test appears to have leaked a Transport:
        goroutine 104874 [running]:
        net/http_test.checkLeakedTransports(0x1916c4e0)
            /build/go.386/go/src/pkg/net/http/z_last_test.go:46 +0x196
        net/http_test.TestTransportSocketLateBinding(0x1916c4e0)
            /build/go.386/go/src/pkg/net/http/transport_test.go:1382 +0x597
        testing.tRunner(0x1916c4e0, 0x8434c78)
            /build/go.386/go/src/pkg/testing/testing.go:346 +0x87
        created by testing.RunTests
            /build/go.386/go/src/pkg/testing/testing.go:426 +0x684
        
        goroutine 1 [chan receive]:
        testing.RunTests(0x82f5538, 0x84345a0, 0x95, 0x95, 0x185b7701, ...)
            /build/go.386/go/src/pkg/testing/testing.go:427 +0x69f
        testing.Main(0x82f5538, 0x84345a0, 0x95, 0x95, 0x842f920, ...)
            /build/go.386/go/src/pkg/testing/testing.go:358 +0x69
        main.main()
            net/http/_test/_testmain.go:361 +0x81
full log attached.

Attachments:

1. consoleText.txt (1839092 bytes)

[bradfitz]

Comment 4:

It's possible that the "leaked a Transport" test is from checkLeakedTransports is flaky,
or doesn't give things enough time to destroy their goroutines.  If you modify
checkLeakedTransports to just "return" at top, does it all work reliably?

[alberts]

Comment 5:

I think there's some kind of general runtime issue here. Here's another one.
--- FAIL: TestLinuxSendfile-2 (0.06 seconds)
fs_test.go:727: no sendfile system call found in:
go version devel +6415ff684316 Sun Mar 10 19:07:16 2013 -0700 linux/386
this is after the 64-bit atomic alignment fix
go test -v -cpu 1,2,4 -timeout=30m net/http
in a loop should reproduce all of these.
full log attached

Attachments:

1. consoleText.txt (1339239 bytes)

[dvyukov]

Comment 6:

The log contains sendfile64:
        [pid 30730] sendfile64(8, 13, NULL, 22Process 30731 attached
        ) = 22
It's just corrupted by concurrent output, and so regexp fails.

[DanielMorsing]

Comment 7:

That error is just because a thread is spawned and that garbles the strace output.
Manual inspection of the strace output shows that the sendfile call is there.

[dvyukov]

Comment 8:

This is the best I can do. GOMAXPROCS=1 won't help, because runtime can create threads
even when GOMAXPROCS=1.
https://golang.org/cl/7651045

[alberts]

Comment 9:

I'll take a look at the rest again tomorrow once 7651045 is in. Cheers.

[alberts]

Comment 10:

just saw this on amd64, so it's not 386 flakiness only:
still need to try the checkLeakedTransports stuff. will report back soon.
--- FAIL: TestGoroutinesRunning-67 (0.00 seconds)
    z_last_test.go:19: num goroutines = 23
    z_last_test.go:26: Too many goroutines:
        goroutine 2295 [running]:
        net/http_test.TestGoroutinesRunning(0xc2002f7ea0)
            /build/go.tip/go/src/pkg/net/http/z_last_test.go:25 +0x10f
        testing.tRunner(0xc2002f7ea0, 0x8eb438)
            /build/go.tip/go/src/pkg/testing/testing.go:346 +0x8a
        created by testing.RunTests
            /build/go.tip/go/src/pkg/testing/testing.go:426 +0x86b
        
        goroutine 1 [chan receive]:
        testing.RunTests(0x787b88, 0x8ea640, 0x96, 0x96, 0xc20010e301, ...)
            /build/go.tip/go/src/pkg/testing/testing.go:427 +0x88e
        testing.Main(0x787b88, 0x8ea640, 0x96, 0x96, 0x8e30e0, ...)
            /build/go.tip/go/src/pkg/testing/testing.go:358 +0x8a
        main.main()
            net/http/_test/_testmain.go:363 +0x9a
        
        goroutine 2 [syscall]:
        
        goroutine 37 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0x7, 0xc20010d170, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc20010d160, 0xc200695180, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc200695180)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 40 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0xb, 0xc20010d220, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc20010d210, 0xc200695330, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc200695330)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 810 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0x30, 0xc2002b3220, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc2002b3210, 0xc20023a210, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc20023a210)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 415 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0x19, 0xc200194010, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc200194000, 0xc2002fa360, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc2002fa360)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 100 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0xf, 0xc20010d2d0, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc20010d2c0, 0xc2008872d0, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc2008872d0)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 984 [sleep]:
        time.Sleep(0x1dcd6500)
            /build/go.tip/go/src/pkg/runtime/ztime_linux_amd64.c:19 +0x2f
        net/http.(*conn).closeWriteAndWait(0xc200273180)
            /build/go.tip/go/src/pkg/net/http/server.go:778 +0x6d
        net/http.(*conn).serve(0xc200273180)
            /build/go.tip/go/src/pkg/net/http/server.go:880 +0x7bb
        created by net/http.(*Server).Serve
            /build/go.tip/go/src/pkg/net/http/server.go:1338 +0x266
        
        goroutine 333 [finalizer wait]:
        
        goroutine 236 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0x14, 0xc2006a3010, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc2006a3000, 0xc20085f570, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc20085f570)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 489 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0x1d, 0xc2002b3170, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc2002b3160, 0xc2003548a0, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc2003548a0)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 2106 [chan receive]:
        net/http.func·015()
            /build/go.tip/go/src/pkg/net/http/transport.go:418 +0x39
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:421 +0x217
        
        goroutine 2109 [chan receive]:
        net.(*pollServer).WaitWrite(0xc200695180, 0xc2006ad410, 0xc20009b420, 0x73)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:260 +0x63
        net.(*netFD).connect(0xc2006ad410, 0xc200695120, 0xc2003e33a0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_unix.go:99 +0x15f
        net.socket(0x712400, 0x3, 0x2, 0x1, 0x0, ...)
            /build/go.tip/go/src/pkg/net/sock_posix.go:55 +0x301
        net.internetSocket(0x712400, 0x3, 0x0, 0x0, 0xc20017c3c0, ...)
            /build/go.tip/go/src/pkg/net/ipsock_posix.go:146 +0x423
        net.dialTCP(0x712400, 0x3, 0x0, 0xc2006d2ae0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/tcpsock_posix.go:153 +0x111
        net.dial(0x712400, 0x3, 0xc2006d2a27, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:214 +0x3cc
        net.DialOpt(0xc2006d2a27, 0xf, 0x7fa69ea7ada8, 0x1, 0x1, ...)
            /build/go.tip/go/src/pkg/net/dial.go:204 +0x1ff
        net.Dial(0x712400, 0x3, 0xc2006d2a27, 0xf, 0xc2000a0820, ...)
            /build/go.tip/go/src/pkg/net/dial.go:189 +0xd4
        net/http.(*Transport).dial(0xc2008c4080, 0x712400, 0x3, 0xc2006d2a27, 0xf, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:384 +0xd2
        net/http.(*Transport).dialConn(0xc2008c4080, 0xc2006d2ab0, 0xc2003e0e88, 0xc200b20280, 0xc2008c1840, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:427 +0x6c
        net/http.func·014()
            /build/go.tip/go/src/pkg/net/http/transport.go:402 +0x3c
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:404 +0x11b
        
        goroutine 807 [syscall]:
        syscall.Syscall6()
            /build/go.tip/go/src/pkg/syscall/asm_linux_amd64.s:41 +0x5
        syscall.EpollWait(0x24, 0xc200194430, 0xa, 0xa, 0xffffffffffffffff, ...)
            /build/go.tip/go/src/pkg/syscall/zerrors_linux_amd64.go:1872 +0x95
        net.(*pollster).WaitFD(0xc200194420, 0xc200277c60, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_linux.go:151 +0x127
        net.(*pollServer).Run(0xc200277c60)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:206 +0x10a
        created by net.newPollServer
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:55 +0x2d5
        
        goroutine 2112 [chan receive]:
        net/http.func·015()
            /build/go.tip/go/src/pkg/net/http/transport.go:418 +0x39
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:421 +0x217
        
        goroutine 2099 [chan receive]:
        net.(*pollServer).WaitWrite(0xc2003548a0, 0xc200876820, 0xc20009b420, 0x73)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:260 +0x63
        net.(*netFD).connect(0xc200876820, 0xc200695120, 0xc200837380, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_unix.go:99 +0x15f
        net.socket(0x712400, 0x3, 0x2, 0x1, 0x0, ...)
            /build/go.tip/go/src/pkg/net/sock_posix.go:55 +0x301
        net.internetSocket(0x712400, 0x3, 0x0, 0x0, 0xc20017c3c0, ...)
            /build/go.tip/go/src/pkg/net/ipsock_posix.go:146 +0x423
        net.dialTCP(0x712400, 0x3, 0x0, 0xc2006ef4e0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/tcpsock_posix.go:153 +0x111
        net.dial(0x712400, 0x3, 0xc2006ef337, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:214 +0x3cc
        net.DialOpt(0xc2006ef337, 0xf, 0x7fa688035da8, 0x1, 0x1, ...)
            /build/go.tip/go/src/pkg/net/dial.go:204 +0x1ff
        net.Dial(0x712400, 0x3, 0xc2006ef337, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:189 +0xd4
        net/http.(*Transport).dial(0xc2008c4080, 0x712400, 0x3, 0xc2006ef337, 0xf, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:384 +0xd2
        net/http.(*Transport).dialConn(0xc2008c4080, 0xc2006ef390, 0x421f10, 0x749b89, 0x4, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:427 +0x6c
        net/http.func·014()
            /build/go.tip/go/src/pkg/net/http/transport.go:402 +0x3c
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:404 +0x11b
        
        goroutine 2101 [chan receive]:
        net.(*pollServer).WaitWrite(0xc2008872d0, 0xc2008768f0, 0xc20009b420, 0x73)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:260 +0x63
        net.(*netFD).connect(0xc2008768f0, 0xc200695120, 0xc2008373a0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_unix.go:99 +0x15f
        net.socket(0x712400, 0x3, 0x2, 0x1, 0x0, ...)
            /build/go.tip/go/src/pkg/net/sock_posix.go:55 +0x301
        net.internetSocket(0x712400, 0x3, 0x0, 0x0, 0xc20017c3c0, ...)
            /build/go.tip/go/src/pkg/net/ipsock_posix.go:146 +0x423
        net.dialTCP(0x712400, 0x3, 0x0, 0xc2006ef510, 0x0, ...)
            /build/go.tip/go/src/pkg/net/tcpsock_posix.go:153 +0x111
        net.dial(0x712400, 0x3, 0xc2006ef3c7, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:214 +0x3cc
        net.DialOpt(0xc2006ef3c7, 0xf, 0x7fa688034da8, 0x1, 0x1, ...)
            /build/go.tip/go/src/pkg/net/dial.go:204 +0x1ff
        net.Dial(0x712400, 0x3, 0xc2006ef3c7, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:189 +0xd4
        net/http.(*Transport).dial(0xc2008c4080, 0x712400, 0x3, 0xc2006ef3c7, 0xf, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:384 +0xd2
        net/http.(*Transport).dialConn(0xc2008c4080, 0xc2006ef420, 0x0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:427 +0x6c
        net/http.func·014()
            /build/go.tip/go/src/pkg/net/http/transport.go:402 +0x3c
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:404 +0x11b
        
        goroutine 2107 [chan receive]:
        net.(*pollServer).WaitWrite(0xc20023a210, 0xc200a539c0, 0xc20009b420, 0x73)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:260 +0x63
        net.(*netFD).connect(0xc200a539c0, 0xc200695120, 0xc200211a40, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_unix.go:99 +0x15f
        net.socket(0x712400, 0x3, 0x2, 0x1, 0x0, ...)
            /build/go.tip/go/src/pkg/net/sock_posix.go:55 +0x301
        net.internetSocket(0x712400, 0x3, 0x0, 0x0, 0xc20017c3c0, ...)
            /build/go.tip/go/src/pkg/net/ipsock_posix.go:146 +0x423
        net.dialTCP(0x712400, 0x3, 0x0, 0xc2006d2150, 0x0, ...)
            /build/go.tip/go/src/pkg/net/tcpsock_posix.go:153 +0x111
        net.dial(0x712400, 0x3, 0xc2006d20c7, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:214 +0x3cc
        net.DialOpt(0xc2006d20c7, 0xf, 0x7fa68808bda8, 0x1, 0x1, ...)
            /build/go.tip/go/src/pkg/net/dial.go:204 +0x1ff
        net.Dial(0x712400, 0x3, 0xc2006d20c7, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:189 +0xd4
        net/http.(*Transport).dial(0xc2008c4080, 0x712400, 0x3, 0xc2006d20c7, 0xf, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:384 +0xd2
        net/http.(*Transport).dialConn(0xc2008c4080, 0xc2006d2120, 0x421f10, 0x749b89, 0x4, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:427 +0x6c
        net/http.func·014()
            /build/go.tip/go/src/pkg/net/http/transport.go:402 +0x3c
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:404 +0x11b
        
        goroutine 2111 [chan receive]:
        net/http.func·015()
            /build/go.tip/go/src/pkg/net/http/transport.go:418 +0x39
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:421 +0x217
        
        goroutine 2113 [chan receive]:
        net/http.func·015()
            /build/go.tip/go/src/pkg/net/http/transport.go:418 +0x39
        created by net/http.(*Transport).getConn
            /build/go.tip/go/src/pkg/net/http/transport.go:421 +0x217
FAIL

[bradfitz]

Comment 11:

The TestGoroutinesRunning test could be smarter and parse out each goroutine and discard
ones that are innocuous, such as those in syscall.EpollWait from newPollServer.  That's
one per CPU or whatever, and shouldn't count.
The ones that bother me are these 4:
        goroutine 2109 [chan receive]:
        net.(*pollServer).WaitWrite(0xc200695180, 0xc2006ad410, 0xc20009b420, 0x73)
            /build/go.tip/go/src/pkg/net/fd_poll_unix.go:260 +0x63
        net.(*netFD).connect(0xc2006ad410, 0xc200695120, 0xc2003e33a0, 0x0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/fd_unix.go:99 +0x15f
        net.socket(0x712400, 0x3, 0x2, 0x1, 0x0, ...)
            /build/go.tip/go/src/pkg/net/sock_posix.go:55 +0x301
        net.internetSocket(0x712400, 0x3, 0x0, 0x0, 0xc20017c3c0, ...)
            /build/go.tip/go/src/pkg/net/ipsock_posix.go:146 +0x423
        net.dialTCP(0x712400, 0x3, 0x0, 0xc2006d2ae0, 0x0, ...)
            /build/go.tip/go/src/pkg/net/tcpsock_posix.go:153 +0x111
        net.dial(0x712400, 0x3, 0xc2006d2a27, 0xf, 0x0, ...)
            /build/go.tip/go/src/pkg/net/dial.go:214 +0x3cc
        net.DialOpt(0xc2006d2a27, 0xf, 0x7fa69ea7ada8, 0x1, 0x1, ...)
            /build/go.tip/go/src/pkg/net/dial.go:204 +0x1ff
        net.Dial(0x712400, 0x3, 0xc2006d2a27, 0xf, 0xc2000a0820, ...)
            /build/go.tip/go/src/pkg/net/dial.go:189 +0xd4
        net/http.(*Transport).dial(0xc2008c4080, 0x712400, 0x3, 0xc2006d2a27, 0xf, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:384 +0xd2
        net/http.(*Transport).dialConn(0xc2008c4080, 0xc2006d2ab0, 0xc2003e0e88, 0xc200b20280, 0xc2008c1840, ...)
            /build/go.tip/go/src/pkg/net/http/transport.go:427 +0x6c
        net/http.func·014()
            /build/go.tip/go/src/pkg/net/http/transport.go:402 +0x3c
        created by net/http.(*Transport).getConn
Why is something stuck in a dial?
We should modify checkLeakedTransports to look for that stack trace earlier, and find
which test is responsible, rather than only detecting that at the very end.
We should also rename checkLeakedTransports because it does a lot more now.  Maybe just
postTest.

[rsc]

Comment 12:

[The time for maybe has passed.]

[rsc]

Comment 13:

Labels changed: added go1.1maybe, removed go1.1.

[bradfitz]

Comment 14:

Try out https://golang.org/cl/7777043

Status changed to Started.

[alberts]

Comment 15:

hit this one:
--- FAIL: TestHeaderWriteSubsetMallocs (0.00 seconds)
header_test.go:204: mallocs = %!d(float64=0.01); want 0
with:
#!/bin/bash
set -xe
export GOARCH=386
export GOHOSTARCH=386
cd $GOROOT/src
./make.bash
cd $GOROOT/src/pkg/net/http
go test -c
while true; do
GOMAXPROCS=$[ 1 + $[ RANDOM % 256 ]] ./http.test -test.v
./http.test -test.v -test.cpu=1,1,1,2,2,2,4,4,4,16,16,256 >log 2>&1
done
this is probably related to issue #5000.
I'll disable this test and keep going.