net/http: unexplained timeout on `wasip1/wasm`

[gopherbot]

#!watchflakes
default <- goarch == "wasm" && pkg == "net/http" && log ~ `panic: test timed out`

Issue created automatically to collect these failures.

Example (log):

panic: test timed out after 3m0s
running tests:
	TestClientRedirectNoLocation (2m49s)
	TestClientRedirectNoLocation/h1 (2m20s)
	TestClientRedirectNoLocation/h2 (2m20s)
	TestConnContextNotModifyingAllContexts (2m48s)
	TestContentEncodingNoSniffing (2m48s)
	TestContentTypeWithVariousSources (2m48s)
	TestDisableContentLength (2m48s)
	TestDisableKeepAliveUpgrade (2m48s)
...
net/http_test.run[...].func1()
	/workdir/go/src/net/http/clientserver_test.go:85 +0xa fp=0x21ddf60 sp=0x21ddf10 pc=0x3407000a
testing.tRunner(0x22e7380, 0x1ad8900)
	/workdir/go/src/testing/testing.go:1682 +0xd fp=0x21ddfc8 sp=0x21ddf60 pc=0x1add000d
testing.(*T).Run.gowrap1()
	/workdir/go/src/testing/testing.go:1735 +0x2 fp=0x21ddfe0 sp=0x21ddfc8 pc=0x1ae30002
runtime.goexit({})
	/workdir/go/src/runtime/asm_wasm.s:434 +0x1 fp=0x21ddfe8 sp=0x21ddfe0 pc=0x151b0001
created by testing.(*T).Run in goroutine 1250
	/workdir/go/src/testing/testing.go:1735 +0x43

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

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

2023-11-21 21:28 wasip1-wasm-wazero go@d1dcffdb net/http (log)

panic: test timed out after 3m0s
running tests:
	TestClientRedirectNoLocation (2m49s)
	TestClientRedirectNoLocation/h1 (2m20s)
	TestClientRedirectNoLocation/h2 (2m20s)
	TestConnContextNotModifyingAllContexts (2m48s)
	TestContentEncodingNoSniffing (2m48s)
	TestContentTypeWithVariousSources (2m48s)
	TestDisableContentLength (2m48s)
	TestDisableKeepAliveUpgrade (2m48s)
...
net/http_test.run[...].func1()
	/workdir/go/src/net/http/clientserver_test.go:85 +0xa fp=0x21ddf60 sp=0x21ddf10 pc=0x3407000a
testing.tRunner(0x22e7380, 0x1ad8900)
	/workdir/go/src/testing/testing.go:1682 +0xd fp=0x21ddfc8 sp=0x21ddf60 pc=0x1add000d
testing.(*T).Run.gowrap1()
	/workdir/go/src/testing/testing.go:1735 +0x2 fp=0x21ddfe0 sp=0x21ddfc8 pc=0x1ae30002
runtime.goexit({})
	/workdir/go/src/runtime/asm_wasm.s:434 +0x1 fp=0x21ddfe8 sp=0x21ddfe0 pc=0x151b0001
created by testing.(*T).Run in goroutine 1250
	/workdir/go/src/testing/testing.go:1735 +0x43

— watchflakes

[bcmills]

This may be a bug in https://go.dev/cl/526117. I will investigate.

(CC @golang/wasm)

[bcmills]

Note that the actual interestingly-running test here is:

	TestTransportExpect100Continue/h1 (2s)

(Filed #64404 for the unclear logging.)

[bcmills]

Given that there was a test that had only been running for 2s, it seems like the test must have hung somewhere else for a long time. Unassigning to collect more data and look for a pattern.

(CC @neild)

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- goarch == "wasm" && pkg == "net/http" && log ~ `panic: test timed out`

2023-12-07 19:52 gotip-wasip1-wasm_wazero go@e1c0349a net/http.TestIssue4191_InfiniteGetTimeout (log)

=== RUN   TestIssue4191_InfiniteGetTimeout/h1
=== PAUSE TestIssue4191_InfiniteGetTimeout/h1
=== CONT  TestIssue4191_InfiniteGetTimeout/h1
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetTimeout/h1 (2m4s)

goroutine 15243 gp=0x1a94380 m=0 mp=0x7130a0 [running]:
panic({0x4fe60, 0x4ee5780})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x1f fp=0x23e7f00 sp=0x23e7e58 pc=0x1293001f
...
net/http_test.run[...].func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/net/http/clientserver_test.go:85 +0xa fp=0x21c5f60 sp=0x21c5f10 pc=0x3449000a
testing.tRunner(0x2843860, 0x18ca840)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1689 +0xd fp=0x21c5fc8 sp=0x21c5f60 pc=0x1b1f000d
testing.(*T).Run.gowrap1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x2 fp=0x21c5fe0 sp=0x21c5fc8 pc=0x1b250002
runtime.goexit({})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_wasm.s:434 +0x1 fp=0x21c5fe8 sp=0x21c5fe0 pc=0x15580001
created by testing.(*T).Run in goroutine 1250
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x43

2024-01-08 17:02 gotip-wasip1-wasm_wazero go@10a66d68 net/http.TestIssue4191_InfiniteGetTimeout (log)

=== RUN   TestIssue4191_InfiniteGetTimeout/h1
=== PAUSE TestIssue4191_InfiniteGetTimeout/h1
=== CONT  TestIssue4191_InfiniteGetTimeout/h1
panic: test timed out after 3m0s
running tests:
	TestIssue4191_InfiniteGetTimeout/h1 (2m2s)

goroutine 15301 gp=0x21d6a80 m=0 mp=0x714160 [running]:
panic({0x4fe60, 0x19143a0})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/panic.go:779 +0x1f fp=0x23e9f00 sp=0x23e9e58 pc=0x1293001f
...
net/http_test.run[...].func1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/net/http/clientserver_test.go:85 +0xa fp=0x21f1f60 sp=0x21f1f10 pc=0x344a000a
testing.tRunner(0x23df860, 0x2098840)
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1689 +0xd fp=0x21f1fc8 sp=0x21f1f60 pc=0x1b1f000d
testing.(*T).Run.gowrap1()
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x2 fp=0x21f1fe0 sp=0x21f1fc8 pc=0x1b250002
runtime.goexit({})
	/home/swarming/.swarming/w/ir/x/w/goroot/src/runtime/asm_wasm.s:434 +0x1 fp=0x21f1fe8 sp=0x21f1fe0 pc=0x15580001
created by testing.(*T).Run in goroutine 1251
	/home/swarming/.swarming/w/ir/x/w/goroot/src/testing/testing.go:1742 +0x43

— watchflakes

[bcmills]

The above seems like a different failure mode; filed as #65177.