Navigation Menu

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: TestServerConnState failures #56577

Closed
gopherbot opened this issue Nov 4, 2022 · 21 comments
Closed

net/http: TestServerConnState failures #56577

gopherbot opened this issue Nov 4, 2022 · 21 comments
Labels
NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone

Comments

@gopherbot
Copy link

gopherbot commented Nov 4, 2022

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState" && date < "2023-08-01"

Issue created automatically to collect these failures.

Example (log):

2022/10/31 15:11:39 http2: server: error reading preface from client 127.0.0.1:49554: local error: tls: bad record MAC
2022/10/31 15:11:41 http2: server: error reading preface from client 127.0.0.1:49237: bogus greeting "CONNECT golang.fake.tld:"
2022/10/31 15:11:41 http2: server: error reading preface from client 127.0.0.1:49214: bogus greeting "CONNECT golang.fake.tld:"
2022/10/31 15:11:51 http: TLS handshake error from 127.0.0.1:64615: write tcp 127.0.0.1:64616->127.0.0.1:64615: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64613: write tcp 127.0.0.1:64614->127.0.0.1:64613: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64610: write tcp 127.0.0.1:64611->127.0.0.1:64610: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64607: read tcp 127.0.0.1:64608->127.0.0.1:64607: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64605: write tcp 127.0.0.1:64606->127.0.0.1:64605: i/o timeout
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.46s)
...
2022/10/31 15:12:07 http: TLS handshake error from 127.0.0.1:64414: read tcp 127.0.0.1:64419->127.0.0.1:64414: use of closed network connection
2022/10/31 15:12:08 http: TLS handshake error from 127.0.0.1:64417: write tcp 127.0.0.1:64419->127.0.0.1:64417: use of closed network connection
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64083: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64082: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64081: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64076: read tcp 127.0.0.1:64084->127.0.0.1:64076: read: connection reset by peer
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64071: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64068: read tcp 127.0.0.1:64072->127.0.0.1:64068: read: connection reset by peer
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64067: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64066: EOF

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 Nov 4, 2022
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2022-10-31 12:52 netbsd-arm-bsiegert go@6774ddfe net/http.TestServerConnState (log)
2022/10/31 15:11:39 http2: server: error reading preface from client 127.0.0.1:49554: local error: tls: bad record MAC
2022/10/31 15:11:41 http2: server: error reading preface from client 127.0.0.1:49237: bogus greeting "CONNECT golang.fake.tld:"
2022/10/31 15:11:41 http2: server: error reading preface from client 127.0.0.1:49214: bogus greeting "CONNECT golang.fake.tld:"
2022/10/31 15:11:51 http: TLS handshake error from 127.0.0.1:64615: write tcp 127.0.0.1:64616->127.0.0.1:64615: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64613: write tcp 127.0.0.1:64614->127.0.0.1:64613: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64610: write tcp 127.0.0.1:64611->127.0.0.1:64610: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64607: read tcp 127.0.0.1:64608->127.0.0.1:64607: i/o timeout
2022/10/31 15:11:52 http: TLS handshake error from 127.0.0.1:64605: write tcp 127.0.0.1:64606->127.0.0.1:64605: i/o timeout
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.46s)
...
2022/10/31 15:12:07 http: TLS handshake error from 127.0.0.1:64414: read tcp 127.0.0.1:64419->127.0.0.1:64414: use of closed network connection
2022/10/31 15:12:08 http: TLS handshake error from 127.0.0.1:64417: write tcp 127.0.0.1:64419->127.0.0.1:64417: use of closed network connection
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64083: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64082: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64081: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64076: read tcp 127.0.0.1:64084->127.0.0.1:64076: read: connection reset by peer
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64071: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64068: read tcp 127.0.0.1:64072->127.0.0.1:64068: read: connection reset by peer
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64067: EOF
2022/10/31 15:12:19 http: TLS handshake error from 127.0.0.1:64066: EOF

watchflakes

@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 == "TestServerConnState"
2022-12-01 21:00 darwin-amd64-race go@cd133abc net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.02s)
    --- FAIL: TestServerConnState/h1 (0.27s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2022-12-02 16:30 openbsd-arm64-jsing go@d71b1c3d net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (1.36s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@prattmic
Copy link
Member

prattmic commented Dec 7, 2022

cc @neild

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2022-12-07 23:52 darwin-amd64-10_15 go@9431237d net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.22s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4268: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2022-12-06 05:12 freebsd-arm-paulzhol go@1eb0465f net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (1.66s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4268: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
1 second passes in backend, proxygone= false
2022-12-06 22:07 darwin-amd64-nocgo go@e535d677 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.30s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4268: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2022-12-07 03:45 darwin-amd64-13 go@a3989632 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.22s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2022-12-01 22:04 freebsd-arm-paulzhol go@6a70292d net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (7.63s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2022-12-02 16:29 freebsd-arm-paulzhol go@1711f953 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (1.25s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2022-12-02 16:30 darwin-amd64-race go@5a4e440f net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.28s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2022-12-19 21:17 freebsd-arm-paulzhol go@a5a47442 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (1.43s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
1 second passes in backend, proxygone= false
1 second passes in backend, proxygone= false

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-01-09 20:25 openbsd-arm64-jsing go@d9f23cfe net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.44s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-01-17 15:26 openbsd-386-71 go@66689c7d net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.33s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2023-01-23 20:59 darwin-amd64-11_0 go@24233701 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.29s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4268: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
        serve_test.go:4227: unexpected conn in state closed
2023-01-24 19:11 netbsd-arm64-bsiegert go@02704d51 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.26s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4268: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-01-31 18:11 darwin-amd64-13 go@1fc585dc net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.29s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4273: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2023-02-01 19:47 linux-amd64-race go@ab0f0459 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-02-07 22:22 freebsd-amd64-race go@9565d990 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-02-28 01:11 darwin-amd64-10_15 go@dd16258f net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.45s)
        serve_test.go:4223: unexpected conn in state new
        serve_test.go:4223: unexpected conn in state active
        serve_test.go:4223: unexpected conn in state closed
        serve_test.go:4269: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-03-10 17:02 darwin-amd64-nocgo go@49588d0c net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.23s)
        serve_test.go:4217: unexpected conn in state new
        serve_test.go:4217: unexpected conn in state active
        serve_test.go:4217: unexpected conn in state closed
        serve_test.go:4258: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-03-13 18:55 darwin-amd64-11_0 go@778627f3 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.36s)
        serve_test.go:4217: unexpected conn in state new
        serve_test.go:4217: unexpected conn in state active
        serve_test.go:4217: unexpected conn in state closed
        serve_test.go:4263: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]
2023/03/13 15:17:49 httptest.Server blocked in Close after 5 seconds, waiting for connections:
  *tls.Conn 0xc0008fa700 127.0.0.1:51174 in state active

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-03-13 17:03 darwin-amd64-race go@e671fe0c net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.01s)
    --- FAIL: TestServerConnState/h1 (0.35s)
        serve_test.go:4217: unexpected conn in state new
        serve_test.go:4217: unexpected conn in state active
        serve_test.go:4217: unexpected conn in state closed
        serve_test.go:4258: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-03-21 20:55 darwin-arm64-11 go@f9a4cfd5 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.13s)
        serve_test.go:4124: unexpected conn in state new
        serve_test.go:4124: unexpected conn in state active
        serve_test.go:4124: unexpected conn in state closed
        serve_test.go:4170: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-03-29 22:56 darwin-amd64-nocgo go@6a51c000 net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.42s)
        serve_test.go:4124: unexpected conn in state new
        serve_test.go:4124: unexpected conn in state active
        serve_test.go:4124: unexpected conn in state closed
        serve_test.go:4165: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot
Copy link
Author

Change https://go.dev/cl/483116 mentions this issue: net/http: wait forever for write results in tests

@dmitshur dmitshur added NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels May 24, 2023
@dmitshur dmitshur modified the milestones: Unplanned, Go1.21 May 24, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-05-30 16:25 darwin-amd64-11_0 go@4b95fc1e net/http.TestServerConnState (log)
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.41s)
        serve_test.go:4227: unexpected conn in state new
        serve_test.go:4227: unexpected conn in state active
        serve_test.go:4227: unexpected conn in state closed
        serve_test.go:4268: Request(s) produced unexpected state sequence.
            Got:  [new active idle closed]
            Want: [new active idle active closed]

watchflakes

@gopherbot gopherbot reopened this May 31, 2023
@gopherbot gopherbot modified the milestones: Go1.21, Go1.22 Aug 8, 2023
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerConnState"
2023-08-14 21:10 plan9-arm go@d788b27c net/http.TestServerConnState (log)
http.test 35798: warning: process exceeds 100 file descriptors
--- FAIL: TestServerConnState (0.00s)
    --- FAIL: TestServerConnState/h1 (0.59s)
        serve_test.go:4175: Error fetching http://127.0.0.1:62676/: Get "http://127.0.0.1:62676/": dial tcp 127.0.0.1:62676: open /net/tcp/clone: '/net/tcp/clone' does not exist
        serve_test.go:4174: Request(s) produced unexpected state sequence.
            Got:  [new active closed]
            Want: [new active idle active closed]

watchflakes

@dmitshur
Copy link
Contributor

Commit 4b95fc1 was on release-branch.go1.20.
Commit d788b27 is on the main branch and looks like a different failure mode.

@bcmills bcmills closed this as completed Aug 29, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsFix The path to resolution is known, but the work has not been done. 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

5 participants