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: TestServerShutdown failures #56421

Closed
gopherbot opened this issue Oct 25, 2022 · 21 comments
Closed

net/http: TestServerShutdown failures #56421

gopherbot opened this issue Oct 25, 2022 · 21 comments
Assignees
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@gopherbot
Copy link

gopherbot commented Oct 25, 2022

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`

Issue created automatically to collect these failures.

Example (log):

2022/10/25 00:24:18 http2: server: error reading preface from client 127.0.0.1:58560: bogus greeting "CONNECT golang.fake.tld:"
2022/10/25 00:24:18 http2: server: error reading preface from client 127.0.0.1:59626: bogus greeting "CONNECT golang.fake.tld:"
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:57220: read tcp 127.0.0.1:43019->127.0.0.1:57220: i/o timeout
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.06s)
        serve_test.go:5564: second request should fail. server should be shut down
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:37530: EOF
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:42388: EOF
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55964: write tcp 127.0.0.1:39597->127.0.0.1:55964: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55944: write tcp 127.0.0.1:39597->127.0.0.1:55944: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47390: write tcp 127.0.0.1:43357->127.0.0.1:47390: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55990: write tcp 127.0.0.1:39597->127.0.0.1:55990: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47416: write tcp 127.0.0.1:43357->127.0.0.1:47416: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47396: write tcp 127.0.0.1:43357->127.0.0.1:47396: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55978: write tcp 127.0.0.1:39597->127.0.0.1:55978: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47432: write tcp 127.0.0.1:43357->127.0.0.1:47432: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47440: write tcp 127.0.0.1:43357->127.0.0.1:47440: use of closed network connection

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 Oct 25, 2022
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown"
2022-10-25 00:18 linux-amd64-buster go@9fffcde1 net/http.TestServerShutdown (log)
2022/10/25 00:24:18 http2: server: error reading preface from client 127.0.0.1:58560: bogus greeting "CONNECT golang.fake.tld:"
2022/10/25 00:24:18 http2: server: error reading preface from client 127.0.0.1:59626: bogus greeting "CONNECT golang.fake.tld:"
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:57220: read tcp 127.0.0.1:43019->127.0.0.1:57220: i/o timeout
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.06s)
        serve_test.go:5564: second request should fail. server should be shut down
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:37530: EOF
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:42388: EOF
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55964: write tcp 127.0.0.1:39597->127.0.0.1:55964: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55944: write tcp 127.0.0.1:39597->127.0.0.1:55944: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47390: write tcp 127.0.0.1:43357->127.0.0.1:47390: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55990: write tcp 127.0.0.1:39597->127.0.0.1:55990: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47416: write tcp 127.0.0.1:43357->127.0.0.1:47416: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47396: write tcp 127.0.0.1:43357->127.0.0.1:47396: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:55978: write tcp 127.0.0.1:39597->127.0.0.1:55978: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47432: write tcp 127.0.0.1:43357->127.0.0.1:47432: use of closed network connection
2022/10/25 00:24:18 http: TLS handshake error from 127.0.0.1:47440: write tcp 127.0.0.1:43357->127.0.0.1:47440: use of closed network connection

watchflakes

@bcmills
Copy link
Contributor

bcmills commented Oct 25, 2022

Is this a duplicate of #56036?

(Compare #38305, #54758 (comment).)

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown"
2022-10-27 01:24 dragonfly-amd64-622 go@612bb34a net/http.TestServerShutdown (log)
2022/10/27 01:42:04 http2: server: error reading preface from client 127.0.0.1:49622: bogus greeting "CONNECT golang.fake.tld:"
2022/10/27 01:42:04 http2: server: error reading preface from client 127.0.0.1:58722: bogus greeting "CONNECT golang.fake.tld:"
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:53152: EOF
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:52184: EOF
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:49586: read tcp 127.0.0.1:64104->127.0.0.1:49586: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:50198: read tcp 127.0.0.1:64104->127.0.0.1:50198: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:64095: read tcp 127.0.0.1:64104->127.0.0.1:64095: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:57265: read tcp 127.0.0.1:64104->127.0.0.1:57265: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:60062: read tcp 127.0.0.1:64104->127.0.0.1:60062: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:52742: read tcp 127.0.0.1:64104->127.0.0.1:52742: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:63438: read tcp 127.0.0.1:61272->127.0.0.1:63438: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:59978: read tcp 127.0.0.1:61272->127.0.0.1:59978: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:50094: read tcp 127.0.0.1:61272->127.0.0.1:50094: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:59623: write tcp 127.0.0.1:61272->127.0.0.1:59623: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:59455: read tcp 127.0.0.1:61272->127.0.0.1:59455: use of closed network connection
2022/10/27 01:42:05 http: TLS handshake error from 127.0.0.1:55941: write tcp 127.0.0.1:64104->127.0.0.1:55941: use of closed network connection
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h1 (0.05s)
        serve_test.go:5564: second request should fail. server should be shut down
2022-10-31 20:45 linux-amd64-nounified go@76940b3e net/http.TestServerShutdown (log)
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:53206: read tcp 127.0.0.1:43723->127.0.0.1:53206: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:53226: read tcp 127.0.0.1:43723->127.0.0.1:53226: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:36180: write tcp 127.0.0.1:45453->127.0.0.1:36180: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:53256: write tcp 127.0.0.1:43723->127.0.0.1:53256: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:53208: write tcp 127.0.0.1:43723->127.0.0.1:53208: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:53200: write tcp 127.0.0.1:43723->127.0.0.1:53200: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:53214: write tcp 127.0.0.1:43723->127.0.0.1:53214: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:36162: write tcp 127.0.0.1:45453->127.0.0.1:36162: use of closed network connection
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:54892: EOF
2022/10/31 20:54:56 http: TLS handshake error from 127.0.0.1:39626: EOF
2022/10/31 20:54:56 http2: server: error reading preface from client 127.0.0.1:59452: bogus greeting "CONNECT golang.fake.tld:"
2022/10/31 20:54:56 http2: server: error reading preface from client 127.0.0.1:37450: bogus greeting "CONNECT golang.fake.tld:"
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.05s)
        serve_test.go:5564: second request should fail. server should be shut down

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown"
2022-11-15 00:27 linux-amd64 go@f977ffe8 net/http.TestServerShutdown (log)
2022/11/15 00:34:39 http2: server: error reading preface from client 127.0.0.1:54838: bogus greeting "CONNECT golang.fake.tld:"
2022/11/15 00:34:39 http2: server: error reading preface from client 127.0.0.1:44904: bogus greeting "CONNECT golang.fake.tld:"
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h1 (0.05s)
        serve_test.go:5633: second request should fail. server should be shut down
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:47584: EOF
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:59368: EOF
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:43416: read tcp 127.0.0.1:33251->127.0.0.1:43416: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:43402: read tcp 127.0.0.1:33251->127.0.0.1:43402: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:38466: read tcp 127.0.0.1:32867->127.0.0.1:38466: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:38406: read tcp 127.0.0.1:32867->127.0.0.1:38406: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:38492: write tcp 127.0.0.1:32867->127.0.0.1:38492: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:38436: write tcp 127.0.0.1:32867->127.0.0.1:38436: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:38488: write tcp 127.0.0.1:32867->127.0.0.1:38488: use of closed network connection
2022/11/15 00:34:39 http: TLS handshake error from 127.0.0.1:38476: write tcp 127.0.0.1:32867->127.0.0.1:38476: use of closed network connection

watchflakes

@bcmills
Copy link
Contributor

bcmills commented Nov 17, 2022

(attn @neild)

@neild
Copy link
Contributor

neild commented Nov 17, 2022

Is this a duplicate of #56036?

Yes, due to the test being renamed from TestServerShutdown_h2 to TestServerShutdown/h2 in the Great Test Refactoring.

@neild neild self-assigned this Nov 18, 2022
@seankhliao seankhliao added this to the Unplanned milestone Nov 19, 2022
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown"
2022-11-11 01:29 linux-386-sid go@4d37f968 net/http.TestServerShutdown (log)
2022/11/11 01:37:23 http2: server: error reading preface from client 127.0.0.1:54880: bogus greeting "CONNECT golang.fake.tld:"
2022/11/11 01:37:23 http2: server: error reading preface from client 127.0.0.1:38704: bogus greeting "CONNECT golang.fake.tld:"
2022/11/11 01:37:23 http: TLS handshake error from 127.0.0.1:39848: write tcp 127.0.0.1:43551->127.0.0.1:39848: i/o timeout
2022/11/11 01:37:23 http: TLS handshake error from 127.0.0.1:58432: write tcp 127.0.0.1:40857->127.0.0.1:58432: i/o timeout
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.08s)
        serve_test.go:5633: second request should fail. server should be shut down
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:52628: EOF
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:50602: EOF
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:43642: read tcp 127.0.0.1:36421->127.0.0.1:43642: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:43704: read tcp 127.0.0.1:36421->127.0.0.1:43704: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:43666: write tcp 127.0.0.1:36421->127.0.0.1:43666: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:49966: write tcp 127.0.0.1:39819->127.0.0.1:49966: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:49908: write tcp 127.0.0.1:39819->127.0.0.1:49908: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:49926: write tcp 127.0.0.1:39819->127.0.0.1:49926: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:49978: write tcp 127.0.0.1:39819->127.0.0.1:49978: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:49910: write tcp 127.0.0.1:39819->127.0.0.1:49910: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:49942: write tcp 127.0.0.1:39819->127.0.0.1:49942: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:43696: write tcp 127.0.0.1:36421->127.0.0.1:43696: use of closed network connection
2022/11/11 01:37:24 http: TLS handshake error from 127.0.0.1:43692: write tcp 127.0.0.1:36421->127.0.0.1:43692: use of closed network connection
2022/11/11 01:37:25 http: TLS handshake error from 127.0.0.1:37746: EOF
2022/11/11 01:37:25 http: TLS handshake error from 127.0.0.1:56952: EOF
2022/11/11 01:37:25 http: TLS handshake error from 127.0.0.1:37760: EOF
2022/11/11 01:37:25 http: TLS handshake error from 127.0.0.1:56962: EOF
2022/11/11 01:37:25 http: TLS handshake error from 127.0.0.1:56974: EOF

watchflakes

@gopherbot

This comment was marked as off-topic.

@bcmills

This comment was marked as off-topic.

@gopherbot

This comment was marked as off-topic.

@bcmills

This comment was marked as off-topic.

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`
2023-02-09 23:41 linux-arm64 go@fb79da29 net/http.TestServerShutdown (log)
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h1 (0.05s)
        serve_test.go:5625: second request should fail. server should be shut down

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`
2023-02-27 11:56 linux-amd64 go@0d52401e net/http.TestServerShutdown (log)
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h1 (0.05s)
        serve_test.go:5625: second request should fail. server should be shut down

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`
2023-03-01 21:50 linux-386-bullseye go@3243f937 net/http.TestServerShutdown (log)
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.20s)
        serve_test.go:5629: second request should fail. server should be shut down

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`
2023-03-13 14:20 dragonfly-amd64-622 go@b6f29d23 net/http.TestServerShutdown (log)
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.06s)
        serve_test.go:5619: second request should fail. server should be shut down

watchflakes

@gopherbot
Copy link
Author

Change https://go.dev/cl/476036 mentions this issue: net/http: avoid making a request to a closed server in TestServerShutdown

@gopherbot
Copy link
Author

Change https://go.dev/cl/483896 mentions this issue: net/http: only report the first leak of each test run

gopherbot pushed a commit that referenced this issue Apr 12, 2023
We don't have a way to terminate the leaked goroutines, and we can't
wait forever for them to exit (or else we would risk timing out the
test and losing the log line describing what exactly leaked).
So we have reason to believe that they will remain leaked while we run
the next test, and we don't want the goroutines from the first leak to
generate a spurious error when the second test completes.

This also removes a racy Parallel call I added in CL 476036, which was
flagged by the race detector in the duplicate-suppression check.
(I hadn't considered the potential interaction with the leak checker.)

For #59526.
Updates #56421.

Change-Id: Ib1f759f102fb41ece114401680cd728343e58545
Reviewed-on: https://go-review.googlesource.com/c/go/+/483896
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Michael Pratt <mpratt@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
Run-TryBot: Bryan Mills <bcmills@google.com>
@gopherbot gopherbot reopened this Nov 7, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`
2023-11-07 17:04 linux-amd64 go@46fb7816 net/http.TestServerShutdown (log)
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h2 (0.06s)
        serve_test.go:5629: second request should fail. server should be shut down

watchflakes

@bcmills
Copy link
Contributor

bcmills commented Nov 8, 2023

The above failure is on release-branch.go1.20 (#59483, #57632).

@bcmills bcmills closed this as completed Nov 8, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerShutdown" && `server should be shut down`
2024-01-09 18:15 linux-amd64-boringcrypto go@a95136a8 net/http.TestServerShutdown (log)
--- FAIL: TestServerShutdown (0.00s)
    --- FAIL: TestServerShutdown/h1 (0.07s)
        serve_test.go:5629: second request should fail. server should be shut down

watchflakes

@bcmills
Copy link
Contributor

bcmills commented Jan 26, 2024

Commit a95136a is also on release-branch.go1.20.

@bcmills bcmills closed this as not planned Won't fix, can't repro, duplicate, stale Jan 26, 2024
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.
Projects
Status: Done
Development

No branches or pull requests

4 participants