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

net/http: TestRequestBodyLimit failures due to leaked Transports #60264

Closed
gopherbot opened this issue May 17, 2023 · 10 comments
Closed

net/http: TestRequestBodyLimit failures due to leaked Transports #60264

gopherbot opened this issue May 17, 2023 · 10 comments
Assignees
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone

Comments

@gopherbot
Copy link

gopherbot commented May 17, 2023

#!watchflakes
post <- pkg == "net/http" && test == "TestRequestBodyLimit" && `Test appears to have leaked a Transport` && date < "2023-08-26"

Issue created automatically to collect these failures.

Example (log):

--- FAIL: TestRequestBodyLimit (3.16s)
    --- FAIL: TestRequestBodyLimit/h1 (3.12s)
        main_test.go:161: Test appears to have leaked a Transport:
            internal/poll.runtime_Semacquire(0x4a63d320?)
            	/tmp/buildlet/go/src/runtime/sema.go:67 +0x25
            internal/poll.(*FD).Close(0xc000328200)
            	/tmp/buildlet/go/src/internal/poll/fd_unix.go:116 +0x65
            net.(*netFD).Close(0xc000328200)
            	/tmp/buildlet/go/src/net/fd_posix.go:37 +0x32
            net.(*conn).Close(0xc00004e058)
...
            testing.(*T).Run(0xc000300d00, {0x14c13ab?, 0x27?}, 0xc0003f2060)
            	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc000300d00, 0x15114f0, {0x0, 0x0, 0x1087ecf})
            	/tmp/buildlet/go/src/net/http/clientserver_test.go:82 +0x26f
            net/http_test.TestRequestBodyLimit(0x12ac9e0?)
            	/tmp/buildlet/go/src/net/http/serve_test.go:2982 +0x2b
            testing.tRunner(0xc000300d00, 0x1510138)
            	/tmp/buildlet/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
            	/tmp/buildlet/go/src/testing/testing.go:1648 +0x3ad

watchflakes

@gopherbot gopherbot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label May 17, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestRequestBodyLimit"
2023-05-16 19:46 darwin-amd64-longtest go@b3d1cce3 net/http.TestRequestBodyLimit (log)
--- FAIL: TestRequestBodyLimit (3.16s)
    --- FAIL: TestRequestBodyLimit/h1 (3.12s)
        main_test.go:161: Test appears to have leaked a Transport:
            internal/poll.runtime_Semacquire(0x4a63d320?)
            	/tmp/buildlet/go/src/runtime/sema.go:67 +0x25
            internal/poll.(*FD).Close(0xc000328200)
            	/tmp/buildlet/go/src/internal/poll/fd_unix.go:116 +0x65
            net.(*netFD).Close(0xc000328200)
            	/tmp/buildlet/go/src/net/fd_posix.go:37 +0x32
            net.(*conn).Close(0xc00004e058)
...
            testing.(*T).Run(0xc000300d00, {0x14c13ab?, 0x27?}, 0xc0003f2060)
            	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc000300d00, 0x15114f0, {0x0, 0x0, 0x1087ecf})
            	/tmp/buildlet/go/src/net/http/clientserver_test.go:82 +0x26f
            net/http_test.TestRequestBodyLimit(0x12ac9e0?)
            	/tmp/buildlet/go/src/net/http/serve_test.go:2982 +0x2b
            testing.tRunner(0xc000300d00, 0x1510138)
            	/tmp/buildlet/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
            	/tmp/buildlet/go/src/testing/testing.go:1648 +0x3ad

watchflakes

@bcmills
Copy link
Contributor

bcmills commented May 17, 2023

(attn @neild)

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestRequestBodyLimit"
2023-06-05 19:18 darwin-amd64-longtest go@5db1e99b net/http.TestRequestBodyLimit (log)
--- FAIL: TestRequestBodyLimit (14.19s)
    --- FAIL: TestRequestBodyLimit/h1 (3.10s)
        main_test.go:161: Test appears to have leaked a Transport:
            internal/poll.runtime_Semacquire(0x49b7be98?)
            	/tmp/buildlet/go/src/runtime/sema.go:67 +0x25
            internal/poll.(*FD).Close(0xc0001a8280)
            	/tmp/buildlet/go/src/internal/poll/fd_unix.go:113 +0x65
            net.(*netFD).Close(0xc0001a8280)
            	/tmp/buildlet/go/src/net/fd_posix.go:37 +0x32
            net.(*conn).Close(0xc0002ca058)
...
            testing.(*T).Run(0xc0001b44e0, {0x14cd8c9?, 0x27?}, 0xc00024c270)
            	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc0001b44e0, 0x151e210, {0x0, 0x0, 0x6afa30c6a0000000})
            	/tmp/buildlet/go/src/net/http/clientserver_test.go:82 +0x26f
            net/http_test.TestRequestBodyLimit(0x12b6620?)
            	/tmp/buildlet/go/src/net/http/serve_test.go:2982 +0x2b
            testing.tRunner(0xc0001b44e0, 0x151ce40)
            	/tmp/buildlet/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
            	/tmp/buildlet/go/src/testing/testing.go:1648 +0x3ad

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestRequestBodyLimit"
2023-06-06 19:22 darwin-amd64-longtest go@e23273dd net/http.TestRequestBodyLimit (log)
--- FAIL: TestRequestBodyLimit (3.22s)
    --- FAIL: TestRequestBodyLimit/h1 (3.14s)
        main_test.go:161: Test appears to have leaked a Transport:
            internal/poll.runtime_Semacquire(0x49d1e048?)
            	/tmp/buildlet/go/src/runtime/sema.go:67 +0x25
            internal/poll.(*FD).Close(0xc000022480)
            	/tmp/buildlet/go/src/internal/poll/fd_unix.go:113 +0x65
            net.(*netFD).Close(0xc000022480)
            	/tmp/buildlet/go/src/net/fd_posix.go:37 +0x32
            net.(*conn).Close(0xc0000960a0)
...
            testing.(*T).Run(0xc0002569c0, {0x14cdd29?, 0x27?}, 0xc0001625d0)
            	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc0002569c0, 0x151e770, {0x0, 0x0, 0x108940f})
            	/tmp/buildlet/go/src/net/http/clientserver_test.go:82 +0x26f
            net/http_test.TestRequestBodyLimit(0x18?)
            	/tmp/buildlet/go/src/net/http/serve_test.go:2982 +0x2b
            testing.tRunner(0xc0002569c0, 0x151d3a0)
            	/tmp/buildlet/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
            	/tmp/buildlet/go/src/testing/testing.go:1648 +0x3ad

watchflakes

@bcmills bcmills changed the title net/http: TestRequestBodyLimit failures net/http: TestRequestBodyLimit failures due to leaked Transports Jun 7, 2023
@bcmills
Copy link
Contributor

bcmills commented Jun 7, 2023

Given the timing of the failures in the report, this is looking like a Go 1.21 regression. Marking as release-blocker at least until we can determine whether it is new.

@bcmills bcmills added this to the Go1.21 milestone Jun 7, 2023
@eliben
Copy link
Member

eliben commented Jun 7, 2023

@neild PTAL

@gopherbot
Copy link
Author

Change https://go.dev/cl/501309 mentions this issue: net/http: close response body in TestRequestBodyLimit

@bcmills bcmills added the Testing An issue that has been verified to require only test changes, not just a test failure. label Jun 7, 2023
@gopherbot gopherbot reopened this Aug 17, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestRequestBodyLimit" && `Test appears to have leaked a Transport`
2023-08-17 16:25 darwin-amd64-longtest go@56076c30 net/http.TestRequestBodyLimit (log)
--- FAIL: TestRequestBodyLimit (3.21s)
    --- FAIL: TestRequestBodyLimit/h1 (3.12s)
        main_test.go:161: Test appears to have leaked a Transport:
            internal/poll.runtime_Semacquire(0x573144b0?)
            	/tmp/buildlet/go/src/runtime/sema.go:67 +0x25
            internal/poll.(*FD).Close(0xc0001b0800)
            	/tmp/buildlet/go/src/internal/poll/fd_unix.go:113 +0x65
            net.(*netFD).Close(0xc0001b0800)
            	/tmp/buildlet/go/src/net/fd_posix.go:37 +0x32
            net.(*conn).Close(0xc00038c090)
...
            	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc0003281a0, 0x10169c58, {0x0, 0x0, 0xfc4da2f})
            	/tmp/buildlet/go/src/net/http/clientserver_test.go:82 +0x25b
            net/http_test.TestRequestBodyLimit(0x0?)
            	/tmp/buildlet/go/src/net/http/serve_test.go:2982 +0x2b
            testing.tRunner(0xc0003281a0, 0x101688d8)
            	/tmp/buildlet/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
            	/tmp/buildlet/go/src/testing/testing.go:1648 +0x3ad
2023/08/17 12:50:30 Unsolicited response received on idle HTTP channel starting with "HTTP/1.1 204 No Content\r\nConnection: close\r\n\r\n"; err=<nil>

watchflakes

@bcmills bcmills modified the milestones: Go1.21, Go1.22 Aug 17, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestRequestBodyLimit" && `Test appears to have leaked a Transport`
2023-08-21 17:10 darwin-amd64-longtest go@a7c3de70 net/http.TestRequestBodyLimit (log)
--- FAIL: TestRequestBodyLimit (3.09s)
    --- FAIL: TestRequestBodyLimit/h1 (3.07s)
        main_test.go:161: Test appears to have leaked a Transport:
            internal/poll.runtime_Semacquire(0x53a268e0?)
            	/tmp/buildlet/go/src/runtime/sema.go:67 +0x25
            internal/poll.(*FD).Close(0xc0000fe800)
            	/tmp/buildlet/go/src/internal/poll/fd_unix.go:113 +0x65
            net.(*netFD).Close(0xc0000fe800)
            	/tmp/buildlet/go/src/net/fd_posix.go:37 +0x32
            net.(*conn).Close(0xc00012a050)
...
            testing.(*T).Run(0xc00079c340, {0xc587c30?, 0x27?}, 0xc0002f43f0)
            	/tmp/buildlet/go/src/testing/testing.go:1649 +0x3c8
            net/http_test.run[...](0xc00079c340, 0xc719af8, {0x0, 0x0, 0xc1fcb6f})
            	/tmp/buildlet/go/src/net/http/clientserver_test.go:82 +0x25b
            net/http_test.TestRequestBodyLimit(0xc00024f7d0?)
            	/tmp/buildlet/go/src/net/http/serve_test.go:2982 +0x2b
            testing.tRunner(0xc00079c340, 0xc718778)
            	/tmp/buildlet/go/src/testing/testing.go:1595 +0xff
            created by testing.(*T).Run in goroutine 1
            	/tmp/buildlet/go/src/testing/testing.go:1648 +0x3ad

watchflakes

@gopherbot
Copy link
Author

Change https://go.dev/cl/522695 mentions this issue: net/http: deflake TestRequestBodyLimit

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
Status: Done
Development

No branches or pull requests

4 participants