Go: runtime: fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)

Created on 5 Mar 2020 · 19Comments · Source: golang/go

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

$ go version
go1.14 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

What did you do?

I built a version of my program with a minor code change, and for the first time switching from the go 1.13 compiler to go 1.14. I then deployed that version of the program to my staging environment, all linux/amd64 machines.

What did you expect to see?

The program to start up normally on all hosts.

What did you see instead?

On about half of the hosts, the program crashed on startup with slight variations on this message:

runtime: pointer 0xc0034fbd40 to unused region of span span.base()=0xc006bf2000 span.limit=0xc006c67300 span.state=1
runtime: found in object at *(0xc000425110+0x28)
object=0xc000425110 s.base()=0xc000424000 s.limit=0xc000425fb0 s.spanclass=28 s.elemsize=208 s.state=mSpanInUse
 *(object+0) = 0x1010100000080
 *(object+8) = 0xc0034fb980
 *(object+16) = 0x8726ce
 *(object+24) = 0x0
 *(object+32) = 0x0
 *(object+40) = 0xc0034fbd40 <==
 *(object+48) = 0xc0a6c8
 *(object+56) = 0xc0034fbaf0
 *(object+64) = 0x872431
 *(object+72) = 0x0
 *(object+80) = 0x0
 *(object+88) = 0x0
 *(object+96) = 0x0
 *(object+104) = 0x0
 *(object+112) = 0x0
 *(object+120) = 0x0
 *(object+128) = 0x0
 *(object+136) = 0x0
 *(object+144) = 0x0
 *(object+152) = 0x0
 *(object+160) = 0x0
 *(object+168) = 0x0
 *(object+176) = 0x0
 *(object+184) = 0x0
 *(object+192) = 0x0
 *(object+200) = 0x0
fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)
runtime stack:
runtime.throw(0xbc9a25, 0x3e)
        /opt/go/src/runtime/panic.go:1112 +0x72 fp=0x7fb9c77fdd30 sp=0x7fb9c77fdd00 pc=0x436132
runtime.badPointer(0x7fba3c4cf108, 0xc0034fbd40, 0xc000425110, 0x28)
        /opt/go/src/runtime/mbitmap.go:380 +0x230 fp=0x7fb9c77fdd78 sp=0x7fb9c77fdd30 pc=0x416410
runtime.findObject(0xc0034fbd40, 0xc000425110, 0x28, 0x7fba3c659d20, 0xc000036e98, 0x7)
        /opt/go/src/runtime/mbitmap.go:416 +0x9b fp=0x7fb9c77fddb0 sp=0x7fb9c77fdd78 pc=0x4164bb
runtime.scanobject(0xc000425110, 0xc000036e98)
        /opt/go/src/runtime/mgcmark.go:1274 +0x235 fp=0x7fb9c77fde40 sp=0x7fb9c77fddb0 pc=0x421555
runtime.gcDrain(0xc000036e98, 0x2)
        /opt/go/src/runtime/mgcmark.go:1032 +0x1fb fp=0x7fb9c77fde98 sp=0x7fb9c77fde40 pc=0x420d5b
runtime.gcBgMarkWorker.func2()
        /opt/go/src/runtime/mgc.go:1951 +0x11e fp=0x7fb9c77fded8 sp=0x7fb9c77fde98 pc=0x46383e
runtime.systemstack(0x7fb9e6ffcb70)
        /opt/go/src/runtime/asm_amd64.s:370 +0x66 fp=0x7fb9c77fdee0 sp=0x7fb9c77fded8 pc=0x466976
runtime.mstart()
        /opt/go/src/runtime/proc.go:1041 fp=0x7fb9c77fdee8 sp=0x7fb9c77fdee0 pc=0x43af10

I don't use unsafe or cgo in my program directly, though some of my transitive dependencies might, I can't say for sure.

NeedsInvestigation

Source

peterbourgon

Most helpful comment

Yes, thanks for bisecting it! I have reproduced it on my system, so I will start debugging it.

danscales on 20 Mar 2020

🎉2 👍1

All 19 comments

cc @aclements @randall77

myitcv on 5 Mar 2020

See also #37506, #37502, #35541, #32324.

(CC @mknyszek)

bcmills on 5 Mar 2020

👍1

@peterbourgon, does a binary built with -race exhibit the same failure mode? (And, importantly, does it detect any races?)

bcmills on 5 Mar 2020

Frustratingly, I've been unable to reproduce, even with the same binary on the same host. I'm still working at it...

peterbourgon on 5 Mar 2020

I'm seeing the same issue with a package I maintain. Fails with 1.14.0 without -race, does not fail with -race (and there are no races reported) or 1.13.8. Also on linux/amd64.

To reproduce:

go test -count=100 go.elastic.co/apm/module/apmrestful

If I skip all the tests that involve panic recovery, then it no longer reproduces:

go test -count=100 -run 'TestMassageRoutePath|TestContainerFilter$|TestContainerFilterUnknownRoute|TestHandlerHTTPSuite/TestImplicitWrite' go.elastic.co/apm/module/apmrestful

axw on 9 Mar 2020

If I skip all the tests that involve panic recovery, then it no longer reproduces:

Possibly related to #37664 ? @danscales

randall77 on 9 Mar 2020

Though it's always possible, this doesn't look likely related to #37664 . In that bug, I would expect either an invalid pc during a traceback (gentraceback()) from a stale defer or a problem during adjustdefers() or tracebackdefers() in scanstack(). It would easy to confirm if we have a repro case (but that's hard to come by, I know).

danscales on 9 Mar 2020

@danscales the repro is in https://github.com/golang/go/issues/37688#issuecomment-596309132, but I've applied https://go-review.googlesource.com/c/go/+/222420/ locally and it doesn't resolve the issue.

axw on 10 Mar 2020

Small update: just confirmed that this issue persists with 1.14.1. I ran a git bisect between 1.13.8 and 1.14.0, and the first bad commit is dad616375f054d0644e006d7794724186d7a6720

axw on 20 Mar 2020

Thanks. That is https://golang.org/cl/190098 which added low-cost defers. @danscales

ianlancetaylor on 20 Mar 2020

Yes, thanks for bisecting it! I have reproduced it on my system, so I will start debugging it.

danscales on 20 Mar 2020

🎉2 👍1

I understand the cause and have a simple fix. Working to see if I can create a much simpler test that can reproduce the problem. Not sure if that will be doable, because of the complex interactions and non-determinism involving the GC, etc.

danscales on 20 Mar 2020

🎉1

@gopherbot Please open a backport to 1.14. This problem causes program crashes with no workaround.

ianlancetaylor on 20 Mar 2020

Backport issue(s) opened: #37968 (for 1.14).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

gopherbot on 20 Mar 2020

Change https://golang.org/cl/224581 mentions this issue: runtime: fix code so defer is not added to g0 defer list

gopherbot on 21 Mar 2020

Change https://golang.org/cl/225279 mentions this issue: [release-branch.go1.14] runtime: fix code so defer record is not added to g0 defer list during panic

gopherbot on 24 Mar 2020

Hello, I'm seeing panics such as the one this ticket shows with go1.14.4 but NOT with go1.14.2.

https://github.com/golang/go/issues/37968 says these are addressed with go1.14.2, so have they sneaked back in somehow?

runtime: pointer 0xc00050d0d0 to unallocated span span.base()=0xc000506000 span.limit=0xc00050e000 span.state=0
runtime: found in object at *(0xc000125e00+0x50)
object=0xc000125e00 s.base()=0xc000124000 s.limit=0xc000125fe0 s.spanclass=14 s.elemsize=96 s.state=mSpanInUse
 *(object+0) = 0xc0005146f0
 *(object+8) = 0xc00032ae00
 *(object+16) = 0x2
 *(object+24) = 0x4
 *(object+32) = 0xc0005146c0
 *(object+40) = 0x4080000000000000
 *(object+48) = 0x409c480000000000
 *(object+56) = 0x4070000000000000
 *(object+64) = 0x4080000000000000
 *(object+72) = 0x4080000000000000
 *(object+80) = 0xc00050d0d0 <==
 *(object+88) = 0x0
fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)
runtime stack:
runtime.throw(0x1c9b182, 0x3e)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/panic.go:1116 +0x72 fp=0x700004433d98 sp=0x700004433d68 pc=0x10363a2
runtime.badPointer(0xaa5ba20, 0xc00050d0d0, 0xc000125e00, 0x50)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/mbitmap.go:380 +0x230 fp=0x700004433de0 sp=0x700004433d98 pc=0x1016e10
runtime.findObject(0xc00050d0d0, 0xc000125e00, 0x50, 0xaa56600, 0xc000053698, 0x24)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/mbitmap.go:416 +0x9b fp=0x700004433e18 sp=0x700004433de0 pc=0x1016ebb
runtime.scanobject(0xc000125e00, 0xc000053698)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/mgcmark.go:1274 +0x235 fp=0x700004433ea8 sp=0x700004433e18 pc=0x1021c65
runtime.gcDrain(0xc000053698, 0x3)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/mgcmark.go:1032 +0x1fb fp=0x700004433f00 sp=0x700004433ea8 pc=0x102146b
runtime.gcBgMarkWorker.func2()
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/mgc.go:1940 +0x80 fp=0x700004433f40 sp=0x700004433f00 pc=0x1063e10
runtime.systemstack(0x2f00000)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/asm_amd64.s:370 +0x66 fp=0x700004433f48 sp=0x700004433f40 pc=0x1066ba6
runtime.mstart()
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.4/go/src/runtime/proc.go:1041 fp=0x700004433f50 sp=0x700004433f48 pc=0x103b1d0

abhinavdangeti on 19 Jun 2020

~Apologies, I had probably not cleaned up my workspace after I upgraded the go version the first time. I can't see the panics any longer.~

I see the panics with 1.14.3 as well ..

runtime: pointer 0xc0005e30d0 to unused region of span span.base()=0xc000390000 span.limit=0xc000391f80 span.state=1
runtime: found in object at *(0xc000307860+0x50)
object=0xc000307860 s.base()=0xc000306000 s.limit=0xc000307fe0 s.spanclass=14 s.elemsize=96 s.state=mSpanInUse
 *(object+0) = 0xc000119b90
 *(object+8) = 0xc0002ef880
 *(object+16) = 0x1
 *(object+24) = 0x4
 *(object+32) = 0xc000119b60
 *(object+40) = 0x4080000000000000
 *(object+48) = 0x409c600000000000
 *(object+56) = 0x4070000000000000
 *(object+64) = 0x4080000000000000
 *(object+72) = 0x4080000000000000
 *(object+80) = 0xc0005e30d0 <==
 *(object+88) = 0x0
fatal error: found bad pointer in Go heap (incorrect use of unsafe or cgo?)

runtime stack:
runtime.throw(0x1c9b282, 0x3e)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/panic.go:1116 +0x72 fp=0x70000eab3d98 sp=0x70000eab3d68 pc=0x10363a2
runtime.badPointer(0x2f55038, 0xc0005e30d0, 0xc000307860, 0x50)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/mbitmap.go:380 +0x230 fp=0x70000eab3de0 sp=0x70000eab3d98 pc=0x1016e10
runtime.findObject(0xc0005e30d0, 0xc000307860, 0x50, 0x2f11a20, 0xc00004e698, 0x92)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/mbitmap.go:416 +0x9b fp=0x70000eab3e18 sp=0x70000eab3de0 pc=0x1016ebb
runtime.scanobject(0xc000307860, 0xc00004e698)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/mgcmark.go:1274 +0x235 fp=0x70000eab3ea8 sp=0x70000eab3e18 pc=0x1021c65
runtime.gcDrain(0xc00004e698, 0x3)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/mgcmark.go:1032 +0x1fb fp=0x70000eab3f00 sp=0x70000eab3ea8 pc=0x102146b
runtime.gcBgMarkWorker.func2()
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/mgc.go:1940 +0x80 fp=0x70000eab3f40 sp=0x70000eab3f00 pc=0x1063d60
runtime.systemstack(0xb900000)
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/asm_amd64.s:370 +0x66 fp=0x70000eab3f48 sp=0x70000eab3f40 pc=0x1066af6
runtime.mstart()
    /Users/abhinavdangeti/.cbdepscache/exploded/x86_64/go-1.14.3/go/src/runtime/proc.go:1041 fp=0x70000eab3f50 sp=0x70000eab3f48 pc=0x103b200

abhinavdangeti on 19 Jun 2020

@abhinavdangeti, please open a new issue and include details on what you tried that failed, with a reproducer program or directions on how to replicate your situation.