Skip to content

net/http: TestServerCancelsReadTimeoutWhenIdle failures #57602

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.

Sign up for GitHub

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

Jump to bottom
Open
gopherbot opened this issue Jan 4, 2023 · 15 comments
Open

net/http: TestServerCancelsReadTimeoutWhenIdle failures #57602

gopherbot opened this issue Jan 4, 2023 · 15 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@gopherbot
Copy link
Contributor

gopherbot commented Jan 4, 2023 •
edited by bcmills
Loading 

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`

Issue created automatically to collect these failures.

Example (log):

--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (4.61s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50635: read tcp 127.0.0.1:50636->127.0.0.1:50635: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50633: write tcp 127.0.0.1:50634->127.0.0.1:50633: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50619: write tcp 127.0.0.1:50620->127.0.0.1:50619: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50617: write tcp 127.0.0.1:50618->127.0.0.1:50617: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50610: read tcp 127.0.0.1:50611->127.0.0.1:50610: i/o timeout
        serve_test.go:5853: failed with duration 2s: Get: Get "https://127.0.0.1:50611": unexpected 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 Jan 4, 2023
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle"
2022-11-30 17:03 netbsd-arm-bsiegert go@60525dc3 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (4.61s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50635: read tcp 127.0.0.1:50636->127.0.0.1:50635: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50633: write tcp 127.0.0.1:50634->127.0.0.1:50633: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50619: write tcp 127.0.0.1:50620->127.0.0.1:50619: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50617: write tcp 127.0.0.1:50618->127.0.0.1:50617: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:50610: read tcp 127.0.0.1:50611->127.0.0.1:50610: i/o timeout
        serve_test.go:5853: failed with duration 2s: Get: Get "https://127.0.0.1:50611": unexpected EOF

— watchflakes

@bcmills
Copy link
Contributor

bcmills commented Jan 6, 2023

2s is the longest of the (still arbitrary) timeouts in this list:
https://cs.opensource.google/go/go/+/master:src/net/http/serve_test.go;l=5761;drc=21015cf6baed45a1e7c3d1a0dfe34c778140344f

But the test is only setting ts.Config.ReadTimeout — so why is the write operation in the TLS handshake also timing out? 🤔

(CC @neild)

@bcmills bcmills added this to the Backlog milestone Jan 6, 2023
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle"
2023-01-30 08:01 freebsd-arm-paulzhol go@932d0ae8 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (5.31s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24225: write tcp 127.0.0.1:24224->127.0.0.1:24225: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24229: write tcp 127.0.0.1:24228->127.0.0.1:24229: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24239: write tcp 127.0.0.1:24236->127.0.0.1:24239: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24244: write tcp 127.0.0.1:24242->127.0.0.1:24244: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24275: write tcp 127.0.0.1:24274->127.0.0.1:24275: i/o timeout
        serve_test.go:5853: failed with duration 2s: Get: Get "https://127.0.0.1:24274": EOF
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h1 (5.40s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24223: write tcp 127.0.0.1:24222->127.0.0.1:24223: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24227: write tcp 127.0.0.1:24226->127.0.0.1:24227: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24235: write tcp 127.0.0.1:24234->127.0.0.1:24235: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24243: write tcp 127.0.0.1:24241->127.0.0.1:24243: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:24273: write tcp 127.0.0.1:24272->127.0.0.1:24273: i/o timeout
        serve_test.go:5853: failed with duration 2s: Get: Get "https://127.0.0.1:24272": EOF
2023-01-31 13:55 freebsd-arm-paulzhol go@da0c375c net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (6.53s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:10703: write tcp 127.0.0.1:10702->127.0.0.1:10703: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:10709: write tcp 127.0.0.1:10708->127.0.0.1:10709: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:10716: write tcp 127.0.0.1:10715->127.0.0.1:10716: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:10720: write tcp 127.0.0.1:10719->127.0.0.1:10720: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:10728: read tcp 127.0.0.1:10727->127.0.0.1:10728: i/o timeout
        serve_test.go:5853: failed with duration 2s: Get: Get "https://127.0.0.1:10727": write tcp 127.0.0.1:10728->127.0.0.1:10727: write: broken pipe
2023-02-01 19:47 linux-amd64-race go@ab0f0459 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2023-02-07 23:39 freebsd-arm-paulzhol go@0b9974d3 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (5.78s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:52276: write tcp 127.0.0.1:52274->127.0.0.1:52276: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:52284: write tcp 127.0.0.1:52282->127.0.0.1:52284: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:52295: write tcp 127.0.0.1:52293->127.0.0.1:52295: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:52306: write tcp 127.0.0.1:52305->127.0.0.1:52306: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:52350: write tcp 127.0.0.1:52349->127.0.0.1:52350: i/o timeout
        serve_test.go:5849: failed with duration 2s: Get: Get "https://127.0.0.1:52349": EOF

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2023-02-17 00:06 freebsd-arm-paulzhol go@031401a7 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (8.05s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60521: write tcp 127.0.0.1:60520->127.0.0.1:60521: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60529: write tcp 127.0.0.1:60528->127.0.0.1:60529: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60543: write tcp 127.0.0.1:60538->127.0.0.1:60543: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60562: write tcp 127.0.0.1:60561->127.0.0.1:60562: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60564: read tcp 127.0.0.1:60563->127.0.0.1:60564: i/o timeout
        serve_test.go:5849: failed with duration 2s: Get: Get "https://127.0.0.1:60563": write tcp 127.0.0.1:60564->127.0.0.1:60563: write: broken pipe
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h1 (8.93s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60517: write tcp 127.0.0.1:60516->127.0.0.1:60517: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60527: write tcp 127.0.0.1:60526->127.0.0.1:60527: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60534: write tcp 127.0.0.1:60530->127.0.0.1:60534: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60560: write tcp 127.0.0.1:60559->127.0.0.1:60560: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:60566: read tcp 127.0.0.1:60565->127.0.0.1:60566: i/o timeout
        serve_test.go:5849: failed with duration 2s: Get: Get "https://127.0.0.1:60565": write tcp 127.0.0.1:60566->127.0.0.1:60565: write: broken pipe

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2023-03-07 18:26 freebsd-arm-paulzhol go@74a9d283 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (4.69s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19760: read tcp 127.0.0.1:19757->127.0.0.1:19760: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19763: write tcp 127.0.0.1:19762->127.0.0.1:19763: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19769: write tcp 127.0.0.1:19768->127.0.0.1:19769: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19776: write tcp 127.0.0.1:19773->127.0.0.1:19776: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19816: write tcp 127.0.0.1:19815->127.0.0.1:19816: i/o timeout
        serve_test.go:5849: failed with duration 2s: Get: Get "https://127.0.0.1:19815": EOF
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h1 (5.54s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19751: write tcp 127.0.0.1:19750->127.0.0.1:19751: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19759: write tcp 127.0.0.1:19754->127.0.0.1:19759: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19767: write tcp 127.0.0.1:19765->127.0.0.1:19767: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19774: write tcp 127.0.0.1:19772->127.0.0.1:19774: i/o timeout
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:19818: write tcp 127.0.0.1:19817->127.0.0.1:19818: i/o timeout
        serve_test.go:5849: failed with duration 2s: Get: Get "https://127.0.0.1:19817": EOF

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2023-09-15 23:22 freebsd-arm-paulzhol go@561a5079 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (11.10s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:44949: read tcp 127.0.0.1:44947->127.0.0.1:44949: i/o timeout
        serve_test.go:5814: retrying after error with duration 10ms: Get: Get "https://127.0.0.1:44947": read tcp 127.0.0.1:44949->127.0.0.1:44947: read: connection reset by peer
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:44951: write tcp 127.0.0.1:44950->127.0.0.1:44951: i/o timeout
        serve_test.go:5814: retrying after error with duration 50ms: Get: Get "https://127.0.0.1:44950": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:44954: write tcp 127.0.0.1:44952->127.0.0.1:44954: i/o timeout
        serve_test.go:5814: retrying after error with duration 250ms: Get: Get "https://127.0.0.1:44952": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:44970: write tcp 127.0.0.1:44961->127.0.0.1:44970: i/o timeout
        serve_test.go:5814: retrying after error with duration 1s: Get: Get "https://127.0.0.1:44961": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:45004: write tcp 127.0.0.1:45003->127.0.0.1:45004: i/o timeout
        serve_test.go:5812: failed with duration 2s: Get: Get "https://127.0.0.1:45003": EOF

— watchflakes

@gopherbot
Copy link
Contributor Author

Change https://go.dev/cl/529755 mentions this issue: net/http: eliminate a goroutine leak in (*persistConn.addTLS)

gopherbot pushed a commit that referenced this issue Sep 20, 2023
@gopherbot
net/http: eliminate a goroutine leak in (*persistConn.addTLS)
b6e83f3 
In case of a handshake timeout, the goroutine running addTLS
closes the underlying connection, which should unblock the call
to tlsConn.HandshakeContext. However, it didn't then wait for
HandshakeContext to actually return.

I thought this might have something to do with #57602, but as
far as I can tell it does not. Still, it seems best to avoid the leak:
if tracing is enabled we emit a TLSHandshakeDone event, and it seems
misleading to produce that event when the handshake is still in
progress.

For #57602.

Change-Id: Ibfc0cf4ef8df2ccf11d8897f23d7d79ee482d5fb
Reviewed-on: https://go-review.googlesource.com/c/go/+/529755
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Damien Neil <dneil@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
Commit-Queue: Bryan Mills <bcmills@google.com>
@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2023-12-08 20:36 freebsd-arm-paulzhol go@b55bf2d7 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (7.89s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:43761: read tcp 127.0.0.1:43760->127.0.0.1:43761: i/o timeout
        serve_test.go:5842: retrying after error with duration 10ms: Get: Get "https://127.0.0.1:43760": read tcp 127.0.0.1:43761->127.0.0.1:43760: read: connection reset by peer
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:43768: write tcp 127.0.0.1:43764->127.0.0.1:43768: i/o timeout
        serve_test.go:5842: retrying after error with duration 50ms: Get: Get "https://127.0.0.1:43764": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:43798: read tcp 127.0.0.1:43791->127.0.0.1:43798: i/o timeout
        serve_test.go:5842: retrying after error with duration 250ms: Get: Get "https://127.0.0.1:43791": read tcp 127.0.0.1:43798->127.0.0.1:43791: read: connection reset by peer
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:43802: write tcp 127.0.0.1:43801->127.0.0.1:43802: i/o timeout
        serve_test.go:5842: retrying after error with duration 1s: Get: Get "https://127.0.0.1:43801": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:43825: write tcp 127.0.0.1:43824->127.0.0.1:43825: i/o timeout
        serve_test.go:5840: failed with duration 2s: Get: Get "https://127.0.0.1:43824": EOF

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2023-12-11 22:29 freebsd-arm-paulzhol go@a839ec1e net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (6.49s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:46074: read tcp 127.0.0.1:46072->127.0.0.1:46074: i/o timeout
        serve_test.go:5842: retrying after error with duration 10ms: Get: Get "https://127.0.0.1:46072": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:46077: write tcp 127.0.0.1:46076->127.0.0.1:46077: i/o timeout
        serve_test.go:5842: retrying after error with duration 50ms: Get: Get "https://127.0.0.1:46076": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:46092: write tcp 127.0.0.1:46091->127.0.0.1:46092: i/o timeout
        serve_test.go:5842: retrying after error with duration 250ms: Get: Get "https://127.0.0.1:46091": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:46098: read tcp 127.0.0.1:46096->127.0.0.1:46098: i/o timeout
        serve_test.go:5842: retrying after error with duration 1s: Get: Get "https://127.0.0.1:46096": write tcp 127.0.0.1:46098->127.0.0.1:46096: write: broken pipe
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:46107: write tcp 127.0.0.1:46106->127.0.0.1:46107: i/o timeout
        serve_test.go:5840: failed with duration 2s: Get: Get "https://127.0.0.1:46106": EOF

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2024-01-12 16:19 freebsd-arm-paulzhol go@e58e8139 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (7.47s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:28969: write tcp 127.0.0.1:28968->127.0.0.1:28969: i/o timeout
        serve_test.go:5842: retrying after error with duration 10ms: Get: Get "https://127.0.0.1:28968": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:28982: write tcp 127.0.0.1:28981->127.0.0.1:28982: i/o timeout
        serve_test.go:5842: retrying after error with duration 50ms: Get: Get "https://127.0.0.1:28981": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:28995: write tcp 127.0.0.1:28994->127.0.0.1:28995: i/o timeout
        serve_test.go:5842: retrying after error with duration 250ms: Get: Get "https://127.0.0.1:28994": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:28998: read tcp 127.0.0.1:28996->127.0.0.1:28998: i/o timeout
        serve_test.go:5842: retrying after error with duration 1s: Get: Get "https://127.0.0.1:28996": unexpected EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:29030: write tcp 127.0.0.1:29029->127.0.0.1:29030: i/o timeout
        serve_test.go:5840: failed with duration 2s: Get: Get "https://127.0.0.1:29029": EOF

— watchflakes

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2024-02-10 02:03 freebsd-arm-paulzhol go@a1878904 net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (5.33s)
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:25293: read tcp 127.0.0.1:25292->127.0.0.1:25293: i/o timeout
        serve_test.go:5846: retrying after error with duration 10ms: Get: Get "https://127.0.0.1:25292": read tcp 127.0.0.1:25293->127.0.0.1:25292: read: connection reset by peer
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:25302: write tcp 127.0.0.1:25298->127.0.0.1:25302: i/o timeout
        serve_test.go:5846: retrying after error with duration 50ms: Get: Get "https://127.0.0.1:25298": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:25306: write tcp 127.0.0.1:25305->127.0.0.1:25306: i/o timeout
        serve_test.go:5846: retrying after error with duration 250ms: Get: Get "https://127.0.0.1:25305": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:25311: write tcp 127.0.0.1:25308->127.0.0.1:25311: i/o timeout
        serve_test.go:5846: retrying after error with duration 1s: Get: Get "https://127.0.0.1:25308": EOF
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:25317: read tcp 127.0.0.1:25316->127.0.0.1:25317: i/o timeout
        serve_test.go:5844: failed with duration 2s: Get: Get "https://127.0.0.1:25316": write tcp 127.0.0.1:25317->127.0.0.1:25316: write: broken pipe

— watchflakes

@bcmills
Copy link
Contributor

bcmills commented Feb 13, 2024

@paulzhol, there are a lot of these on the freebsd-arm-paulzhol builder. Maybe something to look into?

@paulzhol
Copy link
Member

The last 3 appear to be almost a month apart from each other on a Friday/Saturday, which is the weekend for me here.
I might be hogging the internet which has been a mobile CNAT for a while now.
I'll try to be more aware to the fact and maybe shut down the builder at those times.

@gopherbot
Copy link
Contributor Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && test == "TestServerCancelsReadTimeoutWhenIdle" && `failed with duration`
2024-03-26 21:33 freebsd-arm-paulzhol go@b47f2feb net/http.TestServerCancelsReadTimeoutWhenIdle (log) 
--- FAIL: TestServerCancelsReadTimeoutWhenIdle (0.00s)
    --- FAIL: TestServerCancelsReadTimeoutWhenIdle/h2 (7.16s)
        serve_test.go:5889: Server.Config.ReadTimeout = 10ms
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:14038: write tcp 127.0.0.1:14037->127.0.0.1:14038: i/o timeout
        serve_test.go:5985: retrying after error with duration 10ms: Get: Get "https://127.0.0.1:14037": EOF
        serve_test.go:5889: Server.Config.ReadTimeout = 50ms
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:14045: write tcp 127.0.0.1:14044->127.0.0.1:14045: i/o timeout
        serve_test.go:5985: retrying after error with duration 50ms: Get: Get "https://127.0.0.1:14044": EOF
        serve_test.go:5889: Server.Config.ReadTimeout = 250ms
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:14073: write tcp 127.0.0.1:14072->127.0.0.1:14073: i/o timeout
        serve_test.go:5985: retrying after error with duration 250ms: Get: Get "https://127.0.0.1:14072": EOF
        serve_test.go:5889: Server.Config.ReadTimeout = 1s
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:14077: read tcp 127.0.0.1:14076->127.0.0.1:14077: i/o timeout
        serve_test.go:5985: retrying after error with duration 1s: Get: Get "https://127.0.0.1:14076": unexpected EOF
        serve_test.go:5889: Server.Config.ReadTimeout = 2s
        clientserver_test.go:210: server log: http: TLS handshake error from 127.0.0.1:14103: write tcp 127.0.0.1:14102->127.0.0.1:14103: i/o timeout
        serve_test.go:5983: failed with duration 2s: Get: Get "https://127.0.0.1:14102": EOF

— watchflakes

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Test Flakes
Status: No status
Milestone
Backlog
Development

No branches or pull requests
3 participants
@paulzhol @bcmills @gopherbot