Skip to content
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.

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

net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

Open
bcmills opened this issue Aug 29, 2023 · 6 comments
Open

net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved #62357

bcmills opened this issue Aug 29, 2023 · 6 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@bcmills
Copy link
Member

bcmills commented Aug 29, 2023 •
edited 

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

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

(attn @neild; CC @golang/release)
@bcmills 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 bcmills added this to the Backlog milestone Aug 29, 2023
@bcmills bcmills mentioned this issue Aug 30, 2023
Closed
@mknyszek
Copy link
Contributor

mknyszek commented Aug 30, 2023 •
edited

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
Copy link

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
Copy link

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
Copy link

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

@dmitshur dmitshur changed the title net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved on LUCI builders net/http: apparent deadlock in TestTransportDecrementConnWhenIdleConnRemoved Oct 26, 2023
@gopherbot
Copy link

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
Copy link

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

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: Active
Milestone
Backlog
Development

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