net/http: "Test appears to have leaked a Transport" on darwin-amd64-longtest

[prattmic]

The new darwin-amd64-longtest builders (#35678) are failing continuously with "Test appears to have leaked a Transport" errors, either in TestTransportPrefersResponseOverWriteError/h1 (5/6 failures) or TestMaxBytesHandler/max_size_100_request_size_1000000/h1 (1/6 failures):

2023-04-10T18:52:58-65ea4c5/darwin-amd64-longtest
2023-04-10T17:30:27-5e93a2c/darwin-amd64-longtest
2023-04-10T17:13:41-63a08e6/darwin-amd64-longtest
2023-04-10T17:07:24-a3f3868/darwin-amd64-longtest
2023-04-10T17:06:55-60140a8/darwin-amd64-longtest
2023-04-10T15:57:38-9efca84/darwin-amd64-longtest

The only other failures I see like this in fetchlogs are from 2020, so too old to be obviously related.

cc @neild @bcmills

[prattmic]

For reference, the bug for the 2020 failures was #42943

[prattmic]

This bug easily reproduces on a darwin-amd64-13 gomote, simply by running go test net/http. It also reproduces with filtering (-run TestTransportPrefersResponseOverWriteError/h1).

The full set of failures I get in net/http:

--- FAIL: TestTransportPrefersResponseOverWriteError (6.94s)
    --- FAIL: TestTransportPrefersResponseOverWriteError/h1 (3.85s)
    --- FAIL: TestTransportPrefersResponseOverWriteError/h2 (3.09s)
--- FAIL: TestTransportReuseConnEmptyResponseBody (6.04s)
    --- FAIL: TestTransportReuseConnEmptyResponseBody/h1 (3.04s)
    --- FAIL: TestTransportReuseConnEmptyResponseBody/h2 (3.00s)

(TestMaxBytesHandler suspiciously missing)

[bcmills]

TestTransportPrefersResponseOverWriteError does seem to be leaky: it fires off a bunch of requests for which the server writes an error response without reading the request body to completion.

For those requests, c.Do(req) will return as soon as the server response arrives, even though the request processing hasn't finished yet.

Perhaps the solution is to wrap the strings.Reader with a Close method that calls wg.Done() on a sync.WaitGroup? Then the test could wait for all of the request bodies to be closed before returning. (That's probably close enough timing-wise to not trigger the leak check.)

[bcmills]

I'm not sure what's going on with TestTransportReuseConnEmptyResponseBody, since that request doesn't seem to involve writing a request body. 🤔

[bcmills]

TestMaxBytesHandler has the same issue as TestTransportPrefersResponseOverWriteError: it creates a request that will be rejected by the server before the body has been read, which on the client side leaks the Write goroutine.

It can be fixed in the same way: by adding a Close method to the body that synchronizes with the return from the test function.

[earthboundkid]

I think I wrote TestMaxBytesHandler. As I recall I just copypasta’d another test. Sorry if it’s buggy! 😓

[bcmills]

FWIW, watchflakes found TestMaxBytesHandler in #57612.

[gopherbot]

Change https://go.dev/cl/483895 mentions this issue: net/http: avoid leaking writer goroutines in tests

[bcmills]

I think failures reported in TestTransportReuseConnEmptyResponseBody are a red herring. As far as I can tell, the goroutines reported as “leaked” there are the ones from TestTransportPrefersResponseOverWriteError.

Probably the leak check should just be disabled after the first report.

[gopherbot]

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