net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

bcmills · 2023-08-29T20:42:57Z

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

The goroutine dump from the logs is unfortunately too large to paste in a GitHub issue. 😅

(attn @neild; CC @golang/release)

The text was updated successfully, but these errors were encountered:

mknyszek · 2023-08-30T15:13:26Z

Copying over context from #62363.

I managed to reproduce this on my local linux/amd64 machine on tip, and without GOEXPERIMENT=boringcrypto:

bin/go test -c net/http
stress2 ./http.test -test.run="TestTransportDecrementConnWhenIdleConnRemoved" -test.count=1 -test.timeout=3m

It fails pretty fast; basically as soon as the timeout is reached. Might be able to get a faster turnaround time by lowering the timeout.

EDIT: Switched to stress2 since I couldn't find stress anymore. stress2 is obtainable via go get install github.com/aclements/go-misc/stress2.

gopherbot · 2023-09-08T17:12:22Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-09-05 16:41 freebsd-amd64-13_0 go@a40404da net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved (3m0s)
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (3m0s)

goroutine 16372 [running]:
panic({0x842fc0?, 0xc000714050?})
	/tmp/workdir/go/src/runtime/panic.go:774 +0x158 fp=0xc00083af10 sp=0xc00083ae60 pc=0x437e58
testing.(*M).startAlarm.func1()
	/tmp/workdir/go/src/testing/testing.go:2259 +0x385 fp=0xc00083afe0 sp=0xc00083af10 pc=0x5009a5
runtime.goexit({})
	/tmp/workdir/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00083afe8 sp=0xc00083afe0 pc=0x46d4c1
created by time.goFunc
	/tmp/workdir/go/src/time/sleep.go:177 +0x2d

2023-09-07 01:59 darwin-amd64-11_0 go@3466e573 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved (2m59s)
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m58s)

goroutine 15802 [running]:
panic({0x8bffce0?, 0xc0010d5390?})
	/tmp/buildlet/go/src/runtime/panic.go:774 +0x158 fp=0xc000bd6f10 sp=0xc000bd6e60 pc=0x8723e38
testing.(*M).startAlarm.func1()
	/tmp/buildlet/go/src/testing/testing.go:2259 +0x385 fp=0xc000bd6fe0 sp=0xc000bd6f10 pc=0x87ecaa5
runtime.goexit({})
	/tmp/buildlet/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc000bd6fe8 sp=0xc000bd6fe0 pc=0x875a721
created by time.goFunc
	/tmp/buildlet/go/src/time/sleep.go:177 +0x2d

— watchflakes

gopherbot · 2023-09-11T21:12:54Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-09-11 20:29 linux-amd64-bookworm go@f72693d3 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved (3m0s)
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (3m0s)

goroutine 15734 [running]:
panic({0x845c20?, 0xc00033c600?})
	/workdir/go/src/runtime/panic.go:774 +0x158 fp=0xc00091df10 sp=0xc00091de60 pc=0x438cb8
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2259 +0x385 fp=0xc00091dfe0 sp=0xc00091df10 pc=0x509765
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1650 +0x1 fp=0xc00091dfe8 sp=0xc00091dfe0 pc=0x46ecc1
created by time.goFunc
	/workdir/go/src/time/sleep.go:177 +0x2d

— watchflakes

gopherbot · 2023-10-25T15:05:03Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-10-24 18:12 darwin-amd64-race go@9162c4be net/http (log)

panic: test timed out after 6m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved (5m55s)
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (5m52s)

goroutine 16096 [running]:
panic({0x61b12e0?, 0xc001b10040?})
	/tmp/buildlet/go/src/runtime/panic.go:772 +0x158 fp=0xc001189f18 sp=0xc001189e68 pc=0x5a12358
testing.(*M).startAlarm.func1()
	/tmp/buildlet/go/src/testing/testing.go:2257 +0x214 fp=0xc001189fe0 sp=0xc001189f18 pc=0x5b39f74
runtime.goexit({})
	/tmp/buildlet/go/src/runtime/asm_amd64.s:1671 +0x1 fp=0xc001189fe8 sp=0xc001189fe0 pc=0x5a4ace1
created by time.goFunc
	/tmp/buildlet/go/src/time/sleep.go:177 +0x45

2023-10-24 20:26 linux-s390x-ibm go@9ab51216 net/http (log)

panic: test timed out after 15m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved (14m57s)
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (14m57s)

goroutine 15457 [running]:
panic({0x53a6a0, 0xc0001ac0e0})
	/data/golang/workdir/go/src/runtime/panic.go:772 +0x156 fp=0xc0011aaef8 sp=0xc0011aae50 pc=0x56d26
testing.(*M).startAlarm.func1()
	/data/golang/workdir/go/src/testing/testing.go:2257 +0x464 fp=0xc0011aafd8 sp=0xc0011aaef8 pc=0x157ef4
runtime.goexit({})
	/data/golang/workdir/go/src/runtime/asm_s390x.s:774 +0x2 fp=0xc0011aafd8 sp=0xc0011aafd8 pc=0x993b2
created by time.goFunc
	/data/golang/workdir/go/src/time/sleep.go:177 +0x42

— watchflakes

gopherbot · 2023-11-14T18:39:22Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-11-14 17:15 linux-amd64-buster go@e7d582b5 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved (3m0s)
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m59s)

goroutine 15863 [running]:
panic({0x86a9a0?, 0xc0008d0050?})
	/workdir/go/src/runtime/panic.go:772 +0x158 fp=0xc0013c5f10 sp=0xc0013c5e60 pc=0x4392f8
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2351 +0x374 fp=0xc0013c5fe0 sp=0xc0013c5f10 pc=0x50bbb4
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1694 +0x1 fp=0xc0013c5fe8 sp=0xc0013c5fe0 pc=0x46f7e1
created by time.goFunc
	/workdir/go/src/time/sleep.go:177 +0x2d

— watchflakes

gopherbot · 2023-12-05T00:10:37Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-12-04 19:27 windows-amd64-race go@818de275 net/http (log)

panic: test timed out after 6m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (5m54s)

goroutine 16323 gp=0xc000507d40 m=8 mp=0xc000266708 [running]:
panic({0x140770460?, 0xc0017ec160?})
	C:/workdir/go/src/runtime/panic.go:779 +0x158 fp=0xc000bfdf18 sp=0xc000bfde68 pc=0x14003cf18
testing.(*M).startAlarm.func1()
	C:/workdir/go/src/testing/testing.go:2366 +0x265 fp=0xc000bfdfe0 sp=0xc000bfdf18 pc=0x1401889e5
runtime.goexit({})
...
net/http.(*Client).Get(0xc001902600, {0xc0008226d8, 0x17})
	C:/workdir/go/src/net/http/client.go:487 +0x9a fp=0xc00101be80 sp=0xc00101be08 pc=0x14045647a
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func2()
	C:/workdir/go/src/net/http/transport_test.go:6526 +0x73 fp=0xc00101bf78 sp=0xc00101be80 pc=0x1406b73f3
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func3()
	C:/workdir/go/src/net/http/transport_test.go:6543 +0x82 fp=0xc00101bfe0 sp=0xc00101bf78 pc=0x1406b72e2
runtime.goexit({})
	C:/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00101bfe8 sp=0xc00101bfe0 pc=0x140078981
created by net/http_test.testTransportDecrementConnWhenIdleConnRemoved in goroutine 3319
	C:/workdir/go/src/net/http/transport_test.go:6541 +0x33a

— watchflakes

gopherbot · 2023-12-09T22:16:23Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-12-09 21:47 linux-amd64-alpine go@ca804118 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (3m0s)

goroutine 16099 gp=0xc000656fc0 m=17 mp=0xc000600808 [running]:
panic({0x877180?, 0xc0010c6450?})
	/workdir/go/src/runtime/panic.go:779 +0x158 fp=0xc001c87f10 sp=0xc001c87e60 pc=0x43b018
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc001c87fe0 sp=0xc001c87f10 pc=0x513be5
runtime.goexit({})
...
net/http.(*http2Framer).ReadFrame(0xc0006d80e0)
	/workdir/go/src/net/http/h2_bundle.go:1902 +0x85 fp=0xc0007e2ef8 sp=0xc0007e2e50 pc=0x6c5ea5
net/http.(*http2serverConn).readFrames(0xc000a0e000)
	/workdir/go/src/net/http/h2_bundle.go:4603 +0x87 fp=0xc0007e2fc8 sp=0xc0007e2ef8 pc=0x6cfda7
net/http.(*http2serverConn).serve.gowrap7()
	/workdir/go/src/net/http/h2_bundle.go:4715 +0x25 fp=0xc0007e2fe0 sp=0xc0007e2fc8 pc=0x6d13e5
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0007e2fe8 sp=0xc0007e2fe0 pc=0x4759c1
created by net/http.(*http2serverConn).serve in goroutine 2813
	/workdir/go/src/net/http/h2_bundle.go:4715 +0x56a

— watchflakes

gopherbot · 2023-12-11T18:12:34Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-12-11 17:15 linux-amd64-nocgo go@052d4029 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m59s)

goroutine 15327 gp=0xc000889880 m=13 mp=0xc000206008 [running]:
panic({0x871aa0?, 0xc003818d40?})
	/workdir/go/src/runtime/panic.go:779 +0x158 fp=0xc00223bf10 sp=0xc00223be60 pc=0x4395b8
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc00223bfe0 sp=0xc00223bf10 pc=0x511e45
runtime.goexit({})
...
net/http.(*http2Framer).ReadFrame(0xc0008a27e0)
	/workdir/go/src/net/http/h2_bundle.go:1902 +0x85 fp=0xc0009f3ef8 sp=0xc0009f3e50 pc=0x6c10a5
net/http.(*http2serverConn).readFrames(0xc000b2f380)
	/workdir/go/src/net/http/h2_bundle.go:4603 +0x87 fp=0xc0009f3fc8 sp=0xc0009f3ef8 pc=0x6cafa7
net/http.(*http2serverConn).serve.gowrap7()
	/workdir/go/src/net/http/h2_bundle.go:4715 +0x25 fp=0xc0009f3fe0 sp=0xc0009f3fc8 pc=0x6cc5e5
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0009f3fe8 sp=0xc0009f3fe0 pc=0x473c81
created by net/http.(*http2serverConn).serve in goroutine 3211
	/workdir/go/src/net/http/h2_bundle.go:4715 +0x56a

— watchflakes

gopherbot · 2023-12-12T16:50:42Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-12-11 23:29 windows-amd64-2016 go@b18b0588 net/http (log)

panic: test timed out after 6m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (5m59s)

goroutine 15990 gp=0xc000455340 m=12 mp=0xc0000c2008 [running]:
panic({0xdfc1a0?, 0xc000b3e030?})
	C:/workdir/go/src/runtime/panic.go:779 +0x158 fp=0xc000265f10 sp=0xc000265e60 pc=0x9bb918
testing.(*M).startAlarm.func1()
	C:/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc000265fe0 sp=0xc000265f10 pc=0xa988c5
runtime.goexit({})
...
net/http.(*http2clientConnReadLoop).run(0xc000a13fa8)
	C:/workdir/go/src/net/http/h2_bundle.go:9303 +0x12c fp=0xc000a13f60 sp=0xc000a13df0 pc=0xc6b48c
net/http.(*http2ClientConn).readLoop(0xc00026c180)
	C:/workdir/go/src/net/http/h2_bundle.go:9198 +0x65 fp=0xc000a13fc8 sp=0xc000a13f60 pc=0xc6aa05
net/http.(*http2Transport).newClientConn.gowrap1()
	C:/workdir/go/src/net/http/h2_bundle.go:7848 +0x25 fp=0xc000a13fe0 sp=0xc000a13fc8 pc=0xc64125
runtime.goexit({})
	C:/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000a13fe8 sp=0xc000a13fe0 pc=0x9f5501
created by net/http.(*http2Transport).newClientConn in goroutine 2621
	C:/workdir/go/src/net/http/h2_bundle.go:7848 +0xca6

— watchflakes

gopherbot · 2023-12-13T01:33:43Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-12-13 00:22 solaris-amd64-oraclerel go@400e24a8 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m59s)

goroutine 16229 gp=0xc000c31dc0 m=29 mp=0xc00055e408 [running]:
panic({0x871d40?, 0xc004c26f20?})
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/panic.go:779 +0x158 fp=0xc001c57f10 sp=0xc001c57e60 pc=0x43a978
testing.(*M).startAlarm.func1()
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/testing/testing.go:2366 +0x385 fp=0xc001c57fe0 sp=0xc001c57f10 pc=0x50a4c5
runtime.goexit({})
...
net/http.(*Client).Get(0xc000dc2840, {0xc0006141f8?, 0x0?})
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/client.go:487 +0x5f fp=0xc000435f10 sp=0xc000435ec0 pc=0x6b0bbf
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func2()
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport_test.go:6526 +0x4c fp=0xc000435fb0 sp=0xc000435f10 pc=0x82918c
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func3()
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport_test.go:6543 +0x50 fp=0xc000435fe0 sp=0xc000435fb0 pc=0x8290b0
runtime.goexit({})
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000435fe8 sp=0xc000435fe0 pc=0x474ee1
created by net/http_test.testTransportDecrementConnWhenIdleConnRemoved in goroutine 2531
	/tmp/workdir-host-solaris-oracle-amd64-oraclerel/go/src/net/http/transport_test.go:6541 +0x1be

— watchflakes

gopherbot · 2024-01-08T19:16:34Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2024-01-08 18:26 dragonfly-amd64-622 go@75984918 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m58s)

goroutine 16096 gp=0xc00034bdc0 m=11 mp=0xc000585008 [running]:
panic({0x874360?, 0xc00109ced0?})
	/tmp/workdir/go/src/runtime/panic.go:779 +0x158 fp=0xc000739f10 sp=0xc000739e60 pc=0x439758
testing.(*M).startAlarm.func1()
	/tmp/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc000739fe0 sp=0xc000739f10 pc=0x5090e5
runtime.goexit({})
...
net/http.(*http2clientConnReadLoop).run(0xc000721fa8)
	/tmp/workdir/go/src/net/http/h2_bundle.go:9303 +0x12c fp=0xc000721f60 sp=0xc000721df0 pc=0x6e29ec
net/http.(*http2ClientConn).readLoop(0xc000206480)
	/tmp/workdir/go/src/net/http/h2_bundle.go:9198 +0x65 fp=0xc000721fc8 sp=0xc000721f60 pc=0x6e1f65
net/http.(*http2Transport).newClientConn.gowrap1()
	/tmp/workdir/go/src/net/http/h2_bundle.go:7848 +0x25 fp=0xc000721fe0 sp=0xc000721fc8 pc=0x6db685
runtime.goexit({})
	/tmp/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000721fe8 sp=0xc000721fe0 pc=0x473481
created by net/http.(*http2Transport).newClientConn in goroutine 3062
	/tmp/workdir/go/src/net/http/h2_bundle.go:7848 +0xca6

— watchflakes

gopherbot · 2024-01-19T20:06:44Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`

2023-12-11 21:37 gotip-linux-amd64-boringcrypto go@c22781cb net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

gopherbot · 2024-01-25T18:08:37Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-22 19:00 gotip-linux-arm64 go@3e54329c net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

2024-01-24 07:25 gotip-linux-arm64 go@b4e7d630 net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

gopherbot · 2024-01-25T22:48:09Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-04 20:45 go1.22-openbsd-amd64 release-branch.go1.22@ead47b0a net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 [ABORT] (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

gopherbot · 2024-01-26T05:03:36Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-26 04:31 linux-amd64-bookworm go@3dcdc09c net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m59s)

goroutine 15577 gp=0xc000191c00 m=22 mp=0xc00036d808 [running]:
panic({0x8781a0?, 0xc0012cc8e0?})
	/workdir/go/src/runtime/panic.go:768 +0x158 fp=0xc0008a9f10 sp=0xc0008a9e60 pc=0x43afb8
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc0008a9fe0 sp=0xc0008a9f10 pc=0x513c85
runtime.goexit({})
...
net/http.(*Client).Get(0xc000df92c0, {0xc0016440f0?, 0x7878787878787878?})
	/workdir/go/src/net/http/client.go:487 +0x5f fp=0xc000a57f10 sp=0xc000a57ec0 pc=0x6b6aff
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func2()
	/workdir/go/src/net/http/transport_test.go:6526 +0x4c fp=0xc000a57fb0 sp=0xc000a57f10 pc=0x82ff4c
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func3()
	/workdir/go/src/net/http/transport_test.go:6543 +0x50 fp=0xc000a57fe0 sp=0xc000a57fb0 pc=0x82fe70
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000a57fe8 sp=0xc000a57fe0 pc=0x475a41
created by net/http_test.testTransportDecrementConnWhenIdleConnRemoved in goroutine 2538
	/workdir/go/src/net/http/transport_test.go:6541 +0x1be

— watchflakes

gopherbot · 2024-01-26T16:48:24Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-26 14:04 linux-amd64-staticlockranking go@8e02e7b2 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m59s)

goroutine 13918 gp=0xc000a8e700 m=0 mp=0xcdd3a0 [running]:
panic({0x87a1a0?, 0xc001d56040?})
	/workdir/go/src/runtime/panic.go:768 +0x158 fp=0xc0005eef10 sp=0xc0005eee60 pc=0x43ce38
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc0005eefe0 sp=0xc0005eef10 pc=0x515fc5
runtime.goexit({})
...
net/http.(*Client).Get(0xc001162360, {0xc0004e0630?, 0x7878787878787878?})
	/workdir/go/src/net/http/client.go:487 +0x5f fp=0xc000f97f10 sp=0xc000f97ec0 pc=0x6b8e3f
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func2()
	/workdir/go/src/net/http/transport_test.go:6526 +0x4c fp=0xc000f97fb0 sp=0xc000f97f10 pc=0x8322cc
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func3()
	/workdir/go/src/net/http/transport_test.go:6543 +0x50 fp=0xc000f97fe0 sp=0xc000f97fb0 pc=0x8321f0
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000f97fe8 sp=0xc000f97fe0 pc=0x477d81
created by net/http_test.testTransportDecrementConnWhenIdleConnRemoved in goroutine 2593
	/workdir/go/src/net/http/transport_test.go:6541 +0x1be

— watchflakes

gopherbot · 2024-01-30T15:49:07Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-29 22:55 gotip-openbsd-amd64 go@0c64be46 net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 [ABORT] (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

gopherbot · 2024-01-31T23:03:15Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-31 20:51 linux-amd64-nocgo go@5c0d0929 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (3m0s)

goroutine 15916 gp=0xc000337c00 m=0 mp=0xccd280 [running]:
panic({0x872ac0?, 0xc001cf5220?})
	/workdir/go/src/runtime/panic.go:768 +0x158 fp=0xc000b43f10 sp=0xc000b43e60 pc=0x439738
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc000b43fe0 sp=0xc000b43f10 pc=0x512225
runtime.goexit({})
...
net/http.(*http2Framer).ReadFrame(0xc000d9c2a0)
	/workdir/go/src/net/http/h2_bundle.go:1902 +0x85 fp=0xc00044bef8 sp=0xc00044be50 pc=0x6c1445
net/http.(*http2serverConn).readFrames(0xc0007ac9c0)
	/workdir/go/src/net/http/h2_bundle.go:4602 +0x87 fp=0xc00044bfc8 sp=0xc00044bef8 pc=0x6cb347
net/http.(*http2serverConn).serve.gowrap7()
	/workdir/go/src/net/http/h2_bundle.go:4714 +0x25 fp=0xc00044bfe0 sp=0xc00044bfc8 pc=0x6cc985
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00044bfe8 sp=0xc00044bfe0 pc=0x474061
created by net/http.(*http2serverConn).serve in goroutine 4065
	/workdir/go/src/net/http/h2_bundle.go:4714 +0x56a

— watchflakes

gopherbot · 2024-02-02T15:49:34Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-02-02 15:13 linux-amd64-alpine go@244ccf47 net/http (log)

panic: test timed out after 3m0s
running tests:
	TestTransportDecrementConnWhenIdleConnRemoved/h2 (2m59s)

goroutine 15930 gp=0xc0001ed6c0 m=7 mp=0xc0004a0008 [running]:
panic({0x878120?, 0xc001944780?})
	/workdir/go/src/runtime/panic.go:768 +0x158 fp=0xc000a2ff10 sp=0xc000a2fe60 pc=0x43b178
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:2366 +0x385 fp=0xc000a2ffe0 sp=0xc000a2ff10 pc=0x5140a5
runtime.goexit({})
...
net/http.(*Client).Get(0xc000ed72f0, {0xc0005fa948?, 0x73e8d7f0ed5524bb?})
	/workdir/go/src/net/http/client.go:487 +0x5f fp=0xc002ec9f10 sp=0xc002ec9ec0 pc=0x6b6ebf
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func2()
	/workdir/go/src/net/http/transport_test.go:6526 +0x4c fp=0xc002ec9fb0 sp=0xc002ec9f10 pc=0x82feac
net/http_test.testTransportDecrementConnWhenIdleConnRemoved.func3()
	/workdir/go/src/net/http/transport_test.go:6543 +0x50 fp=0xc002ec9fe0 sp=0xc002ec9fb0 pc=0x82fdd0
runtime.goexit({})
	/workdir/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc002ec9fe8 sp=0xc002ec9fe0 pc=0x475e81
created by net/http_test.testTransportDecrementConnWhenIdleConnRemoved in goroutine 3119
	/workdir/go/src/net/http/transport_test.go:6541 +0x1be

— watchflakes

gopherbot · 2024-02-02T18:42:36Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-01-31 19:22 gotip-linux-amd64-newinliner go@600225f8 net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 [ABORT] (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

gopherbot · 2024-02-05T17:18:07Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-02-02 23:14 gotip-openbsd-amd64 go@b8ac61e6 net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 [ABORT] (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

gopherbot · 2024-02-15T19:42:38Z

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" &&
	((log ~ `running tests:\n\s*TestTransportDecrementConnWhenIdleConnRemoved` && log ~ `panic: test timed out`) ||
		(test ~ `TestTransportDecrementConnWhenIdleConnRemoved` && status == "ABORT"))

2024-02-12 22:38 gotip-darwin-arm64_12 go@e45c262f net/http.TestTransportDecrementConnWhenIdleConnRemoved/h2 [ABORT] (log)

=== RUN   TestTransportDecrementConnWhenIdleConnRemoved/h2
=== PAUSE TestTransportDecrementConnWhenIdleConnRemoved/h2
=== CONT  TestTransportDecrementConnWhenIdleConnRemoved/h2

— watchflakes

bcmills · 2024-02-15T21:16:15Z

Also https://ci.chromium.org/ui/inv/build-8756698374321080385/test-results (a TryBot on an unrelated CL).

@neild, given the high failure rate, can we prioritize either a fix or a skip for this test?

bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 29, 2023

bcmills added this to the Backlog milestone Aug 29, 2023

bcmills mentioned this issue Aug 30, 2023

net/http: TestTransportDecrementConnWhenIdleConnRemoved/h2 times out #62363

Closed

dmitshur changed the title ~~net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved on LUCI builders~~ net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved Oct 26, 2023

bcmills mentioned this issue Feb 21, 2024

x/build: timeout on LUCI openbsd-amd64 builder #65311

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

bcmills commented Aug 29, 2023 •

edited by cherrymui

mknyszek commented Aug 30, 2023 •

edited

gopherbot commented Sep 8, 2023

gopherbot commented Sep 11, 2023

gopherbot commented Oct 25, 2023

gopherbot commented Nov 14, 2023

gopherbot commented Dec 5, 2023

gopherbot commented Dec 9, 2023

gopherbot commented Dec 11, 2023

gopherbot commented Dec 12, 2023

gopherbot commented Dec 13, 2023

gopherbot commented Jan 8, 2024

gopherbot commented Jan 19, 2024

gopherbot commented Jan 25, 2024

gopherbot commented Jan 25, 2024

gopherbot commented Jan 26, 2024

gopherbot commented Jan 26, 2024

gopherbot commented Jan 30, 2024

gopherbot commented Jan 31, 2024

gopherbot commented Feb 2, 2024

gopherbot commented Feb 2, 2024

gopherbot commented Feb 5, 2024

gopherbot commented Feb 15, 2024

bcmills commented Feb 15, 2024

net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

Comments

bcmills commented Aug 29, 2023 • edited by cherrymui

mknyszek commented Aug 30, 2023 • edited

gopherbot commented Sep 8, 2023

gopherbot commented Sep 11, 2023

gopherbot commented Oct 25, 2023

gopherbot commented Nov 14, 2023

gopherbot commented Dec 5, 2023

gopherbot commented Dec 9, 2023

gopherbot commented Dec 11, 2023

gopherbot commented Dec 12, 2023

gopherbot commented Dec 13, 2023

gopherbot commented Jan 8, 2024

gopherbot commented Jan 19, 2024

gopherbot commented Jan 25, 2024

gopherbot commented Jan 25, 2024

gopherbot commented Jan 26, 2024

gopherbot commented Jan 26, 2024

gopherbot commented Jan 30, 2024

gopherbot commented Jan 31, 2024

gopherbot commented Feb 2, 2024

gopherbot commented Feb 2, 2024

gopherbot commented Feb 5, 2024

gopherbot commented Feb 15, 2024

bcmills commented Feb 15, 2024

bcmills commented Aug 29, 2023 •

edited by cherrymui

mknyszek commented Aug 30, 2023 •

edited