runtime: "fatal error: mSpanList.insertBack" in mallocgc

[myitcv]

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

$ go version
go version devel +0ac8739ad5 Mon Nov 18 15:11:03 2019 +0000 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

go env Output

$ go env
GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/myitcv/.cache/go-build"
GOENV="/home/myitcv/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/myitcv/gostuff"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/myitcv/gos"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/myitcv/gos/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/myitcv/gostuff/src/github.com/myitcv/govim/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build649113178=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Got the following:

$ GOPROXY=direct go get golang.org/x/tools/gopls@master golang.org/x/tools@master
go: finding golang.org/x/tools master
go: finding golang.org/x/tools/gopls master
go: golang.org/x/tools master => v0.0.0-20191122080028-f774e2e2e5be
go: golang.org/x/tools/gopls master => v0.1.8-0.20191122080028-f774e2e2e5be
go: downloading golang.org/x/tools v0.0.0-20191122080028-f774e2e2e5be
go: downloading golang.org/x/tools/gopls v0.1.8-0.20191122080028-f774e2e2e5be
# golang.org/x/tools/go/analysis/passes/inspect
runtime: failed mSpanList.insertBack 0x7f80c3261060 0x4115c774f9191e87 0x0 0x0
fatal error: mSpanList.insertBack

goroutine 1 [running, locked to thread]:
runtime.throw(0xe55095, 0x14)
        /home/myitcv/dev/go/src/runtime/panic.go:1106 +0x72 fp=0xc000074b48 sp=0xc000074b18 pc=0x432152
runtime.(*mSpanList).insertBack(0x15d1d70, 0x7f80c3261060)
        /home/myitcv/dev/go/src/runtime/mheap.go:1521 +0x10b fp=0xc000074b80 sp=0xc000074b48 pc=0x42603b
runtime.(*mcentral).cacheSpan(0x15d1d50, 0xc000074c00)
        /home/myitcv/dev/go/src/runtime/mcentral.go:111 +0x2f5 fp=0xc000074bc8 sp=0xc000074b80 pc=0x416ba5
runtime.(*mcache).refill(0x7f80c54cfd98, 0x9)
        /home/myitcv/dev/go/src/runtime/mcache.go:138 +0x85 fp=0xc000074be8 sp=0xc000074bc8 pc=0x416655
runtime.(*mcache).nextFree(0x7f80c54cfd98, 0x43bc09, 0xc000000180, 0x200000003, 0xc000000180)
        /home/myitcv/dev/go/src/runtime/malloc.go:866 +0x87 fp=0xc000074c20 sp=0xc000074be8 pc=0x40baf7
runtime.mallocgc(0x30, 0x0, 0xc00001e000, 0xc0000161e0)
        /home/myitcv/dev/go/src/runtime/malloc.go:1034 +0x793 fp=0xc000074cc0 sp=0xc000074c20 pc=0x40c433
runtime.slicebytetostring(0x0, 0xc00001e080, 0x2d, 0x80, 0x0, 0x0)
        /home/myitcv/dev/go/src/runtime/string.go:102 +0x9f fp=0xc000074cf0 sp=0xc000074cc0 pc=0x44cf9f
os.Readlink(0xe4f963, 0xe, 0xc000074d98, 0x46c01d, 0xdec440, 0xc00005a1a0)
        /home/myitcv/dev/go/src/os/file_unix.go:417 +0xdf fp=0xc000074d68 sp=0xc000074cf0 pc=0x4b2e5f
os.glob..func1(0xe5ae50, 0x1c, 0x100a6c0, 0xc00005a1a0)
        /home/myitcv/dev/go/src/os/executable_procfs.go:29 +0x36 fp=0xc000074da8 sp=0xc000074d68 pc=0x4b5096
os.init()
        /home/myitcv/dev/go/src/os/executable_procfs.go:30 +0x15a fp=0xc000074dd8 sp=0xc000074da8 pc=0x4b523a
runtime.doInit(0x1532420)
        /home/myitcv/dev/go/src/runtime/proc.go:5432 +0x8a fp=0xc000074e08 sp=0xc000074dd8 pc=0x44101a
runtime.doInit(0x1531a60)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074e38 sp=0xc000074e08 pc=0x440fe7
runtime.doInit(0x1532320)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074e68 sp=0xc000074e38 pc=0x440fe7
runtime.doInit(0x1532620)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074e98 sp=0xc000074e68 pc=0x440fe7
runtime.doInit(0x15333e0)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074ec8 sp=0xc000074e98 pc=0x440fe7
runtime.doInit(0x15317c0)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074ef8 sp=0xc000074ec8 pc=0x440fe7
runtime.doInit(0x1535b80)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074f28 sp=0xc000074ef8 pc=0x440fe7
runtime.doInit(0x1531d20)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074f58 sp=0xc000074f28 pc=0x440fe7
runtime.doInit(0x1533160)
        /home/myitcv/dev/go/src/runtime/proc.go:5427 +0x57 fp=0xc000074f88 sp=0xc000074f58 pc=0x440fe7
runtime.main()
        /home/myitcv/dev/go/src/runtime/proc.go:190 +0x1ce fp=0xc000074fe0 sp=0xc000074f88 pc=0x4345ce
runtime.goexit()
        /home/myitcv/dev/go/src/runtime/asm_amd64.s:1375 +0x1 fp=0xc000074fe8 sp=0xc000074fe0 pc=0x462a21

Unable to reproduce.

What did you expect to see?

No fatal error

What did you see instead?

Per above

CC @mdempsky @aclements @mknyszek @ianlancetaylor @bcmills

[bcmills]

This looks like a runtime bug. Might be related to the new bitmap allocator.

Thanks for the report!

[mknyszek]

@myitcv Thanks!

@bcmills The span is indeed coming out of the new allocator, but the problem here is that its' next field is non-nil. And in fact, it's some really bizarre value (0x4115c774f9191e87) which doesn't look like it's any range familiar to me. In that way, it's similar to some of the other bugs (and the value is equally bizarre there as well). The span pointer itself looks reasonable.

I've just confirmed that any span returned by mheap_.alloc (called by mcentral.grow, which is where the span above is coming from) has init called on it (unless its nil) which zeroes out the next field explicitly. In other words, even if there was a problem with say, a freed span being left on some linked list, it would never actually manifest in this way, because we always zero the field which is being checked here.

Based on the bizarre value (disclaimer: bizarre to me, maybe someone else has better insights), my next guess is that this is the manifestation of another memory corruption bug such as #35592.

I'll keep thinking about it.

[aclements]

Folding in to memory corruption super-bug (#35777) because this definitely looks like memory corruption, and because the pointer value looks like a random bit pattern.

@myitcv, any chance you've been able to reproduce this since your original report?

[myitcv]

Unfortunately not: same response as per #35689 (comment)

[aclements]

Thanks. Closing since it's not reproducible, but we'll keep track of this in the super-bug.