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: "lock ordering problem" in (*gcSweepBuf).push #38441

Closed
bcmills opened this issue Apr 14, 2020 · 1 comment
Closed

runtime: "lock ordering problem" in (*gcSweepBuf).push #38441

bcmills opened this issue Apr 14, 2020 · 1 comment
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Milestone
Go1.15

Comments

@bcmills
Copy link
Contributor

bcmills commented Apr 14, 2020

2020-04-13T22:48:16-240eac3/linux-amd64-staticlockranking

CC @danscales @aclements

##### ../test
# go run run.go -- fixedbugs/issue9862_run.go
incorrect output
go run issue9862.go gave unexpected error; want symbol too large:
 137479  ======
0 : assistQueue 4 0xed27d8
1 : spine 31 0xefa858
fatal error: lock ordering problem
137479  ======
0 : assistQueue 4 0xed27d8
1 : spine 31 0xefa858
2 : panic 9 0xeff610
fatal error: lock ordering problem
panic during panic

runtime stack:
runtime.throw(0xa414f6, 0x15)
	/workdir/go/src/runtime/panic.go:1116 +0x72
runtime.checkRanks(0xed23a0, 0x1f, 0x9)
	/workdir/go/src/runtime/lockrank_on.go:107 +0x270
runtime.lockWithRank.func1()
	/workdir/go/src/runtime/lockrank_on.go:72 +0xb4
runtime.lockWithRank(0xeff610, 0x9)
	/workdir/go/src/runtime/lockrank_on.go:61 +0x82
runtime.lock(0xeff610)
	/workdir/go/src/runtime/lock_futex.go:47 +0x33
runtime.startpanic_m(0x1)
	/workdir/go/src/runtime/panic.go:1260 +0x131
runtime.fatalthrow.func1()
	/workdir/go/src/runtime/panic.go:1169 +0x3d
runtime.fatalthrow()
	/workdir/go/src/runtime/panic.go:1168 +0x57
runtime.throw(0xa414f6, 0x15)
	/workdir/go/src/runtime/panic.go:1116 +0x72
runtime.checkRanks(0xed23a0, 0x4, 0x1f)
	/workdir/go/src/runtime/lockrank_on.go:107 +0x270
runtime.lockWithRank.func1()
	/workdir/go/src/runtime/lockrank_on.go:72 +0xb4
runtime.lockWithRank(0xefa858, 0x1f)
	/workdir/go/src/runtime/lockrank_on.go:61 +0x82
runtime.lock(...)
	/workdir/go/src/runtime/lock_futex.go:47
runtime.(*gcSweepBuf).push(0xefa858, 0x7f27286a4c88)
	/workdir/go/src/runtime/mgcsweepbuf.go:72 +0x7d
runtime.(*mheap).allocSpan(0xeea740, 0x1, 0x7f27286a2300, 0xf01128, 0x416c4f)
	/workdir/go/src/runtime/mheap.go:1266 +0x2ae
runtime.(*mheap).alloc.func1()
	/workdir/go/src/runtime/mheap.go:875 +0x64
runtime.(*mheap).alloc(0xeea740, 0x1, 0x400123, 0x7ffd0effd858)
	/workdir/go/src/runtime/mheap.go:869 +0x81
runtime.(*mcentral).grow(0xefbd48, 0x1e)
	/workdir/go/src/runtime/mcentral.go:256 +0x7a
runtime.(*mcentral).cacheSpan(0xefbd48, 0x7ffd0effd968)
	/workdir/go/src/runtime/mcentral.go:107 +0x30a
runtime.(*mcache).refill(0x7f27521cce98, 0x23)
	/workdir/go/src/runtime/mcache.go:138 +0x84
runtime.(*mcache).nextFree(0x7f27521cce98, 0xc000502023, 0x0, 0xc00050e000, 0x7f275203c800)
	/workdir/go/src/runtime/malloc.go:870 +0x87
runtime.mallocgc(0x100, 0x9a0e00, 0xed2301, 0xed2538)
	/workdir/go/src/runtime/malloc.go:1050 +0x792
runtime.newobject(0x9a0e00, 0xc00050e000)
	/workdir/go/src/runtime/malloc.go:1179 +0x38
runtime.mcommoninit(0xc00050e000)
	/workdir/go/src/runtime/proc.go:663 +0x191
runtime.allocm(0xc00002c000, 0xa835e8, 0xed23a0)
	/workdir/go/src/runtime/proc.go:1443 +0x153
runtime.newm(0xa835e8, 0xc00002c000)
	/workdir/go/src/runtime/proc.go:1757 +0x39
runtime.startm(0x0, 0xc0004cf901)
	/workdir/go/src/runtime/proc.go:1922 +0x130
runtime.wakep(...)
	/workdir/go/src/runtime/proc.go:2006
runtime.ready(0xc0004cf980, 0x0, 0x426500)
	/workdir/go/src/runtime/proc.go:694 +0x12f
runtime.gcFlushBgCredit(0x830)
	/workdir/go/src/runtime/mgcmark.go:652 +0x9b
runtime.gcDrain(0xc000032698, 0x2)
	/workdir/go/src/runtime/mgcmark.go:1044 +0x2e1
runtime.gcBgMarkWorker.func2()
	/workdir/go/src/runtime/mgc.go:1977 +0x12f
runtime.systemstack(0x467f94)
	/workdir/go/src/runtime/asm_amd64.s:370 +0x66
runtime.mstart()
	/workdir/go/src/runtime/proc.go:1094

goroutine 18 [GC worker (idle)]:
runtime.systemstack_switch()
	/workdir/go/src/runtime/asm_amd64.s:330 fp=0xc000036760 sp=0xc000036758 pc=0x468090
runtime.gcBgMarkWorker(0xc000031000)
	/workdir/go/src/runtime/mgc.go:1945 +0x1be fp=0xc0000367d8 sp=0xc000036760 pc=0x41e2de
runtime.goexit()
	/workdir/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0000367e0 sp=0xc0000367d8 pc=0x469c41
created by runtime.gcBgMarkStartWorkers
	/workdir/go/src/runtime/mgc.go:1839 +0x77

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc0005980d8)
	/workdir/go/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc0005980d0)
	/workdir/go/src/sync/waitgroup.go:130 +0x64
cmd/go/internal/work.(*Builder).Do(0xc00011b720, 0xc00035fa40)
	/workdir/go/src/cmd/go/internal/work/exec.go:188 +0x3a5
cmd/go/internal/run.runRun(0xec6bc0, 0xc0000201a0, 0x1, 0x1)
	/workdir/go/src/cmd/go/internal/run/run.go:143 +0x538
main.main()
	/workdir/go/src/cmd/go/main.go:189 +0x55d

goroutine 8 [runnable]:
crypto/sha256.New(...)
	/workdir/go/src/crypto/sha256/sha256.go:162
cmd/go/internal/cache.NewHash(0xc000600000, 0x1a, 0x6)
	/workdir/go/src/cmd/go/internal/cache/hash.go:64 +0x31
cmd/go/internal/work.(*Builder).buildActionID(0xc00011b720, 0xc00035f7c0, 0x0, 0x0, 0x0, 0x0)
	/workdir/go/src/cmd/go/internal/work/exec.go:197 +0xa5
cmd/go/internal/work.(*Builder).build(0xc00011b720, 0xc00035f7c0, 0x0, 0x0)
	/workdir/go/src/cmd/go/internal/work/exec.go:406 +0x4efa
cmd/go/internal/work.(*Builder).Do.func2(0xc00035f7c0)
	/workdir/go/src/cmd/go/internal/work/exec.go:119 +0x34f
cmd/go/internal/work.(*Builder).Do.func3(0xc0005980d0, 0xc00011b720, 0xc000586740)
	/workdir/go/src/cmd/go/internal/work/exec.go:179 +0x76
created by cmd/go/internal/work.(*Builder).Do
	/workdir/go/src/cmd/go/internal/work/exec.go:166 +0x381

goroutine 9 [running]:
	goroutine running on other thread; stack unavailable
created by cmd/go/internal/work.(*Builder).Do
	/workdir/go/src/cmd/go/internal/work/exec.go:166 +0x381

goroutine 10 [select]:
cmd/go/internal/work.(*Builder).Do.func3(0xc0005980d0, 0xc00011b720, 0xc000586740)
	/workdir/go/src/cmd/go/internal/work/exec.go:169 +0xed
created by cmd/go/internal/work.(*Builder).Do
	/workdir/go/src/cmd/go/internal/work/exec.go:166 +0x381

goroutine 11 [syscall]:
syscall.Syscall6(0xf7, 0x1, 0x21918, 0xc000130e18, 0x1000004, 0x0, 0x0, 0xb20aa9, 0xaaaaaaaaaaaaaa, 0xc000130e60)
	/workdir/go/src/syscall/asm_linux_amd64.s:41 +0x5
os.(*Process).blockUntilWaitable(0xc0005a4000, 0x2, 0x422ad5, 0xc0004c1bf0)
	/workdir/go/src/os/wait_waitid.go:30 +0x98
os.(*Process).wait(0xc0005a4000, 0xa832b8, 0xa832c0, 0xa832b0)
	/workdir/go/src/os/exec_unix.go:22 +0x39
os.(*Process).Wait(...)
	/workdir/go/src/os/exec.go:125
os/exec.(*Cmd).Wait(0xc000113b80, 0x0, 0x0)
	/workdir/go/src/os/exec/exec.go:507 +0x60
os/exec.(*Cmd).Run(0xc000113b80, 0xc0004c1bf0, 0x2a)
	/workdir/go/src/os/exec/exec.go:341 +0x5c
cmd/go/internal/work.(*Builder).toolID(0xc00011b720, 0xa38684, 0x7, 0xb, 0xc000131418)
	/workdir/go/src/cmd/go/internal/work/buildid.go:192 +0x44d
cmd/go/internal/work.(*Builder).buildActionID(0xc00011b720, 0xc00035f2c0, 0x0, 0x0, 0x0, 0x0)
	/workdir/go/src/cmd/go/internal/work/exec.go:251 +0xd80
cmd/go/internal/work.(*Builder).build(0xc00011b720, 0xc00035f2c0, 0x0, 0x0)
	/workdir/go/src/cmd/go/internal/work/exec.go:406 +0x4efa
cmd/go/internal/work.(*Builder).Do.func2(0xc00035f2c0)
	/workdir/go/src/cmd/go/internal/work/exec.go:119 +0x34f
cmd/go/internal/work.(*Builder).Do.func3(0xc0005980d0, 0xc00011b720, 0xc000586740)
	/workdir/go/src/cmd/go/internal/work/exec.go:179 +0x76
created by cmd/go/internal/work.(*Builder).Do
	/workdir/go/src/cmd/go/internal/work/exec.go:166 +0x381

goroutine 12 [GC assist wait]:
bytes.makeSlice(0x600, 0x0, 0x0, 0x0)
	/workdir/go/src/bytes/buffer.go:229 +0x73
bytes.(*Buffer).grow(0xc0004c1bc0, 0x200, 0x200)
	/workdir/go/src/bytes/buffer.go:142 +0x152
bytes.(*Buffer).ReadFrom(0xc0004c1bc0, 0xb326a0, 0xc000456898, 0x7f2728663028, 0xc0004c1bc0, 0x9d0801)
	/workdir/go/src/bytes/buffer.go:202 +0x48
io.copyBuffer(0xb31a20, 0xc0004c1bc0, 0xb326a0, 0xc000456898, 0x0, 0x0, 0x0, 0x0, 0x1, 0x0)
	/workdir/go/src/io/io.go:395 +0x2fc
io.Copy(...)
	/workdir/go/src/io/io.go:368
os/exec.(*Cmd).writerDescriptor.func1(0x0, 0xc0005980d0)
	/workdir/go/src/os/exec/exec.go:311 +0x63
os/exec.(*Cmd).Start.func1(0xc000113b80, 0xc0005867e0)
	/workdir/go/src/os/exec/exec.go:441 +0x27
created by os/exec.(*Cmd).Start
	/workdir/go/src/os/exec/exec.go:440 +0x60a

goroutine 13 [IO wait]:
internal/poll.runtime_pollWait(0x7f27286e7db8, 0x72, 0xffffffffffffffff)
	/workdir/go/src/runtime/netpoll.go:220 +0x55
internal/poll.(*pollDesc).wait(0xc0005827f8, 0x72, 0x201, 0x200, 0xffffffffffffffff)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
	/workdir/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0005827e0, 0xc000602200, 0x200, 0x200, 0x0, 0x0, 0x0)
	/workdir/go/src/internal/poll/fd_unix.go:160 +0x19b
os.(*File).read(...)
	/workdir/go/src/os/file_posix.go:31
os.(*File).Read(0xc0004568b0, 0xc000602200, 0x200, 0x200, 0x0, 0x0, 0xc0000916a0)
	/workdir/go/src/os/file.go:116 +0x71
bytes.(*Buffer).ReadFrom(0xc0004c1bf0, 0xb326a0, 0xc0004568b0, 0x7f2728663028, 0xc0004c1bf0, 0x1)
	/workdir/go/src/bytes/buffer.go:204 +0xb1
io.copyBuffer(0xb31a20, 0xc0004c1bf0, 0xb326a0, 0xc0004568b0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/workdir/go/src/io/io.go:395 +0x2fc
io.Copy(...)
	/workdir/go/src/io/io.go:368
os/exec.(*Cmd).writerDescriptor.func1(0x0, 0x0)
	/workdir/go/src/os/exec/exec.go:311 +0x63
os/exec.(*Cmd).Start.func1(0xc000113b80, 0xc000586820)
	/workdir/go/src/os/exec/exec.go:441 +0x27
created by os/exec.(*Cmd).Start
	/workdir/go/src/os/exec/exec.go:440 +0x60a
fatal error: unlock of unlocked lock
stack trace unavailable


FAIL	fixedbugs/issue9862_run.go	0.342s
@bcmills bcmills added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker labels Apr 14, 2020
@bcmills bcmills added this to the Go1.15 milestone Apr 14, 2020
@danscales danscales self-assigned this Apr 14, 2020
@gopherbot
Copy link

Change https://golang.org/cl/229480 mentions this issue: runtime: added three new lock-rank partial order edges

xujianhai666 pushed a commit to xujianhai666/go-1 that referenced this issue May 21, 2020
@danscales @xujianhai666
runtime: added several new lock-rank partial order edges
076f69f 
Several new ones came from my testing (long, repeated runs) and one (assistQueue ->
spine) came from the staticlockranking builder (filed as issue 38441).

Fixes golang#38441

Change-Id: I4268da0d8b8cc51251eba6bd936110c8ab4c4e61
Reviewed-on: https://go-review.googlesource.com/c/go/+/229480
Run-TryBot: Dan Scales <danscales@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Michael Pratt <mpratt@google.com>
@golang golang locked and limited conversation to collaborators Apr 27, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. release-blocker
Projects
None yet
Milestone
Go1.15
Development

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