net/http: TestTransportRemovesH2ConnsAfterIdle/h2 failures

[gopherbot]

#!watchflakes
default <- pkg == "net/http" && test == "TestTransportRemovesH2ConnsAfterIdle/h2"

Issue created automatically to collect these failures.

Example (log):

=== RUN   TestTransportRemovesH2ConnsAfterIdle/h2
2024/11/22 02:11:36 Error enabling Transport HTTP/2 support: protocol https already registered
    transport_test.go:4259: got error: Get "https://127.0.0.1:46039": http2: client conn could not be established
--- FAIL: TestTransportRemovesH2ConnsAfterIdle/h2 (0.01s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "net/http" && test == "TestTransportRemovesH2ConnsAfterIdle/h2"

2024-11-22 02:04 gotip-linux-amd64-longtest-noswissmap go@d524c954 net/http.TestTransportRemovesH2ConnsAfterIdle/h2 (log)

=== RUN   TestTransportRemovesH2ConnsAfterIdle/h2
2024/11/22 02:11:36 Error enabling Transport HTTP/2 support: protocol https already registered
    transport_test.go:4259: got error: Get "https://127.0.0.1:46039": http2: client conn could not be established
--- FAIL: TestTransportRemovesH2ConnsAfterIdle/h2 (0.01s)

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "net/http" && test == "TestTransportRemovesH2ConnsAfterIdle/h2"

2024-11-22 03:48 gotip-linux-386-longtest go@b299e9a4 net/http.TestTransportRemovesH2ConnsAfterIdle/h2 (log)

=== RUN   TestTransportRemovesH2ConnsAfterIdle/h2
2024/11/22 03:58:57 Error enabling Transport HTTP/2 support: protocol https already registered
    transport_test.go:4259: got error: Get "https://127.0.0.1:40031": http2: client conn could not be established
--- FAIL: TestTransportRemovesH2ConnsAfterIdle/h2 (0.05s)

— watchflakes

[dmitshur]

These "Error enabling Transport HTTP/2 support: protocol https already registered" errors may be fairly new, and if so maybe related to recent net/http changes. Also seeing them in #70299. CC @neild.

[gopherbot]

Change https://go.dev/cl/631795 mentions this issue: net/http: test for racing idle conn closure and new requests

[neild]

This is caused by a bug introduced in https://go.dev/cl/625398:

As of that CL, when a client connection encounters an error prior to the first request being sent on it, we fail that request. For example, if the server immediately closes a new connection before we have a chance to send a request, we treat that as a failure on the assumption that trying again will get the same result. (Previously, we'd say "oh, we don't have any usable connections", and retry on a new connection--which would probably fail again in the same way.)

The bug is that when the connection idle timer races with the first request on a connection, this can result in that first request failing. This is unlikely to happen in the real world, since it requires a very short idle timer and a new connection which has somehow made it into the pool without being used. Even in tests, it requires some fairly unlucky timing to appear.

[gopherbot]

Change https://go.dev/cl/631815 mentions this issue: http2: do not surface errors from a conn's idle timer expiring