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

runtime: test frequently times out after 10 minutes on linux-amd64-longtest builder #25886

Closed
mvdan opened this issue Jun 14, 2018 · 22 comments
Closed
Labels
Builders x/build issues (builders, bots, dashboards) FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Milestone

Comments

@mvdan
Copy link
Member

mvdan commented Jun 14, 2018

For example: https://build.golang.org/log/9b5c6ae2c5be87e49c9893e9ea6dcc2aa6198200

The builder has been consistently broken for this and other reasons since mid-May, so it's hard to pinpoint when this failure started happening. I tried looking for an existing issue about this, but couldn't find any.

If I run go test -v runtime on my laptop, I get the result:

ok      runtime 171.977s

Perhaps the three-minute timeout per package is too low for the runtime package, seeing as how my run barely fit under 180s. Or perhaps some of the long or expensive tests should be made faster.

/cc @aclements @ianlancetaylor @bradfitz

Tangential question - should this be labelled Testing or Builders? Perhaps the label descriptions could be clarified.

@mvdan mvdan added Testing An issue that has been verified to require only test changes, not just a test failure. NeedsFix The path to resolution is known, but the work has not been done. labels Jun 14, 2018
@mvdan mvdan added this to the Go1.11 milestone Jun 14, 2018
@ALTree
Copy link
Member

ALTree commented Jun 14, 2018

I bumped the timeout to 6 minutes in CL 115016.

Either I did it wrong or it's not deployed yet.

@ALTree
Copy link
Member

ALTree commented Jun 14, 2018

p.s. I thinks this should be labeled "builders".

@mvdan
Copy link
Member Author

mvdan commented Jun 14, 2018

Ah, I forgot to remove the is:open filter from my issue search. It didn't occur to me that the issue was already closed. I naively assumed that it couldn't have been, since the problem is still present :)

Then yes, this seems like it should be labelled Builders. Do you want to keep this issue open to track the deployment/debugging of your fix?

@mvdan mvdan added Builders x/build issues (builders, bots, dashboards) and removed Testing An issue that has been verified to require only test changes, not just a test failure. labels Jun 14, 2018
@mvdan mvdan changed the title runtime: tests consistently timing out after 3m on linux-amd64-longtest x/build: linux-amd64-longtest still timing out on the runtime tests Jun 14, 2018
@ALTree
Copy link
Member

ALTree commented Jun 14, 2018

Do you want to keep this issue open to track the deployment/debugging of your fix?

I guess we could do this to avoid someone else opening another one : ) Once the version with the new time limit is deployed we can close.

@ianlancetaylor ianlancetaylor modified the milestones: Go1.11, Go1.12 Jun 29, 2018
@bradfitz bradfitz changed the title x/build: linux-amd64-longtest still timing out on the runtime tests runtime: linux-amd64-longtest builder failing Aug 29, 2018
@mvdan
Copy link
Member Author

mvdan commented Sep 28, 2018

We're closer - now it only fails most of the time. When it does fail, it seems like the usual culprit is:

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
panic: test timed out after 10m0s

@bcmills bcmills added the Testing An issue that has been verified to require only test changes, not just a test failure. label Jan 8, 2019
@bcmills
Copy link
Contributor

bcmills commented Jan 8, 2019

Those timeouts seem to be fairly frequent. Two recent examples:
https://build.golang.org/log/dd99567c4f2f016a14ab11e6e937ffce023c597a
https://build.golang.org/log/c61b77bdccf2b21024b0029704f224f71a04864f

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
panic: test timed out after 10m0s

goroutine 77960537 [running]:
panic(0x692300, 0xc0000747b0)
	/workdir/go/src/runtime/panic.go:565 +0x2c5 fp=0xc0006faf88 sp=0xc0006faef8 pc=0x42fb45
testing.(*M).startAlarm.func1()
	/workdir/go/src/testing/testing.go:1331 +0xdf fp=0xc0006fafe0 sp=0xc0006faf88 pc=0x4f91bf
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0006fafe8 sp=0xc0006fafe0 pc=0x461ec1
created by time.goFunc
	/workdir/go/src/time/sleep.go:169 +0x44

goroutine 1 [chan receive, locked to thread]:
runtime.gopark(0x711190, 0xc0000645f8, 0x170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000040be8 sp=0xc000040bc8 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0000645a0, 0x0, 0xc000cacb01, 0xc0007f0101)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc000040c78 sp=0xc000040be8 pc=0x4077b0
runtime.chanrecv1(0xc0000645a0, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc000040ca8 sp=0xc000040c78 pc=0x40748b
testing.tRunner.func1(0xc0006dc000)
	/workdir/go/src/testing/testing.go:838 +0x1f5 fp=0xc000040d28 sp=0xc000040ca8 pc=0x4f8de5
testing.tRunner(0xc0006dc000, 0xc000040de0)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000040d50 sp=0xc000040d28 pc=0x4f4e0a
testing.runTests(0xc000080220, 0x94f040, 0x112, 0x112, 0x0)
	/workdir/go/src/testing/testing.go:1152 +0x2a9 fp=0xc000040e10 sp=0xc000040d50 pc=0x4f6629
testing.(*M).Run(0xc0000be200, 0x0)
	/workdir/go/src/testing/testing.go:1069 +0x162 fp=0xc000040ee0 sp=0xc000040e10 pc=0x4f55b2
runtime_test.TestMain(0xc0000be200)
	/workdir/go/src/runtime/crash_test.go:28 +0x2f fp=0xc000040f30 sp=0xc000040ee0 pc=0x602d8f
main.main()
	_testmain.go:1054 +0x13e fp=0xc000040f98 sp=0xc000040f30 pc=0x66228e
runtime.main()
	/workdir/go/src/runtime/proc.go:200 +0x20c fp=0xc000040fe0 sp=0xc000040f98 pc=0x43184c
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000040fe8 sp=0xc000040fe0 pc=0x461ec1

goroutine 2 [force gc (idle), 2 minutes]:
runtime.gopark(0x711190, 0x9518b0, 0x1410, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000032fb0 sp=0xc000032f90 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.forcegchelper()
	/workdir/go/src/runtime/proc.go:250 +0xb7 fp=0xc000032fe0 sp=0xc000032fb0 pc=0x431ae7
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000032fe8 sp=0xc000032fe0 pc=0x461ec1
created by runtime.init.5
	/workdir/go/src/runtime/proc.go:239 +0x35

goroutine 3 [GC sweep wait]:
runtime.gopark(0x711190, 0x951cc0, 0x140c, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0000337a8 sp=0xc000033788 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.bgsweep(0xc000016070)
	/workdir/go/src/runtime/mgcsweep.go:89 +0x134 fp=0xc0000337d8 sp=0xc0000337a8 pc=0x423cc4
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0000337e0 sp=0xc0000337d8 pc=0x461ec1
created by runtime.gcenable
	/workdir/go/src/runtime/mgc.go:208 +0x58

goroutine 18 [finalizer wait]:
runtime.gopark(0x711190, 0x96df60, 0xc00001140f, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00045bf58 sp=0xc00045bf38 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.runfinq()
	/workdir/go/src/runtime/mfinal.go:175 +0xa6 fp=0xc00045bfe0 sp=0xc00045bf58 pc=0x41a936
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00045bfe8 sp=0xc00045bfe0 pc=0x461ec1
created by runtime.createfing
	/workdir/go/src/runtime/mfinal.go:156 +0x61

goroutine 19 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955840, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00002e760 sp=0xc00002e740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955840)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc00002e7d8 sp=0xc00002e760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00002e7e0 sp=0xc00002e7d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 9 [syscall]:
runtime.notetsleepg(0x9557e0, 0x84d28747c, 0x0)
	/workdir/go/src/runtime/lock_futex.go:227 +0x34 fp=0xc000033f60 sp=0xc000033f30 pc=0x40cca4
runtime.timerproc(0x9557c0)
	/workdir/go/src/runtime/time.go:311 +0x2ea fp=0xc000033fd8 sp=0xc000033f60 pc=0x44f18a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000033fe0 sp=0xc000033fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 35 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x9558c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000112760 sp=0xc000112740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9558c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0001127d8 sp=0xc000112760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0001127e0 sp=0xc0001127d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 61 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955940, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000121760 sp=0xc000121740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955940)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0001217d8 sp=0xc000121760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0001217e0 sp=0xc0001217d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 215 [GC worker (idle)]:
runtime.gopark(0x710fe0, 0xc000276020, 0x401417, 0x0)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000035760 sp=0xc000035740 pc=0x431c3f
runtime.gcBgMarkWorker(0xc000020000)
	/workdir/go/src/runtime/mgc.go:1836 +0xff fp=0xc0000357d8 sp=0xc000035760 pc=0x41e3df
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0000357e0 sp=0xc0000357d8 pc=0x461ec1
created by runtime.gcBgMarkStartWorkers
	/workdir/go/src/runtime/mgc.go:1784 +0x77

goroutine 72987001 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000113da8 sp=0xc000113d88 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc000113e01, 0xc000113e80)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc000113e38 sp=0xc000113da8 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc000113e68 sp=0xc000113e38 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc000113e90 sp=0xc000113e68 pc=0x4f5385
testing.(*T).Parallel(0xc0000d8100)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc000113f18 sp=0xc000113e90 pc=0x4f4b61
runtime_test.testConcurrentReadsAfterGrowth(0xc0000d8100, 0x1811d099201)
	/workdir/go/src/runtime/map_test.go:315 +0x2f fp=0xc000113f88 sp=0xc000113f18 pc=0x62355f
runtime_test.TestConcurrentReadsAfterGrowthReflect(0xc0000d8100)
	/workdir/go/src/runtime/map_test.go:365 +0x30 fp=0xc000113fa8 sp=0xc000113f88 pc=0x623840
testing.tRunner(0xc0000d8100, 0x711f68)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc000113fd0 sp=0xc000113fa8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000113fd8 sp=0xc000113fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72986986 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0006fb5a8 sp=0xc0006fb588 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc0006fb601, 0xc0006fb680)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc0006fb638 sp=0xc0006fb5a8 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc0006fb668 sp=0xc0006fb638 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc0006fb690 sp=0xc0006fb668 pc=0x4f5385
testing.(*T).Parallel(0xc00070a100)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc0006fb718 sp=0xc0006fb690 pc=0x4f4b61
runtime_test.testConcurrentReadsAfterGrowth(0xc00070a100, 0x1811d07a600)
	/workdir/go/src/runtime/map_test.go:315 +0x2f fp=0xc0006fb788 sp=0xc0006fb718 pc=0x62355f
runtime_test.TestConcurrentReadsAfterGrowth(0xc00070a100)
	/workdir/go/src/runtime/map_test.go:361 +0x30 fp=0xc0006fb7a8 sp=0xc0006fb788 pc=0x6237f0
testing.tRunner(0xc00070a100, 0x711f70)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc0006fb7d0 sp=0xc0006fb7a8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0006fb7d8 sp=0xc0006fb7d0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72986851 [chan send]:
runtime.gopark(0x711190, 0xc0000648f8, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000062e70 sp=0xc000062e50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0000648a0, 0xc000062f5f, 0xc00070a901, 0x4f8e54, 0xc00070a900)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000062ef0 sp=0xc000062e70 pc=0x406bae
runtime.chansend1(0xc0000648a0, 0xc000062f5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000062f28 sp=0xc000062ef0 pc=0x406975
testing.tRunner.func1(0xc00070a900)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000062fa8 sp=0xc000062f28 pc=0x4f8e54
testing.tRunner(0xc00070a900, 0x711f78)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000062fd0 sp=0xc000062fa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000062fd8 sp=0xc000062fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72987017 [running]:
	goroutine running on other thread; stack unavailable
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77950033 [chan send]:
runtime.gopark(0x711190, 0xc0007f9078, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000824e70 sp=0xc000824e50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0007f9020, 0xc000824f5f, 0xc0000d9d01, 0x4f8e54, 0xc0000d9d00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000824ef0 sp=0xc000824e70 pc=0x406bae
runtime.chansend1(0xc0007f9020, 0xc000a97f5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000824f28 sp=0xc000824ef0 pc=0x406975
testing.tRunner.func1(0xc0000d9d00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000824fa8 sp=0xc000824f28 pc=0x4f8e54
testing.tRunner(0xc0000d9d00, 0x712150)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000824fd0 sp=0xc000824fa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000824fd8 sp=0xc000824fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72986844 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d00530 sp=0xc000d00510 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc000d00601, 0xc000d00608)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc000d005c0 sp=0xc000d00530 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc000d005f0 sp=0xc000d005c0 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc000d00618 sp=0xc000d005f0 pc=0x4f5385
testing.(*T).Parallel(0xc0000d8d00)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc000d006a0 sp=0xc000d00618 pc=0x4f4b61
runtime_test.TestPanicSystemstack(0xc0000d8d00)
	/workdir/go/src/runtime/crash_unix_test.go:185 +0x67 fp=0xc000d007a8 sp=0xc000d006a0 pc=0x60a4e7
testing.tRunner(0xc0000d8d00, 0x7124d8)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc000d007d0 sp=0xc000d007a8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d007d8 sp=0xc000d007d0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72987034 [chan send]:
runtime.gopark(0x711190, 0xc0007f8598, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000fbae70 sp=0xc000fbae50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0007f8540, 0xc000fbaf5f, 0xc00070ad01, 0x4f8e54, 0xc00070ad00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000fbaef0 sp=0xc000fbae70 pc=0x406bae
runtime.chansend1(0xc0007f8540, 0xc000fbaf5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000fbaf28 sp=0xc000fbaef0 pc=0x406975
testing.tRunner.func1(0xc00070ad00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000fbafa8 sp=0xc000fbaf28 pc=0x4f8e54
testing.tRunner(0xc00070ad00, 0x712398)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000fbafd0 sp=0xc000fbafa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000fbafd8 sp=0xc000fbafd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77950055 [chan send]:
runtime.gopark(0x711190, 0xc0010a05f8, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00054fe70 sp=0xc00054fe50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0010a05a0, 0xc00054ff5f, 0xc000358e01, 0x4f8e54, 0xc000358e00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc00054fef0 sp=0xc00054fe70 pc=0x406bae
runtime.chansend1(0xc0010a05a0, 0xc00054ff5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc00054ff28 sp=0xc00054fef0 pc=0x406975
testing.tRunner.func1(0xc000358e00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc00054ffa8 sp=0xc00054ff28 pc=0x4f8e54
testing.tRunner(0xc000358e00, 0x712160)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc00054ffd0 sp=0xc00054ffa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00054ffd8 sp=0xc00054ffd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77959265 [GC worker (idle)]:
runtime.gopark(0x710fe0, 0xc000c74160, 0xc000451417, 0x0)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00045d760 sp=0xc00045d740 pc=0x431c3f
runtime.gcBgMarkWorker(0xc000022500)
	/workdir/go/src/runtime/mgc.go:1836 +0xff fp=0xc00045d7d8 sp=0xc00045d760 pc=0x41e3df
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00045d7e0 sp=0xc00045d7d8 pc=0x461ec1
created by runtime.gcBgMarkStartWorkers
	/workdir/go/src/runtime/mgc.go:1784 +0x77

goroutine 77950032 [chan send]:
runtime.gopark(0x711190, 0xc0007f8fb8, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000fbde70 sp=0xc000fbde50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0007f8f60, 0xc000fbdf5f, 0xc0000d9c01, 0x4f8e54, 0xc0000d9c00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000fbdef0 sp=0xc000fbde70 pc=0x406bae
runtime.chansend1(0xc0007f8f60, 0xc0009b5f5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000fbdf28 sp=0xc000fbdef0 pc=0x406975
testing.tRunner.func1(0xc0000d9c00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000fbdfa8 sp=0xc000fbdf28 pc=0x4f8e54
testing.tRunner(0xc0000d9c00, 0x712148)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000fbdfd0 sp=0xc000fbdfa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000fbdfd8 sp=0xc000fbdfd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 26068834 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955b40, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d43f60 sp=0xc000d43f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955b40)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000d43fd8 sp=0xc000d43f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d43fe0 sp=0xc000d43fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068780 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955bc0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d34760 sp=0xc000d34740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955bc0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000d347d8 sp=0xc000d34760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d347e0 sp=0xc000d347d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068758 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955ac0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003ccf60 sp=0xc0003ccf40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955ac0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0003ccfd8 sp=0xc0003ccf60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003ccfe0 sp=0xc0003ccfd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 25968470 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x9559c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0002fbf60 sp=0xc0002fbf40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9559c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0002fbfd8 sp=0xc0002fbf60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0002fbfe0 sp=0xc0002fbfd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068882 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955ec0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003caf60 sp=0xc0003caf40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955ec0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0003cafd8 sp=0xc0003caf60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003cafe0 sp=0xc0003cafd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 72987033 [chan send]:
runtime.gopark(0x711190, 0xc0007f84d8, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000045e70 sp=0xc000045e50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0007f8480, 0xc000045f5f, 0xc00070ac01, 0x4f8e54, 0xc00070ac00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000045ef0 sp=0xc000045e70 pc=0x406bae
runtime.chansend1(0xc0007f8480, 0xc000045f5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000045f28 sp=0xc000045ef0 pc=0x406975
testing.tRunner.func1(0xc00070ac00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000045fa8 sp=0xc000045f28 pc=0x4f8e54
testing.tRunner(0xc00070ac00, 0x712390)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000045fd0 sp=0xc000045fa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000045fd8 sp=0xc000045fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 25968454 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955a40, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003f6760 sp=0xc0003f6740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955a40)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0003f67d8 sp=0xc0003f6760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003f67e0 sp=0xc0003f67d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068898 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955f40, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00002ff60 sp=0xc00002ff40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955f40)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc00002ffd8 sp=0xc00002ff60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00002ffe0 sp=0xc00002ffd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068914 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955d40, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d1f760 sp=0xc000d1f740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955d40)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000d1f7d8 sp=0xc000d1f760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d1f7e0 sp=0xc000d1f7d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069538 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9565c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00075ff60 sp=0xc00075ff40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9565c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc00075ffd8 sp=0xc00075ff60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00075ffe0 sp=0xc00075ffd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068930 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955dc0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000031f60 sp=0xc000031f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955dc0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000031fd8 sp=0xc000031f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000031fe0 sp=0xc000031fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069138 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956240, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000122760 sp=0xc000122740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956240)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0001227d8 sp=0xc000122760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0001227e0 sp=0xc0001227d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068946 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955c40, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003c7760 sp=0xc0003c7740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955c40)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0003c77d8 sp=0xc0003c7760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003c77e0 sp=0xc0003c77d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26068978 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955cc0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d10f60 sp=0xc000d10f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955cc0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000d10fd8 sp=0xc000d10f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d10fe0 sp=0xc000d10fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 77950056 [chan send]:
runtime.gopark(0x711190, 0xc0010a06b8, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000047e70 sp=0xc000047e50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0010a0660, 0xc000047f5f, 0xc000358f01, 0x4f8e54, 0xc000358f00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000047ef0 sp=0xc000047e70 pc=0x406bae
runtime.chansend1(0xc0010a0660, 0xc000c49f5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000047f28 sp=0xc000047ef0 pc=0x406975
testing.tRunner.func1(0xc000358f00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000047fa8 sp=0xc000047f28 pc=0x4f8e54
testing.tRunner(0xc000358f00, 0x712140)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000047fd0 sp=0xc000047fa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000047fd8 sp=0xc000047fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 26068962 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955e40, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000cfef60 sp=0xc000cfef40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955e40)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000cfefd8 sp=0xc000cfef60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000cfefe0 sp=0xc000cfefd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069026 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x955fc0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000264760 sp=0xc000264740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x955fc0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0002647d8 sp=0xc000264760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0002647e0 sp=0xc0002647d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069042 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9560c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000262f60 sp=0xc000262f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9560c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000262fd8 sp=0xc000262f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000262fe0 sp=0xc000262fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069058 [timer goroutine (idle)]:
runtime.gopark(0x711190, 0x956040, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000cf7760 sp=0xc000cf7740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956040)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000cf77d8 sp=0xc000cf7760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000cf77e0 sp=0xc000cf77d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069074 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956140, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d30f60 sp=0xc000d30f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956140)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000d30fd8 sp=0xc000d30f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d30fe0 sp=0xc000d30fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069090 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9561c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000d33f60 sp=0xc000d33f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9561c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000d33fd8 sp=0xc000d33f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000d33fe0 sp=0xc000d33fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069730 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956740, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000686f60 sp=0xc000686f40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956740)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc000686fd8 sp=0xc000686f60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000686fe0 sp=0xc000686fd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069250 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9562c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00045c760 sp=0xc00045c740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9562c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc00045c7d8 sp=0xc00045c760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00045c7e0 sp=0xc00045c7d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069266 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956340, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00045cf60 sp=0xc00045cf40 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956340)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc00045cfd8 sp=0xc00045cf60 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00045cfe0 sp=0xc00045cfd8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 72986884 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0007085a0 sp=0xc000708580 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc000708601, 0xc000708678)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc000708630 sp=0xc0007085a0 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc000708660 sp=0xc000708630 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc000708688 sp=0xc000708660 pc=0x4f5385
testing.(*T).Parallel(0xc000359e00)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc000708710 sp=0xc000708688 pc=0x4f4b61
runtime_test.TestNetpollDeadlock(0xc000359e00)
	/workdir/go/src/runtime/crash_test.go:405 +0x40 fp=0xc0007087a8 sp=0xc000708710 pc=0x605f70
testing.tRunner(0xc000359e00, 0x7123e8)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc0007087d0 sp=0xc0007087a8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0007087d8 sp=0xc0007087d0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 26069410 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9563c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003d2760 sp=0xc0003d2740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9563c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0003d27d8 sp=0xc0003d2760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003d27e0 sp=0xc0003d27d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069426 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956540, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0002a2760 sp=0xc0002a2740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956540)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0002a27d8 sp=0xc0002a2760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0002a27e0 sp=0xc0002a27d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069442 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956440, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000316760 sp=0xc000316740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956440)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0003167d8 sp=0xc000316760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003167e0 sp=0xc0003167d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069458 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9564c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00031b760 sp=0xc00031b740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9564c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc00031b7d8 sp=0xc00031b760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00031b7e0 sp=0xc00031b7d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069746 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x9566c0, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0006fc760 sp=0xc0006fc740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x9566c0)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0006fc7d8 sp=0xc0006fc760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0006fc7e0 sp=0xc0006fc7d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 26069682 [timer goroutine (idle), 3 minutes]:
runtime.gopark(0x711190, 0x956640, 0x1414, 0x1)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000120760 sp=0xc000120740 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.timerproc(0x956640)
	/workdir/go/src/runtime/time.go:303 +0x273 fp=0xc0001207d8 sp=0xc000120760 pc=0x44f113
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0001207e0 sp=0xc0001207d8 pc=0x461ec1
created by runtime.(*timersBucket).addtimerLocked
	/workdir/go/src/runtime/time.go:169 +0x10e

goroutine 72986752 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003c95a0 sp=0xc0003c9580 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc0003c9601, 0xc0003c9678)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc0003c9630 sp=0xc0003c95a0 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc0003c9660 sp=0xc0003c9630 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc0003c9688 sp=0xc0003c9660 pc=0x4f5385
testing.(*T).Parallel(0xc00070a600)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc0003c9710 sp=0xc0003c9688 pc=0x4f4b61
runtime_test.TestSigStackSwapping(0xc00070a600)
	/workdir/go/src/runtime/crash_cgo_test.go:476 +0x40 fp=0xc0003c97a8 sp=0xc0003c9710 pc=0x6022a0
testing.tRunner(0xc00070a600, 0x7126d8)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc0003c97d0 sp=0xc0003c97a8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003c97d8 sp=0xc0003c97d0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72986753 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0004da5a0 sp=0xc0004da580 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc0004da601, 0xc0004da678)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc0004da630 sp=0xc0004da5a0 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc0004da660 sp=0xc0004da630 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc0004da688 sp=0xc0004da660 pc=0x4f5385
testing.(*T).Parallel(0xc00070a700)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc0004da710 sp=0xc0004da688 pc=0x4f4b61
runtime_test.TestCgoTracebackSigpanic(0xc00070a700)
	/workdir/go/src/runtime/crash_cgo_test.go:493 +0x40 fp=0xc0004da7a8 sp=0xc0004da710 pc=0x602440
testing.tRunner(0xc00070a700, 0x711eb8)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc0004da7d0 sp=0xc0004da7a8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0004da7d8 sp=0xc0004da7d0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72987042 [chan send]:
runtime.gopark(0x711190, 0xc0000649b8, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc00005fe70 sp=0xc00005fe50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc000064960, 0xc00005ff5f, 0xc0000d9601, 0x4f8e54, 0xc0000d9600)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc00005fef0 sp=0xc00005fe70 pc=0x406bae
runtime.chansend1(0xc000064960, 0xc00005ff5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc00005ff28 sp=0xc00005fef0 pc=0x406975
testing.tRunner.func1(0xc0000d9600)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc00005ffa8 sp=0xc00005ff28 pc=0x4f8e54
testing.tRunner(0xc0000d9600, 0x7123b0)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc00005ffd0 sp=0xc00005ffa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc00005ffd8 sp=0xc00005ffd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 72986885 [chan receive]:
runtime.gopark(0x711190, 0xc0007f8058, 0xc00002170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000704d00 sp=0xc000704ce0 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8000, 0x0, 0xc000704d01, 0xc000704dd8)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc000704d90 sp=0xc000704d00 pc=0x4077b0
runtime.chanrecv1(0xc0007f8000, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc000704dc0 sp=0xc000704d90 pc=0x40748b
testing.(*testContext).waitParallel(0xc000a5c120)
	/workdir/go/src/testing/testing.go:961 +0x95 fp=0xc000704de8 sp=0xc000704dc0 pc=0x4f5385
testing.(*T).Parallel(0xc000359f00)
	/workdir/go/src/testing/testing.go:768 +0x1f1 fp=0xc000704e70 sp=0xc000704de8 pc=0x4f4b61
runtime_test.TestPanicTraceback(0xc000359f00)
	/workdir/go/src/runtime/crash_test.go:414 +0x43 fp=0xc000704fa8 sp=0xc000704e70 pc=0x606163
testing.tRunner(0xc000359f00, 0x7124e0)
	/workdir/go/src/testing/testing.go:862 +0xc0 fp=0xc000704fd0 sp=0xc000704fa8 pc=0x4f4e00
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000704fd8 sp=0xc000704fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77950054 [chan send]:
runtime.gopark(0x711190, 0xc0010a0538, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000fbee70 sp=0xc000fbee50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0010a04e0, 0xc000fbef5f, 0xc000358d01, 0x4f8e54, 0xc000358d00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000fbeef0 sp=0xc000fbee70 pc=0x406bae
runtime.chansend1(0xc0010a04e0, 0xc000a17f5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000fbef28 sp=0xc000fbeef0 pc=0x406975
testing.tRunner.func1(0xc000358d00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000fbefa8 sp=0xc000fbef28 pc=0x4f8e54
testing.tRunner(0xc000358d00, 0x712168)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000fbefd0 sp=0xc000fbefa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000fbefd8 sp=0xc000fbefd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77950057 [chan send]:
runtime.gopark(0x711190, 0xc0010a0778, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000046e70 sp=0xc000046e50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0010a0720, 0xc000046f5f, 0xc000359001, 0x4f8e54, 0xc000359000)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000046ef0 sp=0xc000046e70 pc=0x406bae
runtime.chansend1(0xc0010a0720, 0xc00054ff5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000046f28 sp=0xc000046ef0 pc=0x406975
testing.tRunner.func1(0xc000359000)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000046fa8 sp=0xc000046f28 pc=0x4f8e54
testing.tRunner(0xc000359000, 0x712158)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000046fd0 sp=0xc000046fa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000046fd8 sp=0xc000046fd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77960531 [GC worker (idle)]:
runtime.gopark(0x710fe0, 0xc00081a1c0, 0xc0003d1417, 0x0)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc0003d4760 sp=0xc0003d4740 pc=0x431c3f
runtime.gcBgMarkWorker(0xc000026f00)
	/workdir/go/src/runtime/mgc.go:1836 +0xff fp=0xc0003d47d8 sp=0xc0003d4760 pc=0x41e3df
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0003d47e0 sp=0xc0003d47d8 pc=0x461ec1
created by runtime.gcBgMarkStartWorkers
	/workdir/go/src/runtime/mgc.go:1784 +0x77

goroutine 77959478 [chan receive]:
runtime.gopark(0x711190, 0xc0007f80b8, 0x95170d, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000f926f8 sp=0xc000f926d8 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chanrecv(0xc0007f8060, 0x0, 0xc000f92701, 0x4f4e0a)
	/workdir/go/src/runtime/chan.go:524 +0x2d0 fp=0xc000f92788 sp=0xc000f926f8 pc=0x4077b0
runtime.chanrecv1(0xc0007f8060, 0x0)
	/workdir/go/src/runtime/chan.go:406 +0x2b fp=0xc000f927b8 sp=0xc000f92788 pc=0x40748b
testing.runTests.func1.1(0xc0006dc000)
	/workdir/go/src/testing/testing.go:1159 +0x3b fp=0xc000f927d8 sp=0xc000f927b8 pc=0x4f8fcb
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000f927e0 sp=0xc000f927d8 pc=0x461ec1
created by testing.runTests.func1
	/workdir/go/src/testing/testing.go:1159 +0xac

goroutine 77958334 [chan send]:
runtime.gopark(0x711190, 0xc0007fc958, 0xc00002160e, 0x3)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000fbce70 sp=0xc000fbce50 pc=0x431c3f
runtime.goparkunlock(...)
	/workdir/go/src/runtime/proc.go:307
runtime.chansend(0xc0007fc900, 0xc000fbcf5f, 0xc0000d8c01, 0x4f8e54, 0xc0000d8c00)
	/workdir/go/src/runtime/chan.go:236 +0x22e fp=0xc000fbcef0 sp=0xc000fbce70 pc=0x406bae
runtime.chansend1(0xc0007fc900, 0xc000fbcf5f)
	/workdir/go/src/runtime/chan.go:127 +0x35 fp=0xc000fbcf28 sp=0xc000fbcef0 pc=0x406975
testing.tRunner.func1(0xc0000d8c00)
	/workdir/go/src/testing/testing.go:857 +0x264 fp=0xc000fbcfa8 sp=0xc000fbcf28 pc=0x4f8e54
testing.tRunner(0xc0000d8c00, 0x7127e0)
	/workdir/go/src/testing/testing.go:866 +0xca fp=0xc000fbcfd0 sp=0xc000fbcfa8 pc=0x4f4e0a
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc000fbcfd8 sp=0xc000fbcfd0 pc=0x461ec1
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357

goroutine 77960530 [GC worker (idle)]:
runtime.gopark(0x710fe0, 0xc00081a1b0, 0xc000181417, 0x0)
	/workdir/go/src/runtime/proc.go:301 +0xef fp=0xc000185760 sp=0xc000185740 pc=0x431c3f
runtime.gcBgMarkWorker(0xc000024a00)
	/workdir/go/src/runtime/mgc.go:1836 +0xff fp=0xc0001857d8 sp=0xc000185760 pc=0x41e3df
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1337 +0x1 fp=0xc0001857e0 sp=0xc0001857d8 pc=0x461ec1
created by runtime.gcBgMarkStartWorkers
	/workdir/go/src/runtime/mgc.go:1784 +0x77

goroutine 72986993 [running]:
	goroutine running on other thread; stack unavailable
created by testing.(*T).Run
	/workdir/go/src/testing/testing.go:913 +0x357
FAIL	runtime	600.162s

@andybons andybons modified the milestones: Go1.12, Go1.13 Feb 12, 2019
@bcmills
Copy link
Contributor

bcmills commented Feb 28, 2019

Runtime folks (@aclements @rsc @RLH @randall77): can we make it a priority to get the runtime long-test time under 10 minutes under load? The flakes in the longtest builder can easily mask more serious errors.

More examples (three in a row!):
https://build.golang.org/log/56f132e989f66fa5d09b52a61ee62a1e9a574d21
https://build.golang.org/log/9ddb78a19b4ad99475f218c79d1e1a41546a25cb
https://build.golang.org/log/a4253a3cc05bd87ced2958a9c68715743d5212e4

@bcmills bcmills changed the title runtime: linux-amd64-longtest builder failing runtime: test frequently times out after 10 minutes on linux-amd64-longtest builder Feb 28, 2019
@rsc
Copy link
Contributor

rsc commented Mar 14, 2019

By "long test" do you mean just "go test"? Historically there has not been a requirement that the non-short tests complete in any particular time, and I'm kind of disappointed to see this requirement imposed.

But even ignoring that, 'go test runtime' runs in 1.5 minutes on my laptop. If the builders are 6X slower than my laptop, let's focus on that problem.

@aclements
Copy link
Member

It looks like go test runtime usually takes about 200s on the builders, which is a little slow, but not ridiculous. The failure is usually "GOMAXPROCS=2 runtime -cpu=1,2,4 -quick".

That header says "-quick" (I forget how that's different from -short). How does the longtest builder affect that test?

@bradfitz
Copy link
Contributor

By "long test" do you mean just "go test"? Historically there has not been a requirement that the non-short tests complete in any particular time, and I'm kind of disappointed to see this requirement imposed.

It's not the build system imposing it. It's cmd/go:

        -timeout d
            If a test binary runs longer than duration d, panic.
            If d is 0, the timeout is disabled.
            The default is 10 minutes (10m).

We can have the coordinator explicitly set it much higher if you'd like.

@bradfitz
Copy link
Contributor

Actually, that's not quite accurate. While cmd/go's default is 10 minutes, cmd/dist test still sets a limit, adjusted by GO_TEST_TIMEOUT_SCALE. Instead I sent https://go-review.googlesource.com/c/build/+/167638 to just crank up the longtest's timeout scale.

@rsc
Copy link
Contributor

rsc commented Mar 14, 2019

I wrote that paragraph before I checked how long the runtime test actually took.
If the non-short tests run in a couple minutes for each package then I don't mind
having a builder that depends on that staying true (which is what I meant by
adding a requirement).

The real problem seems to be that the "longtest" builder machines are
underprovisioned/oversubscribed. If we are going to run the "long" tests,
which are by definition a bit CPU-intensive, it's not really fair to run them
on a CPU-starved machine that effectively runs at 1/6 the speed of my laptop.
Increasing the timeout doesn't seem like it addresses the real problem here.

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/167638 mentions this issue: dashboard: increase timeout scale for longtest builders

@bradfitz
Copy link
Contributor

The real problem seems to be that the "longtest" builder machines are
underprovisioned/oversubscribed.
...
it's not really fair to run them
on a CPU-starved machine that effectively runs at 1/6 the speed of my laptop.

It's using the default GCE VM type we use for all other container-based builds: n1-standard-4, 4 vCPUs (Haswell), 15 GB of RAM. That's not much worse than your laptop, is it? We could crank it up, though.

The VM is single-use & unshared by other tests. We stopped using Kubernetes a long time ago specifically because of people (often rightfully) blaming Kubernetes' isolation quality for flaky tests.

@aclements
Copy link
Member

The -cpu=1,2,4 test takes a fair bit longer. On my workstation:

ok runtime 422.956s
ok runtime 422.739s
ok runtime 420.853s
ok runtime 419.106s
ok runtime 421.480s
ok runtime 417.887s
ok runtime 421.122s
ok runtime 418.034s
ok runtime 416.562s
ok runtime 417.979s
ok runtime 415.275s

It doesn't surprise me that this goes over the 10 minute mark on a slower machine.

gopherbot pushed a commit to golang/build that referenced this issue Mar 14, 2019
@bcmills
Copy link
Contributor

bcmills commented Mar 14, 2019

If the problem is the combined time for -cpu=1,2,4, should we split that dist test up into individual tests for each cpu value so that they can be run in parallel?

@bradfitz
Copy link
Contributor

Well, we don't run the longtest builder sharded. It's not a trybot so we don't particularly care about latency. We also bound it to 1 builder per commit at a time, which means it can fill in the dashboard slowly, but that's fine.

@aclements
Copy link
Member

It's still timing out at 10 minutes. Has the dashboard change been deployed?

@bradfitz
Copy link
Contributor

@aclements, no, not yet. Every time I've went to do it people were using gomote and just starting trybots.

Btw, you can check this yourself at https://farmer.golang.org/ where it says at the top:

1379 total builds; 84 active. Uptime 46h57m1s. Version 1292b0303e050cc39ea0a4896f87994480a26ca8-bradfitz-2019-03-13T20:20:47Z.

I'll do it now.

@aclements
Copy link
Member

The longtest builder appears to be happy now. Shall we close this?

@bradfitz
Copy link
Contributor

Closing.

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/192679 mentions this issue: dashboard: change linux-amd64-longtest machine to n1-highcpu-16

gopherbot pushed a commit to golang/build that referenced this issue Aug 30, 2019
CL 167638 made a change to add more CPU resources to the longtest
builder, with the intention of going from 4 vCPUs, 15 GB RAM to
16 vCPUs, 14.4 GB RAM.

It used n1-highcpu-8 GCE machine type, which actually has 8 vCPUs
and 7.2 GB RAM.¹ Having less RAM than before wasn't the intention.

Fix that by changing n1-highcpu-8 to n1-highcpu-16, which matches
the comment.

¹ https://cloud.google.com/compute/docs/machine-types

Updates golang/go#32831
Updates golang/go#33986
Updates golang/go#25886

Change-Id: I8426867fe33b3bf86576cb13d0d6113cd87f30c1
Reviewed-on: https://go-review.googlesource.com/c/build/+/192679
Reviewed-by: Bryan C. Mills <[email protected]>
codebien pushed a commit to codebien/build that referenced this issue Nov 13, 2019
CL 167638 made a change to add more CPU resources to the longtest
builder, with the intention of going from 4 vCPUs, 15 GB RAM to
16 vCPUs, 14.4 GB RAM.

It used n1-highcpu-8 GCE machine type, which actually has 8 vCPUs
and 7.2 GB RAM.¹ Having less RAM than before wasn't the intention.

Fix that by changing n1-highcpu-8 to n1-highcpu-16, which matches
the comment.

¹ https://cloud.google.com/compute/docs/machine-types

Updates golang/go#32831
Updates golang/go#33986
Updates golang/go#25886

Change-Id: I8426867fe33b3bf86576cb13d0d6113cd87f30c1
Reviewed-on: https://go-review.googlesource.com/c/build/+/192679
Reviewed-by: Bryan C. Mills <[email protected]>
@golang golang locked and limited conversation to collaborators Aug 29, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Builders x/build issues (builders, bots, dashboards) FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. Testing An issue that has been verified to require only test changes, not just a test failure.
Projects
None yet
Development

No branches or pull requests

9 participants