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

runtime: BenchmarkMSpanCountAlloc is failing #41391

Closed
erifan opened this issue Sep 15, 2020 · 6 comments
Closed

runtime: BenchmarkMSpanCountAlloc is failing #41391

erifan opened this issue Sep 15, 2020 · 6 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Milestone
Go1.16

Comments

@erifan
Copy link

erifan commented Sep 15, 2020

What version of Go are you using (go version)?

$ go version
tip

Does this issue reproduce with the latest release?

yes

What operating system and processor architecture are you using (go env)?

The issue occurs both on amd64/linux and arm64/linux.

BenchmarkMSpanCountAlloc/bits=1024-8      	fatal error: runtime: cannot allocate memory
goroutine 21015 [running]:
runtime.throw(0x271439, 0x1f)
	/home/root/ci-scripts/golang/src/runtime/panic.go:1116 +0x54 fp=0x400049e5c0 sp=0x400049e590 pc=0x451d4
runtime.recordspan(0x418bc0, 0xfff7c9333208)
	/home/root/ci-scripts/golang/src/runtime/mheap.go:506 +0x1b0 fp=0x400049e610 sp=0x400049e5c0 pc=0x36240
runtime.(*fixalloc).alloc(0x431630, 0x1fc)
	/home/root/ci-scripts/golang/src/runtime/mfixalloc.go:86 +0xec fp=0x400049e650 sp=0x400049e610 pc=0x2a55c
runtime.MSpanCountAlloc(0x400003a080, 0x80, 0x80, 0x1fc)
	/home/root/ci-scripts/golang/src/runtime/export_test.go:987 +0x2c fp=0x400049e670 sp=0x400049e650 pc=0x725ac
runtime_test.BenchmarkMSpanCountAlloc.func1(0x400014a480)
	/home/root/ci-scripts/golang/src/runtime/gc_test.go:777 +0xa8 fp=0x400049e6e0 sp=0x400049e670 pc=0x1c95b8
testing.(*B).runN(0x400014a480, 0x651943)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:191 +0xf0 fp=0x400049e750 sp=0x400049e6e0 pc=0xe52c0
testing.(*B).launch(0x400014a480)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:321 +0xcc fp=0x400049e7d0 sp=0x400049e750 pc=0xe583c
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x400049e7d0 sp=0x400049e7d0 pc=0x7cd44
created by testing.(*B).doBench
	/home/root/ci-scripts/golang/src/testing/benchmark.go:276 +0x48

goroutine 1 [chan receive, locked to thread]:
runtime.gopark(0x27a6c8, 0x40000245f8, 0x42170e, 0x2)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40000fd8f0 sp=0x40000fd8d0 pc=0x47ad0
runtime.chanrecv(0x40000245a0, 0x0, 0x4000000101, 0xe53e8)
	/home/root/ci-scripts/golang/src/runtime/chan.go:571 +0x2d0 fp=0x40000fd980 sp=0x40000fd8f0 pc=0x17a20
runtime.chanrecv1(0x40000245a0, 0x0)
	/home/root/ci-scripts/golang/src/runtime/chan.go:438 +0x28 fp=0x40000fd9b0 sp=0x40000fd980 pc=0x176f8
testing.(*B).run1(0x400014a240, 0x400014a240)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:233 +0x7c fp=0x40000fda70 sp=0x40000fd9b0 pc=0xe53fc
testing.(*B).Run(0x400014a000, 0x26d4e9, 0x18, 0x27b1c0, 0xbfcf97d55b30aa00)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:656 +0x2e0 fp=0x40000fdb60 sp=0x40000fda70 pc=0xe75b0
testing.runBenchmarks.func1(0x400014a000)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:533 +0x74 fp=0x40000fdbb0 sp=0x40000fdb60 pc=0xf0c74
testing.(*B).runN(0x400014a000, 0x1)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:191 +0xf0 fp=0x40000fdc20 sp=0x40000fdbb0 pc=0xe52c0
testing.runBenchmarks(0x264e5c, 0x7, 0x400011c000, 0x3fcca0, 0xf4, 0xf4, 0x4019c0)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:542 +0x35c fp=0x40000fdd30 sp=0x40000fdc20 pc=0xe684c
testing.(*M).Run(0x40000f4000, 0x0)
	/home/root/ci-scripts/golang/src/testing/testing.go:1387 +0x430 fp=0x40000fde60 sp=0x40000fdd30 pc=0xee5d0
runtime_test.TestMain(0x40000f4000)
	/home/root/ci-scripts/golang/src/runtime/crash_test.go:28 +0x28 fp=0x40000fdeb0 sp=0x40000fde60 pc=0x16a0a8
main.main()
	_testmain.go:1217 +0x160 fp=0x40000fdf70 sp=0x40000fdeb0 pc=0x1e26f0
runtime.main()
	/home/root/ci-scripts/golang/src/runtime/proc.go:205 +0x20c fp=0x40000fdfd0 sp=0x40000fdf70 pc=0x476fc
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40000fdfd0 sp=0x40000fdfd0 pc=0x7cd44

goroutine 2 [force gc (idle), 9 minutes]:
runtime.gopark(0x27a9d0, 0x401140, 0x1411, 0x1)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x4000094fa0 sp=0x4000094f80 pc=0x47ad0
runtime.goparkunlock(...)
	/home/root/ci-scripts/golang/src/runtime/proc.go:313
runtime.forcegchelper()
	/home/root/ci-scripts/golang/src/runtime/proc.go:256 +0xc4 fp=0x4000094fd0 sp=0x4000094fa0 pc=0x47984
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x4000094fd0 sp=0x4000094fd0 pc=0x7cd44
created by runtime.init.5
	/home/root/ci-scripts/golang/src/runtime/proc.go:244 +0x30

goroutine 3 [GC sweep wait]:
runtime.gopark(0x27a9d0, 0x401540, 0x140c, 0x1)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40000957a0 sp=0x4000095780 pc=0x47ad0
runtime.goparkunlock(...)
	/home/root/ci-scripts/golang/src/runtime/proc.go:313
runtime.bgsweep(0x400001e460)
	/home/root/ci-scripts/golang/src/runtime/mgcsweep.go:180 +0x190 fp=0x40000957d0 sp=0x40000957a0 pc=0x33e00
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40000957d0 sp=0x40000957d0 pc=0x7cd44
created by runtime.gcenable
	/home/root/ci-scripts/golang/src/runtime/mgc.go:217 +0x54

goroutine 4 [GC scavenge wait]:
runtime.gopark(0x27a9d0, 0x4016c0, 0x140d, 0x1)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x4000095f70 sp=0x4000095f50 pc=0x47ad0
runtime.goparkunlock(...)
	/home/root/ci-scripts/golang/src/runtime/proc.go:313
runtime.bgscavenge(0x400001e460)
	/home/root/ci-scripts/golang/src/runtime/mgcscavenge.go:314 +0x270 fp=0x4000095fd0 sp=0x4000095f70 pc=0x32360
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x4000095fd0 sp=0x4000095fd0 pc=0x7cd44
created by runtime.gcenable
	/home/root/ci-scripts/golang/src/runtime/mgc.go:218 +0x74

goroutine 5 [finalizer wait, 9 minutes]:
runtime.gopark(0x27a9d0, 0x431930, 0x1410, 0x1)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x4000094730 sp=0x4000094710 pc=0x47ad0
runtime.goparkunlock(...)
	/home/root/ci-scripts/golang/src/runtime/proc.go:313
runtime.runfinq()
	/home/root/ci-scripts/golang/src/runtime/mfinal.go:175 +0xc0 fp=0x40000947d0 sp=0x4000094730 pc=0x299d0
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40000947d0 sp=0x40000947d0 pc=0x7cd44
created by runtime.createfing
	/home/root/ci-scripts/golang/src/runtime/mfinal.go:156 +0x78

goroutine 20583 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x4000202000, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40004d2750 sp=0x40004d2730 pc=0x47ad0
runtime.gcBgMarkWorker(0x4000081000)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40004d27d0 sp=0x40004d2750 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40004d27d0 sp=0x40004d27d0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 20955 [chan receive]:
runtime.gopark(0x27a6c8, 0x40000246b8, 0x40000a170e, 0x2)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40000a7b20 sp=0x40000a7b00 pc=0x47ad0
runtime.chanrecv(0x4000024660, 0x0, 0x40001aa301, 0xe5718)
	/home/root/ci-scripts/golang/src/runtime/chan.go:571 +0x2d0 fp=0x40000a7bb0 sp=0x40000a7b20 pc=0x17a20
runtime.chanrecv1(0x4000024660, 0x0)
	/home/root/ci-scripts/golang/src/runtime/chan.go:438 +0x28 fp=0x40000a7be0 sp=0x40000a7bb0 pc=0x176f8
testing.(*B).doBench(0x400014a480, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:277 +0x5c fp=0x40000a7c10 sp=0x40000a7be0 pc=0xe572c
testing.(*benchContext).processBench(0x400011c040, 0x400014a480)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:572 +0x1b8 fp=0x40000a7d30 sp=0x40000a7c10 pc=0xe6d08
testing.(*B).run(0x400014a480)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:268 +0x58 fp=0x40000a7d90 sp=0x40000a7d30 pc=0xe5688
testing.(*B).Run(0x400014a240, 0x4000016180, 0x9, 0x400010e020, 0x0)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:657 +0x368 fp=0x40000a7e80 sp=0x40000a7d90 pc=0xe7638
runtime_test.BenchmarkMSpanCountAlloc(0x400014a240)
	/home/root/ci-scripts/golang/src/runtime/gc_test.go:770 +0x90 fp=0x40000a7f20 sp=0x40000a7e80 pc=0x179330
testing.(*B).runN(0x400014a240, 0x1)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:191 +0xf0 fp=0x40000a7f90 sp=0x40000a7f20 pc=0xe52c0
testing.(*B).run1.func1(0x400014a240)
	/home/root/ci-scripts/golang/src/testing/benchmark.go:231 +0x54 fp=0x40000a7fd0 sp=0x40000a7f90 pc=0xf0a04
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40000a7fd0 sp=0x40000a7fd0 pc=0x7cd44
created by testing.(*B).run1
	/home/root/ci-scripts/golang/src/testing/benchmark.go:224 +0x68

goroutine 20648 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x4000016120, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40007f4750 sp=0x40007f4730 pc=0x47ad0
runtime.gcBgMarkWorker(0x4000088800)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40007f47d0 sp=0x40007f4750 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40007f47d0 sp=0x40007f47d0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 20585 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x40003c0040, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40004cef50 sp=0x40004cef30 pc=0x47ad0
runtime.gcBgMarkWorker(0x4000083800)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40004cefd0 sp=0x40004cef50 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40004cefd0 sp=0x40004cefd0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 4517 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x4000202010, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40001bd750 sp=0x40001bd730 pc=0x47ad0
runtime.gcBgMarkWorker(0x400008d800)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40001bd7d0 sp=0x40001bd750 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40001bd7d0 sp=0x40001bd7d0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 20475 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x40003c0010, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40002b7750 sp=0x40002b7730 pc=0x47ad0
runtime.gcBgMarkWorker(0x400007e800)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40002b77d0 sp=0x40002b7750 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40002b77d0 sp=0x40002b77d0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 20537 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x40003c0030, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x4000264f50 sp=0x4000264f30 pc=0x47ad0
runtime.gcBgMarkWorker(0x4000086000)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x4000264fd0 sp=0x4000264f50 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x4000264fd0 sp=0x4000264fd0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 20706 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x40003c0000, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40004d1f50 sp=0x40004d1f30 pc=0x47ad0
runtime.gcBgMarkWorker(0x400007c000)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40004d1fd0 sp=0x40004d1f50 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40004d1fd0 sp=0x40004d1fd0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80

goroutine 20507 [GC worker (idle)]:
runtime.gopark(0x27a7d8, 0x40003c0020, 0x1418, 0x0)
	/home/root/ci-scripts/golang/src/runtime/proc.go:307 +0xd0 fp=0x40007f3f50 sp=0x40007f3f30 pc=0x47ad0
runtime.gcBgMarkWorker(0x400008b000)
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1891 +0xe8 fp=0x40007f3fd0 sp=0x40007f3f50 pc=0x2d318
runtime.goexit()
	/home/root/ci-scripts/golang/src/runtime/asm_arm64.s:1136 +0x4 fp=0x40007f3fd0 sp=0x40007f3fd0 pc=0x7cd44
created by runtime.gcBgMarkStartWorkers
	/home/root/ci-scripts/golang/src/runtime/mgc.go:1839 +0x80
exit status 2
FAIL	runtime	567.042s
@ianlancetaylor ianlancetaylor changed the title BenchmarkMSpanCountAlloc is failing runtime: BenchmarkMSpanCountAlloc is failing Sep 15, 2020
@ianlancetaylor ianlancetaylor added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 15, 2020
@ianlancetaylor ianlancetaylor added this to the Go1.16 milestone Sep 15, 2020
@ianlancetaylor
Copy link
Contributor

CC @aclements @mknyszek

@cuonglm
Copy link
Member

cuonglm commented Sep 15, 2020

It runs fine for me with current tip bae9cf6, linux amd64

@erifan
Copy link
Author

erifan commented Sep 15, 2020 •
edited

@cuonglm It is a bit random, not a steady failure. The version I use is 66e66e7

@mknyszek
Copy link
Contributor

This code changed with d9a6bdf to prevent go:notinheap memory from appearing on the stack, but I think there are two issues here: mheap_.lock needs to be held to allocate from the fixalloc and we never free it, so we keep growing the fixalloc, hence the cannot allocate memory failure.

The fix is straightforward.

@mknyszek mknyszek self-assigned this Sep 16, 2020
@mknyszek mknyszek added the NeedsFix The path to resolution is known, but the work has not been done. label Sep 16, 2020
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 16, 2020
@gopherbot
Copy link

Change https://golang.org/cl/255297 mentions this issue: runtime: fix leak and locking in BenchmarkMSpanCountAlloc

@gopherbot
Copy link

Change https://golang.org/cl/255298 mentions this issue: runtime: actually fix locking in BenchmarkMSpanCountAlloc

gopherbot pushed a commit that referenced this issue Sep 16, 2020
@mknyszek
runtime: actually fix locking in BenchmarkMSpanCountAlloc
10dfb1d 
I just submitted CL 255297 which mostly fixed this problem, but totally
forgot to actually acquire/release the heap lock. Oops.

Updates #41391.

Change-Id: I45b42f20a9fc765c4de52476db3654d4bfe9feb3
Reviewed-on: https://go-review.googlesource.com/c/go/+/255298
Trust: Michael Knyszek <mknyszek@google.com>
Run-TryBot: Michael Knyszek <mknyszek@google.com>
Reviewed-by: Keith Randall <khr@golang.org>
TryBot-Result: Go Bot <gobot@golang.org>
@golang golang locked and limited conversation to collaborators Sep 16, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Milestone
Go1.16
Development

No branches or pull requests
5 participants
@mknyszek @ianlancetaylor @cuonglm @gopherbot @erifan