runtime: fatal error: stopg: invalid status

[mundaym]

Seen once on the builder so far: https://build.golang.org/log/4c0ec95e51e895280902515d8fa6c608487d01a3

Possibly a subtle bug in the new SSA backend.

--- FAIL: TestChan (0.16s)
    ssa_test.go:32: Failed: exit status 2:
        Out: 
        Stderr: # command-line-arguments
        runtime: gp: gp=0xc420000340, goid=1, gp->atomicstatus=4097
        runtime:  g:  g=0xc42004e1a0, goid=0,  g->atomicstatus=0
        fatal error: stopg: invalid status

        runtime stack:
        runtime.throw(0x206ed6, 0x15)
            /data/golang/workdir/go/src/runtime/panic.go:560 +0x9a fp=0xc42005fe10 sp=0xc42005fdf8
        runtime.scang(0xc420000340, 0xc420017228)
            /data/golang/workdir/go/src/runtime/proc.go:811 +0x29e fp=0xc42005fe40 sp=0xc42005fe10
        runtime.markroot.func1()
            /data/golang/workdir/go/src/runtime/mgcmark.go:245 +0x7a fp=0xc42005fe78 sp=0xc42005fe40
        runtime.systemstack(0xc42005fed8)
            /data/golang/workdir/go/src/runtime/asm_s390x.s:263 +0xce fp=0xc42005fe80 sp=0xc42005fe78
        runtime.markroot(0xc420017228, 0x13002d7070)
            /data/golang/workdir/go/src/runtime/mgcmark.go:250 +0x34a fp=0xc42005fef0 sp=0xc42005fe80
        runtime.gcDrain(0xc420017228, 0x0)
            /data/golang/workdir/go/src/runtime/mgcmark.go:972 +0xea fp=0xc42005ff38 sp=0xc42005fef0
        runtime.gcMark(0x69d371484de07)
            /data/golang/workdir/go/src/runtime/mgc.go:1585 +0x11a fp=0xc42005ff78 sp=0xc42005ff38
        runtime.gcMarkTermination.func1()
            /data/golang/workdir/go/src/runtime/mgc.go:1186 +0x34 fp=0xc42005ff88 sp=0xc42005ff78
        runtime.systemstack(0xc420018a00)
            /data/golang/workdir/go/src/runtime/asm_s390x.s:250 +0x9a fp=0xc42005ff90 sp=0xc42005ff88
        runtime.mstart()
            /data/golang/workdir/go/src/runtime/proc.go:1079 fp=0xc42005ff90 sp=0xc42005ff90

        goroutine 5 [garbage collection]:
        runtime.systemstack_switch()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:204 +0x10 fp=0xc420023d28 sp=0xc420023d20
        runtime.gcMarkTermination()
            /data/golang/workdir/go/src/runtime/mgc.go:1194 +0x11c fp=0xc420023f20 sp=0xc420023d28
        runtime.gcMarkDone()
            /data/golang/workdir/go/src/runtime/mgc.go:1158 +0x234 fp=0xc420023f40 sp=0xc420023f20
        runtime.gcBgMarkWorker(0xc420016000)
            /data/golang/workdir/go/src/runtime/mgc.go:1505 +0x316 fp=0xc420023fb0 sp=0xc420023f40
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc420023fb0 sp=0xc420023fb0
        created by runtime.gcBgMarkStartWorkers
            /data/golang/workdir/go/src/runtime/mgc.go:1349 +0xb6

        goroutine 1 [runnable]:
        cmd/link/internal/ld.putelfsym(0xc42049a000, 0x0, 0x202154, 0x6, 0x6d, 0x30, 0x0, 0x0, 0x0)
            /data/golang/workdir/go/src/cmd/link/internal/ld/symtab.go:79 fp=0xc42005da50 sp=0xc42005da50
        cmd/link/internal/ld.genasmsym(0xc42049a000, 0x20f568)
            /data/golang/workdir/go/src/cmd/link/internal/ld/lib.go:1913 +0x25a fp=0xc42005db80 sp=0xc42005da50
        cmd/link/internal/ld.Asmelfsym(0xc42049a000)
            /data/golang/workdir/go/src/cmd/link/internal/ld/symtab.go:207 +0xd8 fp=0xc42005dbb8 sp=0xc42005db80
        cmd/link/internal/s390x.asmb(0xc42049a000)
            /data/golang/workdir/go/src/cmd/link/internal/s390x/asm.go:566 +0x778 fp=0xc42005dd48 sp=0xc42005dbb8
        cmd/link/internal/ld.Main()
            /data/golang/workdir/go/src/cmd/link/internal/ld/main.go:203 +0xb4a fp=0xc42005dec8 sp=0xc42005dd48
        cmd/link/internal/s390x.Main()
            /data/golang/workdir/go/src/cmd/link/internal/s390x/obj.go:44 +0x24 fp=0xc42005ded0 sp=0xc42005dec8
        main.main()
            /data/golang/workdir/go/src/cmd/link/main.go:38 +0x3ca fp=0xc42005df48 sp=0xc42005ded0
        runtime.main()
            /data/golang/workdir/go/src/runtime/proc.go:183 +0x23a fp=0xc42005df98 sp=0xc42005df48
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc42005df98 sp=0xc42005df98

        goroutine 2 [force gc (idle)]:
        runtime.gopark(0x20fac0, 0x2d67b0, 0x204e10, 0xf, 0x1400000000000000, 0x1)
            /data/golang/workdir/go/src/runtime/proc.go:259 +0x15c fp=0xc420022750 sp=0xc420022720
        runtime.goparkunlock(0x2d67b0, 0x204e10, 0xf, 0x140000c420000340, 0x1)
            /data/golang/workdir/go/src/runtime/proc.go:265 +0x5a fp=0xc420022788 sp=0xc420022750
        runtime.forcegchelper()
            /data/golang/workdir/go/src/runtime/proc.go:224 +0x94 fp=0xc4200227b8 sp=0xc420022788
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc4200227b8 sp=0xc4200227b8
        created by runtime.init.3
            /data/golang/workdir/go/src/runtime/proc.go:213 +0x30

        goroutine 3 [GC sweep wait]:
        runtime.gopark(0x20fac0, 0x2d6980, 0x2043fe, 0xd, 0x14000000000690e0, 0x1)
            /data/golang/workdir/go/src/runtime/proc.go:259 +0x15c fp=0xc420022f40 sp=0xc420022f10
        runtime.goparkunlock(0x2d6980, 0x2043fe, 0xd, 0x1400000000000000, 0x1)
            /data/golang/workdir/go/src/runtime/proc.go:265 +0x5a fp=0xc420022f78 sp=0xc420022f40
        runtime.bgsweep(0xc42004a000)
            /data/golang/workdir/go/src/runtime/mgcsweep.go:79 +0x124 fp=0xc420022fb0 sp=0xc420022f78
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc420022fb0 sp=0xc420022fb0
        created by runtime.gcenable
            /data/golang/workdir/go/src/runtime/mgc.go:204 +0x5a

        goroutine 4 [finalizer wait]:
        runtime.gopark(0x20fac0, 0x303ef0, 0x20493e, 0xe, 0x1400000000000000, 0x1)
            /data/golang/workdir/go/src/runtime/proc.go:259 +0x15c fp=0xc420023708 sp=0xc4200236d8
        runtime.goparkunlock(0x303ef0, 0x20493e, 0xe, 0x1400000000000000, 0x1)
            /data/golang/workdir/go/src/runtime/proc.go:265 +0x5a fp=0xc420023740 sp=0xc420023708
        runtime.runfinq()
            /data/golang/workdir/go/src/runtime/mfinal.go:158 +0xac fp=0xc4200237b8 sp=0xc420023740
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc4200237b8 sp=0xc4200237b8
        created by runtime.createfing
            /data/golang/workdir/go/src/runtime/mfinal.go:139 +0x7a

        goroutine 6 [GC worker (idle)]:
        runtime.gopark(0x20f968, 0xc420010540, 0x205120, 0x10, 0x1400000000000000, 0x0)
            /data/golang/workdir/go/src/runtime/proc.go:259 +0x15c fp=0xc420024740 sp=0xc420024710
        runtime.gcBgMarkWorker(0xc420017500)
            /data/golang/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc4200247b0 sp=0xc420024740
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc4200247b0 sp=0xc4200247b0
        created by runtime.gcBgMarkStartWorkers
            /data/golang/workdir/go/src/runtime/mgc.go:1349 +0xb6

        goroutine 7 [GC worker (idle)]:
        runtime.gopark(0x20f968, 0xc420010550, 0x205120, 0x10, 0x1400000000000000, 0x0)
            /data/golang/workdir/go/src/runtime/proc.go:259 +0x15c fp=0xc420024f40 sp=0xc420024f10
        runtime.gcBgMarkWorker(0xc420018a00)
            /data/golang/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc420024fb0 sp=0xc420024f40
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc420024fb0 sp=0xc420024fb0
        created by runtime.gcBgMarkStartWorkers
            /data/golang/workdir/go/src/runtime/mgc.go:1349 +0xb6

        goroutine 8 [GC worker (idle)]:
        runtime.gopark(0x20f968, 0xc420010560, 0x205120, 0x10, 0x1400000000000000, 0x0)
            /data/golang/workdir/go/src/runtime/proc.go:259 +0x15c fp=0xc420025740 sp=0xc420025710
        runtime.gcBgMarkWorker(0xc42001a000)
            /data/golang/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc4200257b0 sp=0xc420025740
        runtime.goexit()
            /data/golang/workdir/go/src/runtime/asm_s390x.s:1022 +0x2 fp=0xc4200257b0 sp=0xc4200257b0
        created by runtime.gcBgMarkStartWorkers
            /data/golang/workdir/go/src/runtime/mgc.go:1349 +0xb6

FAIL

[bradfitz]

I feel like I've seen that error elsewhere, though. @aclements?

[billotosyr]

Not a go test, but a test of something written in go.
cockroachdb/cockroach#9043
I assume this was run on amd64/x86

[aclements]

@bradfitz, you saw it in the trybot run of CL 26762: https://storage.googleapis.com/go-build-log/2b07a28a/nacl-amd64p32_70247f4c.log

Comment 1 is the only time this has ever shown up on the build dashboard, at least for master.

[gopherbot]

CL https://golang.org/cl/29280 mentions this issue.

[colincross]

The Android build (which uses go) was updated to 1.7 on Aug 17, since then we've seen 4 occurrences of "fatal error: stopg: invalid status" on the build bots, and I just saw one on a local build.

[aclements]

We've had one failure since I put in the consistency check:

2016-09-26T15:46:44-375092b/linux-amd64:

# go run run.go -- chan/select.go
exit status 2
# command-line-arguments
runtime: gp 0xc420001860 found at rescan index 0 but should be at 33
runtime: gp 0xc4204c0000 found at rescan index 2 but should be at 35
fatal error: bad g rescan index
fatal error: bad g rescan index
runtime: gp 0xc42007e680 found at rescan index 7 but should be at 41
runtime: gp 0xc42007e820 found at rescan index 8 but should be at 42
fatal error: bad g rescan index
runtime: gp 0xc4204c0340 found at rescan index 4 but should be at 37
fatal error: bad g rescan index
runtime: gp 0xc420001a00 found at rescan index 1 but should be at 34
fatal error: bad g rescan index
runtime: gp 0xc42007e340 found at rescan index 6 but should be at 39
fatal error: bad g rescan index
runtime: gp 0xc4204c04e0 found at rescan index 5 but should be at 38
fatal error: bad g rescan index
fatal error: bad g rescan index
runtime: gp 0xc4204c01a0 found at rescan index 3 but should be at 36
runtime: gp 0xc42007e4e0 found at rescan index 9 but should be at 40
fatal error: bad g rescan index
fatal error: bad g rescan index
runtime: gp 0xc4204c0680 found at rescan index 10 but should be at 43
fatal error: bad g rescan index

I'm not sure what's going on here, but it's interesting that a whole pile of Gs were in the wrong places on the rescan list (all of these errors happened while the first error was just trying to get the panic out the door). This suggests we have some sort of ordering issue that's completely smashing the state of the rescan list.

[mundaym]

Another failure on the s390x builder: https://build.golang.org/log/2fe597deb692316d5bf7b07bcb0a787e94a8c185

Some of the pointers seem to match up with the amd64 failure: 0xc420001860 at index 0 and 0xc420001a00 at index 1.

# trivial
runtime: gp 0xc420001860 found at rescan index 0 but should be at 17
runtime: gp 0xc420001ba0 found at rescan index 2 but should be at 19
fatal error: bad g rescan index
runtime: gp 0xc420001d40 found at rescan index 3 but should be at 20
fatal error: bad g rescan index
runtime: gp 0xc420001a00 found at rescan index 1 but should be at 18
fatal error: bad g rescan index
fatal error: bad g rescan index

[bradfitz]

Another trybot flake on linux-amd64:
https://storage.googleapis.com/go-build-log/62ffb414/linux-amd64_7b2388cc.log

[aclements]

Just got an internal bug report of a "rescan list overflow" panic:

fatal error: rescan list overflow

runtime stack:
runtime.throw(0x5d26b9, 0x14)
      .../go/gc/src/runtime/panic.go:569 +0x9e
runtime.queueRescan(0xc42976e820)
      .../go/gc/src/runtime/mgcmark.go:885 +0x103
runtime.newproc1(0x5e79c0, 0xc4255a57f0, 0x20, 0x4bce7b, 0xc42976e680)
      .../go/gc/src/runtime/proc.go:2788 +0x3be
runtime.newproc.func1()
      .../go/gc/src/runtime/proc.go:2716 +0x51
runtime.systemstack(0xc4204958a0)
      .../go/gc/src/runtime/asm_amd64.s:298 +0x79
runtime.mstart()
      .../go/gc/src/runtime/proc.go:1082

This is further evidence that we're adding a G to the rescan list more than once.

[mundaym]

A couple more failures on the builders @ 94f49fd:

amd64: https://build.golang.org/log/052fde13671350d57666b95b60eaf455dfed36e1
s390x: https://build.golang.org/log/e7b35b325878d29a540645a435cb0590b94a8aa3