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

runtime: invalid pointer found on stack regression in Go1.15 triggered by mapassign in init #41816

Closed
extemporalgenome opened this issue Oct 6, 2020 · 4 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone

Comments

@extemporalgenome
Copy link
Contributor

extemporalgenome commented Oct 6, 2020

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

$ go version
go version go1.15.2 linux/amd64

Does this issue reproduce with the latest release?

Yes (this is the latest release).

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

docker pull golang:1.15 (as of Oct 6, 2020).

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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-build663181731=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Run go test on the same code that had been working from 1.10 through 1.14.

The <scrubbed>:91 line in the stack trace refers to a map assignment within an init function. The map is declared in the global scope, and is a map of string keys to large (several hundred byte) struct values. The map was initialized at declaration time using make without an explicit capacity hint.

What did you expect to see?

no panic/throw.

What did you see instead?

Repeatable, but not deterministic (happens 33% of the time) failures of the form:

runtime: bad pointer in frame <scrubbed>.init.0 at 0xc0006ffe60: 0x1e
fatal error: invalid pointer found on stack

runtime stack:
runtime.throw(0xe39e82, 0x1e)
	/usr/local/go/src/runtime/panic.go:1116 +0x72 fp=0xc000049688 sp=0xc000049658 pc=0x435bf2
runtime.adjustpointers(0xc0006fd9a0, 0xc000049778, 0xc000049b08, 0x1887ad0, 0x18fab20)
	/usr/local/go/src/runtime/stack.go:605 +0x1d6 fp=0xc0000496d8 sp=0xc000049688 pc=0x44dc56
runtime.adjustframe(0xc000049a18, 0xc000049b08, 0x18fab20)
	/usr/local/go/src/runtime/stack.go:647 +0x36b fp=0xc0000497a8 sp=0xc0000496d8 pc=0x44dfeb
runtime.gentraceback(0xffffffffffffffff, 0xffffffffffffffff, 0x0, 0xc000000180, 0x0, 0x0, 0x7fffffff, 0xe6e848, 0xc000049b08, 0x0, ...)
	/usr/local/go/src/runtime/traceback.go:334 +0x1195 fp=0xc000049a80 sp=0xc0000497a8 pc=0x459675
runtime.copystack(0xc000000180, 0x8000)
	/usr/local/go/src/runtime/stack.go:903 +0x299 fp=0xc000049c38 sp=0xc000049a80 pc=0x44e759
runtime.shrinkstack(0xc000000180)
	/usr/local/go/src/runtime/stack.go:1167 +0x13d fp=0xc000049c60 sp=0xc000049c38 pc=0x44f79d
runtime.scanstack(0xc000000180, 0xc00002ee98)
	/usr/local/go/src/runtime/mgcmark.go:815 +0x54e fp=0xc000049e68 sp=0xc000049c60 pc=0x41fd4e
runtime.markroot.func1()
	/usr/local/go/src/runtime/mgcmark.go:245 +0xc6 fp=0xc000049eb8 sp=0xc000049e68 pc=0x4610a6
runtime.markroot(0xc00002ee98, 0x14)
	/usr/local/go/src/runtime/mgcmark.go:218 +0x310 fp=0xc000049f38 sp=0xc000049eb8 pc=0x41e810
runtime.gcDrain(0xc00002ee98, 0x7)
	/usr/local/go/src/runtime/mgcmark.go:1108 +0x118 fp=0xc000049f90 sp=0xc000049f38 pc=0x420438
runtime.gcBgMarkWorker.func2()
	/usr/local/go/src/runtime/mgc.go:1981 +0x177 fp=0xc000049fd0 sp=0xc000049f90 pc=0x460f97
runtime.systemstack(0x0)
	/usr/local/go/src/runtime/asm_amd64.s:370 +0x66 fp=0xc000049fd8 sp=0xc000049fd0 pc=0x468726
runtime.mstart()
	/usr/local/go/src/runtime/proc.go:1116 fp=0xc000049fe0 sp=0xc000049fd8 pc=0x43adc0

goroutine 7 [GC worker (idle)]:
runtime.systemstack_switch()
	/usr/local/go/src/runtime/asm_amd64.s:330 fp=0xc000036f60 sp=0xc000036f58 pc=0x4686a0
runtime.gcBgMarkWorker(0xc00002d800)
	/usr/local/go/src/runtime/mgc.go:1945 +0x1be fp=0xc000036fd8 sp=0xc000036f60 pc=0x41d13e
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc000036fe0 sp=0xc000036fd8 pc=0x46a2e1
created by runtime.gcBgMarkStartWorkers
	/usr/local/go/src/runtime/mgc.go:1839 +0x77

goroutine 1 [GC assist marking (scan), locked to thread]:
runtime.systemstack_switch()
	/usr/local/go/src/runtime/asm_amd64.s:330 fp=0xc0006fd790 sp=0xc0006fd788 pc=0x4686a0
runtime.gcAssistAlloc(0xc000000180)
	/usr/local/go/src/runtime/mgcmark.go:546 +0x165 fp=0xc0006fd7f0 sp=0xc0006fd790 pc=0x41efa5
runtime.mallocgc(0x6b0, 0xd7f220, 0x90c08beba19f501, 0xf9849a08)
	/usr/local/go/src/runtime/malloc.go:952 +0x9bc fp=0xc0006fd890 sp=0xc0006fd7f0 pc=0x40dc3c
runtime.newobject(...)
	/usr/local/go/src/runtime/malloc.go:1195
runtime.mapassign(0xd3dd40, 0xc00053c420, 0xc0006fd9c8, 0x1197360)
	/usr/local/go/src/runtime/map.go:667 +0x28b fp=0xc0006fd910 sp=0xc0006fd890 pc=0x40fb0b
<scrubbed>.init.0()
	<scrubbed>:91 +0x959 fp=0xc0006ffec8 sp=0xc0006fd910 pc=0xbf2f19
runtime.doInit(0x18f3c80)
	/usr/local/go/src/runtime/proc.go:5625 +0x8a fp=0xc0006ffef8 sp=0xc0006ffec8 pc=0x4454aa
runtime.doInit(0x18f4b80)
	/usr/local/go/src/runtime/proc.go:5620 +0x57 fp=0xc0006fff28 sp=0xc0006ffef8 pc=0x445477
runtime.doInit(0x18f7ee0)
	/usr/local/go/src/runtime/proc.go:5620 +0x57 fp=0xc0006fff58 sp=0xc0006fff28 pc=0x445477
runtime.doInit(0x18f5580)
	/usr/local/go/src/runtime/proc.go:5620 +0x57 fp=0xc0006fff88 sp=0xc0006fff58 pc=0x445477
runtime.main()
	/usr/local/go/src/runtime/proc.go:191 +0x1c5 fp=0xc0006fffe0 sp=0xc0006fff88 pc=0x4383a5
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0006fffe8 sp=0xc0006fffe0 pc=0x46a2e1

goroutine 2 [force gc (idle)]:
runtime.gopark(0xe6eab0, 0x193fb40, 0x1411, 0x1)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc000034fb0 sp=0xc000034f90 pc=0x4387e5
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:312
runtime.forcegchelper()
	/usr/local/go/src/runtime/proc.go:255 +0xc5 fp=0xc000034fe0 sp=0xc000034fb0 pc=0x438685
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc000034fe8 sp=0xc000034fe0 pc=0x46a2e1
created by runtime.init.6
	/usr/local/go/src/runtime/proc.go:243 +0x35

goroutine 3 [GC sweep wait]:
runtime.gopark(0xe6eab0, 0x193fd00, 0x140c, 0x1)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc0000357a8 sp=0xc000035788 pc=0x4387e5
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:312
runtime.bgsweep(0xc000054000)
	/usr/local/go/src/runtime/mgcsweep.go:182 +0x13b fp=0xc0000357d8 sp=0xc0000357a8 pc=0x42467b
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0000357e0 sp=0xc0000357d8 pc=0x46a2e1
created by runtime.gcenable
	/usr/local/go/src/runtime/mgc.go:217 +0x5c

goroutine 4 [GC scavenge wait]:
runtime.gopark(0xe6eab0, 0x1940420, 0x140d, 0x1)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc000035f78 sp=0xc000035f58 pc=0x4387e5
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:312
runtime.bgscavenge(0xc000054000)
	/usr/local/go/src/runtime/mgcscavenge.go:314 +0x29c fp=0xc000035fd8 sp=0xc000035f78 pc=0x4227dc
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc000035fe0 sp=0xc000035fd8 pc=0x46a2e1
created by runtime.gcenable
	/usr/local/go/src/runtime/mgc.go:218 +0x7e

goroutine 5 [finalizer wait]:
runtime.gopark(0xe6eab0, 0x19719e8, 0xce1410, 0x1)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc000034758 sp=0xc000034738 pc=0x4387e5
runtime.goparkunlock(...)
	/usr/local/go/src/runtime/proc.go:312
runtime.runfinq()
	/usr/local/go/src/runtime/mfinal.go:175 +0xa9 fp=0xc0000347e0 sp=0xc000034758 pc=0x419409
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0000347e8 sp=0xc0000347e0 pc=0x46a2e1
created by runtime.createfing
	/usr/local/go/src/runtime/mfinal.go:156 +0x65

goroutine 6 [GC worker (idle)]:
runtime.gopark(0xe6e940, 0xc000094000, 0x1418, 0x0)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc000036760 sp=0xc000036740 pc=0x4387e5
runtime.gcBgMarkWorker(0xc000026000)
	/usr/local/go/src/runtime/mgc.go:1891 +0xff fp=0xc0000367d8 sp=0xc000036760 pc=0x41d07f
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0000367e0 sp=0xc0000367d8 pc=0x46a2e1
created by runtime.gcBgMarkStartWorkers
	/usr/local/go/src/runtime/mgc.go:1839 +0x77

goroutine 17 [GC worker (idle)]:
runtime.gopark(0xe6e940, 0xc000520000, 0x1418, 0x0)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc000030760 sp=0xc000030740 pc=0x4387e5
runtime.gcBgMarkWorker(0xc000028800)
	/usr/local/go/src/runtime/mgc.go:1891 +0xff fp=0xc0000307d8 sp=0xc000030760 pc=0x41d07f
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0000307e0 sp=0xc0000307d8 pc=0x46a2e1
created by runtime.gcBgMarkStartWorkers
	/usr/local/go/src/runtime/mgc.go:1839 +0x77

goroutine 33 [GC worker (idle)]:
runtime.gopark(0xe6e940, 0xc000279530, 0x1418, 0x0)
	/usr/local/go/src/runtime/proc.go:306 +0xe5 fp=0xc000528760 sp=0xc000528740 pc=0x4387e5
runtime.gcBgMarkWorker(0xc00002b000)
	/usr/local/go/src/runtime/mgc.go:1891 +0xff fp=0xc0005287d8 sp=0xc000528760 pc=0x41d07f
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc0005287e0 sp=0xc0005287d8 pc=0x46a2e1
created by runtime.gcBgMarkStartWorkers
	/usr/local/go/src/runtime/mgc.go:1839 +0x77
@randall77
Copy link
Contributor

The problem is in the generated code for that init function. The bad pointer was found at 0xc0006ffe60, and that's in the frame of the <scrubbed>.init.0 function.

<scrubbed>.init.0()
	<scrubbed>:91 +0x959 fp=0xc0006ffec8 sp=0xc0006fd910 pc=0xbf2f19

This doesn't necessarily have anything to do with maps. A map operation just happened to be the thing that triggered a stack copy. What else is in that init function? It would be really nice if we could see it...

@martisch martisch added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Oct 7, 2020
@odeke-em odeke-em changed the title invalid pointer found on stack (re: runtime.mapassign) runtime: invalid pointer found on stack regression in Go1.15 triggered by mapassign in init Oct 7, 2020
@extemporalgenome
Copy link
Contributor Author

@randall77 with identifiers renamed:

type itemPair struct {
  a schema.Item
  b schema.Item
}

var uuidToPair = make(map[string]itemPair)

func init() {
  now := time.Now().UTC()

  specialA := datapkg.LookupItem(SpecialStrConstA)
  specialB := datapkg.LookupItem(SpecialStrConstB)

  items := datapkg.ListItems()
  items = datapkg.FilterItemsByTime(items, now)

  for _, v := range items {
    itemUUID := v.Attrs.UUID
    if itemUUID == "" {
      continue
    }

    if isTypeB(v) {
      pair := itemPair{a: specialA, b: v}
      uuidToPair[itemUUID] = pair

      for _, uuid := range v.Attrs.AuxUUIDs {
        pair = uuidToPair[uuid]
        pair.b = v
        uuidToPair[uuid] = pair
      }
      continue
    }

    pair := itemPair{a: v, b: specialB}
    uuidToPair[itemUUID] = pair

    for _, uuid := range v.Attrs.AuxUUIDs {
      pair = uuidToPair[uuid]
      pair.a = v
      uuidToPair[uuid] = pair // <-- this is where the panic/throw occurred
    }
  }
}

@ianlancetaylor ianlancetaylor added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. and removed WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. labels Oct 12, 2020
@ianlancetaylor ianlancetaylor added this to the Go1.16 milestone Oct 12, 2020
@randall77
Copy link
Contributor

Hm, nothing obviously bad.
Anything you could do to help us reproduce would be great. We don't have a lot to go on at the moment.
Can we see the disassembled version of your init function?

@ianlancetaylor ianlancetaylor added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Oct 12, 2020
@gopherbot
Copy link

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)

@golang golang locked and limited conversation to collaborators Nov 12, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Development

No branches or pull requests

5 participants