Crash in syscall / morestack / newstack

[tlbtlbtlb]

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

go version go1.6 linux/amd64

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH=""
GORACE=""
GOROOT="/usr/lib/go"
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GO15VENDOREXPERIMENT="1"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0"
CXX="g++"
CGO_ENABLED="1"

What did you do?

Our VNC client written in Go (github.com/openai/go-vncdriver) linked into a Python program using CGO, crashes occasionally (on the order of once every 200 hours of CPU time) when allocating more stack.

What did you expect to see?

No crash

What did you see instead?

Crash:

runtime: newstack sp=0xc820cd9380 stack=[0xc820cd2000, 0xc820cd9fa0]
        morebuf={pc:0x7fc458f55f6f sp:0xc820cd9388 lr:0x0}
        sched={pc:0x7fc458f3c617 sp:0xc820cd9380 lr:0x0 ctxt:0x0}
runtime: failed to unwind through stackBarrier at SP 0xc820cd9388; [ @@@ ==>]
fatal error: inconsistent state in stackBarrier

runtime stack:
runtime.throw(0x7fc4593dbba0, 0x22)
        /usr/lib/go-1.6/src/runtime/panic.go:547 +0x92
runtime.gentraceback(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000, 0x0, 0x0, 0x64, 0x0, 0x0, 0x0, ...)
        /usr/lib/go-1.6/src/runtime/traceback.go:215 +0x1743
runtime.traceback1(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000, 0x0)
        /usr/lib/go-1.6/src/runtime/traceback.go:591 +0xca
runtime.traceback(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000)
        /usr/lib/go-1.6/src/runtime/traceback.go:568 +0x4a
runtime.newstack()
        /usr/lib/go-1.6/src/runtime/stack.go:833 +0x56d
runtime.morestack()
        /usr/lib/go-1.6/src/runtime/asm_amd64.s:359 +0x74

goroutine 19 [syscall, locked to thread]:
runtime: failed to unwind through stackBarrier at SP 0xc820cd9388; [ @@@ ==>]
fatal error: inconsistent state in stackBarrier
panic during panic

runtime stack:
runtime.startpanic_m()
        /usr/lib/go-1.6/src/runtime/panic.go:604 +0x13e
runtime.systemstack(0x7fc4593f04f8)
        /usr/lib/go-1.6/src/runtime/asm_amd64.s:307 +0xa1
runtime.startpanic()
        /usr/lib/go-1.6/src/runtime/panic.go:525 +0x14
runtime.throw(0x7fc4593dbba0, 0x22)
        /usr/lib/go-1.6/src/runtime/panic.go:546 +0x85
runtime.gentraceback(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000, 0x0, 0x0, 0x64, 0x0, 0x0, 0x0, ...)
        /usr/lib/go-1.6/src/runtime/traceback.go:215 +0x1743
runtime.traceback1(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000, 0x0)
        /usr/lib/go-1.6/src/runtime/traceback.go:591 +0xca
runtime.traceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc820112000)
        /usr/lib/go-1.6/src/runtime/traceback.go:568 +0x4a
runtime.tracebackothers(0xc820b8c000)
        /usr/lib/go-1.6/src/runtime/traceback.go:698 +0xb0
runtime.dopanic_m(0xc820b8c000, 0x7fc458f27de2, 0x7fc34a7fb7c8)
        /usr/lib/go-1.6/src/runtime/panic.go:644 +0x1f5
runtime.dopanic.func1()
        /usr/lib/go-1.6/src/runtime/panic.go:534 +0x34
runtime.systemstack(0x7fc34a7fb7a0)
        /usr/lib/go-1.6/src/runtime/asm_amd64.s:307 +0xa1
runtime.dopanic(0x0)
        /usr/lib/go-1.6/src/runtime/panic.go:535 +0x63
runtime.throw(0x7fc4593dbba0, 0x22)
        /usr/lib/go-1.6/src/runtime/panic.go:547 +0x92
runtime.gentraceback(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000, 0x0, 0x0, 0x64, 0x0, 0x0, 0x0, ...)
        /usr/lib/go-1.6/src/runtime/traceback.go:215 +0x1743
runtime.traceback1(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000, 0x0)
        /usr/lib/go-1.6/src/runtime/traceback.go:591 +0xca
runtime.traceback(0x7fc458f55f6f, 0xc820cd9388, 0x0, 0xc820112000)
        /usr/lib/go-1.6/src/runtime/traceback.go:568 +0x4a
runtime.newstack()
        /usr/lib/go-1.6/src/runtime/stack.go:833 +0x56d
runtime.morestack()
        /usr/lib/go-1.6/src/runtime/asm_amd64.s:359 +0x74

It can't seem to print the backtrace since it died in stack reallocation. The goroutine in question (19) sits in a small loop where the backtrace usually looks like this:

#1  0x00007f8598781140 in runtime.netpollblock (pd=0x7f8514288078, mode=114, waitio=false, ~r3=121) at /usr/lib/go-1.6/src/runtime/netpoll.go:341
#2  0x00007f8598780602 in net.runtime_pollWait (pd=0x7f8514288078, mode=114, ~r2=859593999432) at /usr/lib/go-1.6/src/runtime/netpoll.go:160
#3  0x00007f859887bd0c in net.(*pollDesc).Wait (pd=0xc8200f0140, mode=114, ~r1=...) at /usr/lib/go-1.6/src/net/fd_poll_runtime.go:73
#4  0x00007f859887bd78 in net.(*pollDesc).WaitRead (pd=0xc8200f0140, ~r0=...) at /usr/lib/go-1.6/src/net/fd_poll_runtime.go:78
#5  0x00007f859887dbdc in net.(*netFD).Read (fd=0xc8200f00e0, p= []uint8 = {...}, n=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:250
#6  0x00007f8598891ed6 in net.(*conn).Read (c=0xc8200fe018, b= []uint8 = {...}, ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:172
#7  0x00007f8598834d68 in io.ReadAtLeast (r=..., buf= []uint8 = {...}, min=1, n=0, err=...) at /usr/lib/go-1.6/src/io/io.go:297
#8  0x00007f8598834ea4 in io.ReadFull (r=..., buf= []uint8 = {...}, n=0, err=...) at /usr/lib/go-1.6/src/io/io.go:315
#9  0x00007f85988b67af in encoding/binary.Read (r=..., order=..., data=0x7f85975050a8, ~r3=...) at /usr/lib/go-1.6/src/encoding/binary/binary.go:152
#10 0x00007f8598825221 in github.com/openai/go-vncdriver/vncclient.(*ClientConn).mainLoop (c=0x0) at /experiment/go-vncdriver/.build/src/github.com/openai/go-vncdriver/vncclient/client.go:567
#11 0x00007f85987b58b1 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998
#12 0x000000c82010e000 in ?? ()
#13 0x0000000000000000 in ?? ()

The goroutine's loop is here: https://github.com/openai/go-vncdriver/blob/master/vncclient/client.go#L565-L590. It doesn't recurse, so I wouldn't expect the stack to grow beyond a small limit.

[bradfitz]

Go 1.6 is no longer supported. In fact, development and bug fixes for Go 1.7 are even frozen, except for security fixes.

Could you try Go 1.8?