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: TestCancelRequestWithChannelBeforeDo_Cancel/h2 failure with leaked a timing out dial on Windows #59494

Open
bcmills opened this issue Apr 8, 2023 · 4 comments
Open

net/http: TestCancelRequestWithChannelBeforeDo_Cancel/h2 failure with leaked a timing out dial on Windows #59494

bcmills opened this issue Apr 8, 2023 · 4 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Windows
Milestone
Backlog

Comments

@bcmills
Copy link
Contributor

bcmills commented Apr 8, 2023 •
edited by cherrymui 

#!watchflakes
post <- pkg == "net/http" && test ~ `TestCancelRequestWithChannelBeforeDo_Cancel` && `Test appears to have leaked a timing out dial:`

What version of Go are you using (go version)?

C:\Users\bryan\src\go\src>go version
go version devel go1.21-66cac9e1e4 Fri Apr 7 23:34:21 2023 +0000 windows/amd64

What operating system and processor architecture are you using (go env)?

go env Output
C:\Users\bryan\src\go\src>go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\bryan\AppData\Local\go-build
set GOENV=C:\Users\bryan\AppData\Roaming\go\env
set GOEXE=.exe
set GOEXPERIMENT=
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=C:\Users\bryan\go\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=C:\Users\bryan\go
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Users\bryan\src\go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Users\bryan\src\go\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=devel go1.21-66cac9e1e4 Fri Apr 7 23:34:21 2023 +0000
set GCCGO=gccgo
set GOAMD64=v1
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=C:\Users\bryan\src\go\src\go.mod
set GOWORK=
set CGO_CFLAGS=-O2 -g
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-O2 -g
set CGO_FFLAGS=-O2 -g
set CGO_LDFLAGS=-O2 -g
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=C:\Users\bryan\AppData\Local\Temp\go-build4136781064=/tmp/go-build -gno-record-gcc-switches

What did you do?

go test std cmd -timeout=1h

What did you expect to see?

All tests passing.

What did you see instead?

--- FAIL: TestCancelRequestWithChannelBeforeDo_Cancel (5.00s)
    --- FAIL: TestCancelRequestWithChannelBeforeDo_Cancel/h2 (2.61s)
        main_test.go:141: Test appears to have leaked a timing out dial:
            internal/poll.runtime_pollWait(0x157bb677028, 0x77)
                C:/Users/bryan/src/go/src/runtime/netpoll.go:306 +0x85
            internal/poll.(*pollDesc).wait(0xc000402030?, 0x30?, 0x0)
                C:/Users/bryan/src/go/src/internal/poll/fd_poll_runtime.go:84 +0x27
            internal/poll.execIO(0xc000236868, 0xaa0ac0)
                C:/Users/bryan/src/go/src/internal/poll/fd_windows.go:175 +0xe6
            internal/poll.(*FD).ConnectEx(0xfaf7?, {0xb20500?, 0xc000136460?})
                C:/Users/bryan/src/go/src/internal/poll/fd_windows.go:926 +0x54
            net.(*netFD).connect(0xc000236780, {0xb238e8?, 0xe2de78}, {0x0, 0x0?}, {0xb20500?, 0xc000136460})
                C:/Users/bryan/src/go/src/net/fd_windows.go:106 +0x393
            net.(*netFD).dial(0xc000236780, {0xb238e8, 0xe2de78}, {0xb24400?, 0x0?}, {0xb24400?, 0xc000508c00}, 0xc0001c92a8?)
                C:/Users/bryan/src/go/src/net/sock_posix.go:151 +0x3ca
            net.socket({0xb238e8, 0xe2de78}, {0xa50823, 0x3}, 0x2, 0x1, 0x0?, 0x0?, {0xb24400, 0x0}, ...)
                C:/Users/bryan/src/go/src/net/sock_posix.go:70 +0x2af
            net.internetSocket({0xb238e8, 0xe2de78}, {0xa50823, 0x3}, {0xb24400, 0x0}, {0xb24400?, 0xc000508c00?}, 0x1?, 0x0, ...)
                C:/Users/bryan/src/go/src/net/ipsock_posix.go:142 +0x1e5
            net.(*sysDialer).doDialTCPProto(0xc000074000, {0xb238e8, 0xe2de78}, 0x0, 0xc000508bd0?, 0xc0007d8680?)
                C:/Users/bryan/src/go/src/net/tcpsock_posix.go:78 +0xe9
            net.(*sysDialer).doDialTCP(...)
                C:/Users/bryan/src/go/src/net/tcpsock_posix.go:68
            net.(*sysDialer).dialTCP(0x28?, {0xb238e8?, 0xe2de78?}, 0xc0003bb668?, 0x781625?)
                C:/Users/bryan/src/go/src/net/tcpsock_posix.go:64 +0x65
            net.(*sysDialer).dialSingle(0xc000074000, {0xb238e8, 0xe2de78}, {0xb21cc8?, 0xc000508c00})
                C:/Users/bryan/src/go/src/net/dial.go:639 +0x24b
            net.(*sysDialer).dialSerial(0xc000074000, {0xb238e8, 0xe2de78}, {0xc000230c10?, 0x1, 0x77f232?})
                C:/Users/bryan/src/go/src/net/dial.go:604 +0x248
            net.(*sysDialer).dialParallel(0xc000230be0?, {0xb238e8?, 0xe2de78?}, {0xc000230c10?, 0xe2de78?, 0xa50b21?}, {0x0?, 0xa50823?, 0x5a4fe8?})
                C:/Users/bryan/src/go/src/net/dial.go:505 +0x3e5
            net.(*Dialer).DialContext(0xdd78e0, {0xb238e8, 0xe2de78}, {0xa50823, 0x3}, {0xc0001865a0, 0xf})
                C:/Users/bryan/src/go/src/net/dial.go:496 +0x6de
            net/http.(*Transport).dial(0x5b1745?, {0xb238e8?, 0xe2de78?}, {0xa50823?, 0x59f1e5?}, {0xc0001865a0?, 0xa37b20?})
                C:/Users/bryan/src/go/src/net/http/transport.go:1192 +0xb4
            net/http.(*Transport).dialConn(0xc0000763c0, {0xb238e8, 0xe2de78}, {{}, 0x0, {0xc00001c510, 0x5}, {0xc0001865a0, 0xf}, 0x0})
                C:/Users/bryan/src/go/src/net/http/transport.go:1621 +0x7e8
            net/http.(*Transport).dialConnFor(0xc00072c340?, 0xc0000a6370)
                C:/Users/bryan/src/go/src/net/http/transport.go:1463 +0xa5
            created by net/http.(*Transport).queueForDial in goroutine 25162
                C:/Users/bryan/src/go/src/net/http/transport.go:1432 +0x3d5

            net.(*netFD).connect.func2()
                C:/Users/bryan/src/go/src/net/fd_windows.go:95 +0x6b
            created by net.(*netFD).connect in goroutine 25164
                C:/Users/bryan/src/go/src/net/fd_windows.go:94 +0x376

            testing.(*T).Parallel(0xc00027f6c0)
                C:/Users/bryan/src/go/src/testing/testing.go:1403 +0x205
            net/http.TestCmdGoNoHTTPServer(0xc00027f6c0)
                C:/Users/bryan/src/go/src/net/http/http_test.go:85 +0x2a
            testing.tRunner(0xc00027f6c0, 0xaa0d20)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad

            testing.(*T).Parallel(0xc00027f860)
                C:/Users/bryan/src/go/src/testing/testing.go:1403 +0x205
            net/http.TestOmitHTTP2(0xc00027f860)
                C:/Users/bryan/src/go/src/net/http/http_test.go:119 +0x87
            testing.tRunner(0xc00027f860, 0xaa0da0)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad

            testing.(*T).Parallel(0xc00027fa00)
                C:/Users/bryan/src/go/src/testing/testing.go:1403 +0x205
            net/http.TestOmitHTTP2Vet(0xc00027fa00)
                C:/Users/bryan/src/go/src/net/http/http_test.go:131 +0x25
            testing.tRunner(0xc00027fa00, 0xaa0d98)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad

            testing.(*T).Parallel(0xc0002a6ea0)
                C:/Users/bryan/src/go/src/testing/testing.go:1403 +0x205
            net/http.TestRequestWriteTransport(0xc0002a6ea0)
                C:/Users/bryan/src/go/src/net/http/requestwrite_test.go:668 +0x2a
            testing.tRunner(0xc0002a6ea0, 0xaa0e40)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad

            testing.(*T).Parallel(0xc0002a7860)
                C:/Users/bryan/src/go/src/testing/testing.go:1403 +0x205
            net/http.TestReadResponseCloseInMiddle(0xc0002a7860)
                C:/Users/bryan/src/go/src/net/http/response_test.go:647 +0x2a
            testing.tRunner(0xc0002a7860, 0xaa0de8)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad

            testing.(*T).Parallel(0xc0002da1a0)
                C:/Users/bryan/src/go/src/testing/testing.go:1403 +0x205
            net/http_test.TestConsumingBodyOnNextConn(0xc0002da1a0)
                C:/Users/bryan/src/go/src/net/http/serve_test.go:167 +0x3e
            testing.tRunner(0xc0002da1a0, 0xaa1380)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad

            testing.(*T).Run(0xc000051380, {0xa72efb?, 0x60102d?}, 0xaa11d0)
                C:/Users/bryan/src/go/src/testing/testing.go:1649 +0x3c8
            testing.runTests.func1(0xdd8300?)
                C:/Users/bryan/src/go/src/testing/testing.go:2055 +0x3e
            testing.tRunner(0xc000051380, 0xc000095c30)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            testing.runTests(0xc000074d20?, {0xdd1c20, 0x1fc, 0x1fc}, {0x59cac9?, 0xc000095d40?, 0xdd7860?})
                C:/Users/bryan/src/go/src/testing/testing.go:2053 +0x445
            testing.(*M).Run(0xc000074d20)
                C:/Users/bryan/src/go/src/testing/testing.go:1925 +0x636
            net/http_test.TestMain(0xc000057f30?)
                C:/Users/bryan/src/go/src/net/http/main_test.go:24 +0x27
            main.main()
                _testmain.go:1127 +0x1c6

            testing.(*T).Run(0xc00072c4e0, {0xa50564?, 0x2c?}, 0xc000508060)
                C:/Users/bryan/src/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc00072c4e0, 0xaa11c8, {0x0, 0x0, 0x1000})
                C:/Users/bryan/src/go/src/net/http/clientserver_test.go:82 +0x26f
            net/http_test.TestCancelRequestWithChannelBeforeDo_Cancel(0xc00072c1a0?)
                C:/Users/bryan/src/go/src/net/http/transport_test.go:2608 +0x2b
            testing.tRunner(0xc00072c4e0, 0xaa11d0)
                C:/Users/bryan/src/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
                C:/Users/bryan/src/go/src/testing/testing.go:1648 +0x3ad
FAIL
FAIL    net/http        83.327s

(attn @neild @golang/windows)
@bcmills bcmills added OS-Windows NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Apr 8, 2023
@bcmills bcmills added this to the Backlog milestone Apr 8, 2023
@bcmills bcmills changed the title net/http: TestCancelRequestWithChannelBeforeDo_Cancel/h2 failure with leaked a timing out dial net/http: TestCancelRequestWithChannelBeforeDo_Cancel/h2 failure with leaked a timing out dial on Windows Apr 8, 2023
@prattmic
Copy link
Member

prattmic commented Oct 5, 2023

Occurred on a release branch CL today as well: https://go.dev/cl/533195 https://ci.chromium.org/ui/p/golang/builders/try/go1.20-windows-amd64-longtest/b8768055849584360897/overview

@bcmills
Copy link
Contributor Author

bcmills commented Nov 6, 2023

Another one on release-branch.go1.20, in https://go.dev/cl/540335:
http://ci.chromium.org/b/8765140844236212273/test-results?q=ExactID%3Anet%2Fhttp.TestCancelRequestWithChannelBeforeDo_Cancel%2Fh2+VHash%3A345244cc822e584f&clean=&sortby=&groupby=

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test ~ `TestCancelRequestWithChannelBeforeDo_Cancel` && `Test appears to have leaked a timing out dial:`
2024-01-09 18:15 go1.20-windows-amd64-longtest release-branch.go1.20@a95136a8 net/http.TestCancelRequestWithChannelBeforeDo_Cancel/h2 (log) 
=== RUN   TestCancelRequestWithChannelBeforeDo_Cancel/h2
    main_test.go:140: Test appears to have leaked a timing out dial:
        internal/poll.runtime_pollWait(0x213ae048c08, 0x77)
        	C:/b/s/w/ir/x/w/goroot/src/runtime/netpoll.go:306 +0x89
        internal/poll.(*pollDesc).wait(0xc000260b40?, 0x30?, 0x0)
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_poll_runtime.go:84 +0x32
        internal/poll.execIO(0xc0000c0d68, 0x666cd0)
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_windows.go:175 +0xf7
        internal/poll.(*FD).ConnectEx(0xd083?, {0x6e75a0?, 0xc0002164c0?})
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_windows.go:926 +0x57
...
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1630 +0x405
        net/http_test.run[...](0xc0000fb1e0, 0x6673a8, {0x0, 0x0, 0xc000717fb0})
        	C:/b/s/w/ir/x/w/goroot/src/net/http/clientserver_test.go:82 +0x26a
        net/http_test.TestCancelRequestWithChannelBeforeDo_Cancel(0xc0000fad00?)
        	C:/b/s/w/ir/x/w/goroot/src/net/http/transport_test.go:2609 +0x31
        testing.tRunner(0xc0000fb1e0, 0x6673b0)
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1576 +0x10b
        created by testing.(*T).Run
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1629 +0x3ea
--- FAIL: TestCancelRequestWithChannelBeforeDo_Cancel/h2 (2.76s)

— watchflakes

@gopherbot
Copy link

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test ~ `TestCancelRequestWithChannelBeforeDo_Cancel` && `Test appears to have leaked a timing out dial:`
2024-02-01 18:26 go1.20-windows-amd64-longtest release-branch.go1.20@a2f4a5a6 net/http.TestCancelRequestWithChannelBeforeDo_Cancel/h1 (log) 
=== RUN   TestCancelRequestWithChannelBeforeDo_Cancel/h1
    main_test.go:140: Test appears to have leaked a timing out dial:
        internal/poll.runtime_pollWait(0x19f70fa42c0, 0x77)
        	C:/b/s/w/ir/x/w/goroot/src/runtime/netpoll.go:306 +0x89
        internal/poll.(*pollDesc).wait(0xc000c50720?, 0x30?, 0x0)
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_poll_runtime.go:84 +0x32
        internal/poll.execIO(0xc000206d68, 0xae6cf0)
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_windows.go:175 +0xf7
        internal/poll.(*FD).ConnectEx(0xd02c?, {0xb675e0?, 0xc0001b0280?})
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_windows.go:926 +0x57
...
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1630 +0x405
        net/http_test.run[...](0xc000b504e0, 0xae73c8, {0x0, 0x0, 0x647157})
        	C:/b/s/w/ir/x/w/goroot/src/net/http/clientserver_test.go:82 +0x26a
        net/http_test.TestCancelRequestWithChannelBeforeDo_Cancel(0xc000b50b60?)
        	C:/b/s/w/ir/x/w/goroot/src/net/http/transport_test.go:2609 +0x31
        testing.tRunner(0xc000b504e0, 0xae73d0)
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1576 +0x10b
        created by testing.(*T).Run
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1629 +0x3ea
--- FAIL: TestCancelRequestWithChannelBeforeDo_Cancel/h1 (2.69s)
2024-02-01 18:26 go1.20-windows-amd64-longtest release-branch.go1.20@a2f4a5a6 net/http.TestCancelRequestWithChannelBeforeDo_Cancel/h2 (log) 
=== RUN   TestCancelRequestWithChannelBeforeDo_Cancel/h2
    main_test.go:140: Test appears to have leaked a timing out dial:
        internal/poll.runtime_pollWait(0x19f70fa42c0, 0x77)
        	C:/b/s/w/ir/x/w/goroot/src/runtime/netpoll.go:306 +0x89
        internal/poll.(*pollDesc).wait(0xc00002c990?, 0x30?, 0x0)
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_poll_runtime.go:84 +0x32
        internal/poll.execIO(0xc000206368, 0xae6cf0)
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_windows.go:175 +0xf7
        internal/poll.(*FD).ConnectEx(0xd02e?, {0xb675e0?, 0xc000270420?})
        	C:/b/s/w/ir/x/w/goroot/src/internal/poll/fd_windows.go:926 +0x57
...
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1630 +0x405
        net/http_test.run[...](0xc000b504e0, 0xae73c8, {0x0, 0x0, 0x647157})
        	C:/b/s/w/ir/x/w/goroot/src/net/http/clientserver_test.go:82 +0x26a
        net/http_test.TestCancelRequestWithChannelBeforeDo_Cancel(0xc000b50b60?)
        	C:/b/s/w/ir/x/w/goroot/src/net/http/transport_test.go:2609 +0x31
        testing.tRunner(0xc000b504e0, 0xae73d0)
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1576 +0x10b
        created by testing.(*T).Run
        	C:/b/s/w/ir/x/w/goroot/src/testing/testing.go:1629 +0x3ea
--- FAIL: TestCancelRequestWithChannelBeforeDo_Cancel/h2 (2.64s)

— 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. OS-Windows
Projects
Test Flakes
Status: No status
Milestone
Backlog
Development

No branches or pull requests
3 participants
@prattmic @bcmills @gopherbot