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: stoplockedm: inconsistent locking #21306

Closed
bradfitz opened this issue Aug 4, 2017 · 7 comments
Closed

runtime: stoplockedm: inconsistent locking #21306

bradfitz opened this issue Aug 4, 2017 · 7 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Go1.9

Comments

@bradfitz
Copy link
Contributor

bradfitz commented Aug 4, 2017

linux-386 at be596f0

https://build.golang.org/log/40f5c89dd04f3d7f0f5ebaf14636c25d814d3f65

...

##### ../misc/cgo/errors
test barrier-gcprog-struct-heap output does not contain expected error (failed with exit status 2)
=== test barrier-gcprog-struct-heap output ===
fatal error: stoplockedm: inconsistent locking
fatal error: runtime: internal error: misuse of lockOSThread/unlockOSThread

runtime stack:
runtime.throw(0x80a9482, 0x21)
	/tmp/workdir/go/src/runtime/panic.go:605 +0x7c
runtime.stoplockedm()
	/tmp/workdir/go/src/runtime/proc.go:1808 +0x13e
runtime.schedule()
	/tmp/workdir/go/src/runtime/proc.go:2203 +0x270
runtime.goschedImpl(0x197000e0)
	/tmp/workdir/go/src/runtime/proc.go:2323 +0xdc
runtime.gopreempt_m(0x197000e0)
	/tmp/workdir/go/src/runtime/proc.go:2351 +0x2c
runtime.newstack(0x0)
	/tmp/workdir/go/src/runtime/stack.go:1042 +0x23f
runtime.morestack()
	/tmp/workdir/go/src/runtime/asm_386.s:465 +0x77

goroutine 1 [running, locked to thread]:
	goroutine running on other thread; stack unavailable

runtime stack:
runtime.throw(0x80aaa6b, 0x3e)
	/tmp/workdir/go/src/runtime/panic.go:605 +0x7c
runtime.badunlockosthread()
	/tmp/workdir/go/src/runtime/proc.go:3206 +0x2b
runtime.systemstack(0x1971ca80)
	/tmp/workdir/go/src/runtime/asm_386.s:393 +0x5e
runtime.mstart()
	/tmp/workdir/go/src/runtime/proc.go:1125
=== end of test barrier-gcprog-struct-heap output ===
exit status 1
2017/08/03 21:34:59 Failed: exit status 1
2017/08/03 21:34:59 FAILED

/cc @aclements @ianlancetaylor
@bradfitz bradfitz added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 4, 2017
@bradfitz bradfitz added this to the Go1.9 milestone Aug 4, 2017
@ianlancetaylor
Copy link
Contributor

This is the program in question:

package main

/*
#include <stdlib.h>
struct s { char *a[32769]; };
struct s2 { struct s f; };
struct s2 *f1() { return malloc(sizeof(struct s2)); }
void f2(struct s2 *p) {}
void f3(void *p) {}
*/
import "C"

import "unsafe"

func main() {
	p := C.f1()
	n := &C.struct_s{[32769]*C.char{new(C.char)}}
	p.f = *n
	C.f2(p)
	n.a[0] = nil
	C.f3(unsafe.Pointer(n))
}

The program is being run with GODEBUG=cgocheck=2 set in the environment. It is expected to throw fatal error: Go pointer stored into non-Go memory. The test failure is because the program failed with an unexpected throw.

I just ran the program 30,000 times and the error did not recur.

@ianlancetaylor
Copy link
Contributor

Ah, but when I built the program with GOARCH=386 it failed after 2250 attempts.

@ianlancetaylor
Copy link
Contributor

Here is the full stack trace of a failure:

fatal error: stoplockedm: inconsistent locking

runtime stack:
runtime.throw(0x80a9642, 0x21)
	/home/iant/go/src/runtime/panic.go:605 +0x7c fp=0xff889534 sp=0xff889528 pc=0x8068dcc
runtime.stoplockedm()
	/home/iant/go/src/runtime/proc.go:1808 +0x13e fp=0xff889544 sp=0xff889534 pc=0x806df2e
runtime.schedule()
	/home/iant/go/src/runtime/proc.go:2203 +0x270 fp=0xff889564 sp=0xff889544 pc=0x806f100
runtime.goschedImpl(0x186000e0)
	/home/iant/go/src/runtime/proc.go:2323 +0xdc fp=0xff889574 sp=0xff889564 pc=0x806f44c
runtime.gopreempt_m(0x186000e0)
	/home/iant/go/src/runtime/proc.go:2351 +0x2c fp=0xff88957c sp=0xff889574 pc=0x806f4fc
runtime.newstack(0x0)
	/home/iant/go/src/runtime/stack.go:1042 +0x23c fp=0xff889634 sp=0xff88957c pc=0x807b9ec
runtime.morestack()
	/home/iant/go/src/runtime/asm_386.s:465 +0x77 fp=0xff88963c sp=0xff889634 pc=0x8089717

goroutine 1 [runnable]:
runtime.activeModules(0x1860e000, 0x1, 0x2)
	/home/iant/go/src/runtime/symtab.go:412 +0x64 fp=0x1864bf38 sp=0x1864bf34 pc=0x807d924
runtime.cgoIsGoPointer(0x80df9a0, 0x8054001)
	/home/iant/go/src/runtime/cgocall.go:621 +0x1a fp=0x1864bf48 sp=0x1864bf38 pc=0x804b25a
runtime.cgoCheckWriteBarrier(0x18600168, 0x80df9a0)
	/home/iant/go/src/runtime/cgocheck.go:22 +0x11 fp=0x1864bf60 sp=0x1864bf48 pc=0x804b3c1
runtime.writebarrierptr(0x18600168, 0x80df9a0)
	/home/iant/go/src/runtime/mbarrier.go:204 +0x90 fp=0x1864bf78 sp=0x1864bf60 pc=0x80540f0
runtime.dolockOSThread(...)
	/home/iant/go/src/runtime/proc.go:3154
runtime.lockOSThread(...)
	/home/iant/go/src/runtime/proc.go:3170
runtime.cgocall(0x808f5c0, 0x1864bfa8, 0x0)
	/home/iant/go/src/runtime/cgocall.go:109 +0x130 fp=0x1864bf94 sp=0x1864bf78 pc=0x804a2e0
main._Cfunc_f1(0x0)
	command-line-arguments/_obj/_cgo_gotypes.go:51 +0x3b fp=0x1864bfa8 sp=0x1864bf94 pc=0x808f27b
main.main()
	/home/iant/foo8.go:16 +0x1e fp=0x1864bfc4 sp=0x1864bfa8 pc=0x808f38e
runtime.main()
	/home/iant/go/src/runtime/proc.go:185 +0x1f6 fp=0x1864bff0 sp=0x1864bfc4 pc=0x806a266
runtime.goexit()
	/home/iant/go/src/runtime/asm_386.s:1635 +0x1 fp=0x1864bff4 sp=0x1864bff0 pc=0x808b1f1
```

@ianlancetaylor
Copy link
Contributor

The comment on doLockOSThread says "Do not allow preemption during this call, or else the m might be different in this function than in the caller." So the problem is straightforward enough: we are allowing preemption during the call because the write barrier calls the cgo checker which calls activeModules which is not marked nosplit.

@gopherbot
Copy link

Change https://golang.org/cl/53352 mentions this issue: runtime: mark activeModules nosplit/nowritebarrier

@ianlancetaylor
Copy link
Contributor

CL 53352 has a fix and a test case that fails reliably with GOARCH=386 but never seems to fail with GOARCH=amd64. I don't know what the difference between 386 and amd64 is here.

@ianlancetaylor ianlancetaylor mentioned this issue Aug 4, 2017
Open
@gopherbot
Copy link

Change https://golang.org/cl/53415 mentions this issue: misc/cgo/errors: update ptr.go comment

gopherbot pushed a commit that referenced this issue Aug 8, 2017
@ianlancetaylor
misc/cgo/errors: update ptr.go comment
4fa2674 
Accidentally omitted from submit of CL 53352.

Updates #21306

Change-Id: I022d89c6417fe9371856d49b646eb6294b91657c
Reviewed-on: https://go-review.googlesource.com/53415
Reviewed-by: Austin Clements <austin@google.com>
Reviewed-by: Avelino <t@avelino.xxx>
@golang golang locked and limited conversation to collaborators Aug 5, 2018
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.
Projects
None yet
Milestone
Go1.9
Development

No branches or pull requests
4 participants
@bradfitz @aclements @ianlancetaylor @gopherbot