runtime: TestGdbPython failure with "PC not saved" on linux-s390x-ibm

[bcmills]

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
--- FAIL: TestGdbPython (0.51s)
    runtime-gdb_test.go:76: gdb version 8.2
    runtime-gdb_test.go:265: gdb output:
        Loading Go Runtime support.
        Loaded  Script                                                                 
        Yes     /data/golang/workdir/go/src/runtime/runtime-gdb.py                     
        Breakpoint 1 at 0xa65c0: file /data/golang/workdir/tmp/TestGdbPython3954872015/001/main.go, line 26.
        hi
        
        Thread 1 "a.exe" hit Breakpoint 1, main.main () at /data/golang/workdir/tmp/TestGdbPython3954872015/001/main.go:26
        26		gslice = slicevar
        BEGIN info goroutines
        * 1 running  syscall.Syscall
          2 waiting  runtime.gopark
          3 waiting  runtime.gopark
          4 waiting  runtime.gopark
        * 5 running  runtime.runfinq
        END
        BEGIN print mapvar
        $1 = map[string]string = {["abc"] = "def", ["ghi"] = "jkl"}
        END
        BEGIN print slicemap
        $2 = map[string][]string = {["e"] = []string = {"f", "g", "h"}, ["a"] = []string = {"b", "c", "d"}}
        END
        BEGIN print strvar
        $3 = "abc"
        END
        BEGIN print chanint
        $4 = chan int = {99, 11}
        END
        BEGIN print chanstr
        $5 = chan string = {"spongepants", "squarebob"}
        END
        BEGIN info locals
        mapvar = map[string]string = {["abc"] = "def", ["ghi"] = "jkl"}
        slicemap = map[string][]string = {["e"] = []string = {"f", "g", "h"}, ["a"] = []string = {"b", "c", "d"}}
        chanint = chan int = {99, 11}
        chanstr = chan string = {"spongepants", "squarebob"}
        ptrvar = <optimized out>
        slicevar = []string
        strvar = "abc"
        END
        BEGIN goroutine 1 bt
        #0  main.main () at /data/golang/workdir/tmp/TestGdbPython3954872015/001/main.go:26
        END
        BEGIN goroutine all bt
        #0  main.main () at /data/golang/workdir/tmp/TestGdbPython3954872015/001/main.go:26
        #0  runtime.gopark (unlockf={void (runtime.g *, void *, bool *)} 0xc000034fb8, lock=0x1584a0 <runtime.forcegc>, reason=17 '\021', traceEv=20 '\024', traceskip=1) at /data/golang/workdir/go/src/runtime/proc.go:364
        #1  0x000000000004ce4c in runtime.goparkunlock (lock=<optimized out>, reason=<optimized out>, traceEv=<optimized out>, traceskip=<optimized out>) at /data/golang/workdir/go/src/runtime/proc.go:369
        #2  runtime.forcegchelper () at /data/golang/workdir/go/src/runtime/proc.go:302
        #3  0x000000000007bec2 in runtime.goexit () at /data/golang/workdir/go/src/runtime/asm_s390x.s:742
        #0  runtime.gopark (unlockf={void (runtime.g *, void *, bool *)} 0xc0000357a8, lock=0x158620 <runtime.sweep>, reason=12 '\f', traceEv=20 '\024', traceskip=1) at /data/golang/workdir/go/src/runtime/proc.go:364
        #1  0x00000000000366fa in runtime.goparkunlock (lock=<optimized out>, reason=<optimized out>, traceEv=<optimized out>, traceskip=<optimized out>) at /data/golang/workdir/go/src/runtime/proc.go:369
        #2  runtime.bgsweep (c=chan int) at /data/golang/workdir/go/src/runtime/mgcsweep.go:278
        #3  0x0000000000029448 in runtime.gcenable.func1 () at /data/golang/workdir/go/src/runtime/mgc.go:178
        #4  0x000000000007bec2 in runtime.goexit () at /data/golang/workdir/go/src/runtime/asm_s390x.s:742
        #0  runtime.gopark (unlockf={void (runtime.g *, void *, bool *)} 0xc000035f88, lock=0x158660 <runtime.scavenger>, reason=13 '\r', traceEv=20 '\024', traceskip=2) at /data/golang/workdir/go/src/runtime/proc.go:364
        #1  0x00000000000341fc in runtime.goparkunlock (lock=<optimized out>, reason=<optimized out>, traceEv=<optimized out>, traceskip=<optimized out>) at /data/golang/workdir/go/src/runtime/proc.go:369
        #2  runtime.(*scavengerState).park (s=0x158660 <runtime.scavenger>) at /data/golang/workdir/go/src/runtime/mgcscavenge.go:389
        #3  0x0000000000034884 in runtime.bgscavenge (c=chan int) at /data/golang/workdir/go/src/runtime/mgcscavenge.go:617
        #4  0x00000000000293c8 in runtime.gcenable.func2 () at /data/golang/workdir/go/src/runtime/mgc.go:179
        #5  0x000000000007bec2 in runtime.goexit () at /data/golang/workdir/go/src/runtime/asm_s390x.s:742
        Traceback (most recent call last):
          File "/data/golang/workdir/go/src/runtime/runtime-gdb.py", line 543, in invoke
            self.invoke_per_goid(goid, cmd)
          File "/data/golang/workdir/go/src/runtime/runtime-gdb.py", line 558, in invoke_per_goid
            gdb.parse_and_eval('$pc = {0}'.format(str(pc)))
        gdb.error: PC not saved
        Error occurred in Python command: PC not saved
        END
        No breakpoint at main.go:15.
        Breakpoint 2 at 0xa66f4: file /data/golang/workdir/tmp/TestGdbPython3954872015/001/main.go, line 29.
        
        Thread 1 "a.exe" received signal SIGSEGV, Segmentation fault.
        0x0000000000000000 in ?? ()
        BEGIN goroutine 1 bt at the end
        No such goroutine:  1
        END
    runtime-gdb_test.go:105: malformed backtrace at line 0: No such goroutine:  1
FAIL
FAIL	runtime	22.142s

greplogs -l -e 'gdb\.error: PC not saved'
2022-06-15T17:37:53-c2c76c6/linux-s390x-ibm

(attn @golang/s390x; CC @golang/runtime)

[jonathan-albrecht-ibm]

I ran this test over the weekend with:

$ pwd
/home/jalbrecht/src/goroot/src/runtime
$ go test -timeout=0 -count=100000 -failfast -run "TestGdbPython$"

and it didn't fail until the second run with count=100000 so not easily reproducible. I think its worth mentioning #39204 for visibility.

The test output is below and contains the same traceback with the PC not saved error. Both times it looks like it happened when trying to print the backtrace for the running runtime.runfinq method.

Googling "PC not saved" turns up mostly s390x bugs reports although not a lot and no real resolution to any of the reports from what I can make of it.

I'm going to try and add some more gdb commands to see if there is any more info I can get about where in runtime.runfinq it is when this happens.

--- FAIL: TestGdbPython (0.62s)                                                                                                 runtime-gdb_test.go:76: gdb version 8.2                                                                                     runtime-gdb_test.go:265: gdb output:
        Loading Go Runtime support.
        Loaded  Script
        Yes     /home/jalbrecht/src/goroot/src/runtime/runtime-gdb.py
        Breakpoint 1 at 0xa65c0: file /tmp/TestGdbPython44043474/001/main.go, line 26.                                              hi
                                                                                                                                    Thread 1 "a.exe" hit Breakpoint 1, main.main () at /tmp/TestGdbPython44043474/001/main.go:26
        26              gslice = slicevar
        BEGIN info goroutines
        * 1 running  syscall.Syscall
          2 waiting  runtime.gopark
          17 waiting  runtime.gopark
          18 waiting  runtime.gopark
        * 3 running  runtime.runfinq
        END
        BEGIN print mapvar
        $1 = map[string]string = {["abc"] = "def", ["ghi"] = "jkl"}
        END
        BEGIN print slicemap
        $2 = map[string][]string = {["a"] = []string = {"b", "c", "d"}, ["e"] = []string = {"f", "g", "h"}}
        END
        BEGIN print strvar
        $3 = "abc"
        END
        BEGIN print chanint
        $4 = chan int = {99, 11}                                                                                                    END
        BEGIN print chanstr
        $5 = chan string = {"spongepants", "squarebob"}
        END
        BEGIN info locals                                                                                                           mapvar = map[string]string = {["abc"] = "def", ["ghi"] = "jkl"}
        slicemap = map[string][]string = {["a"] = []string = {"b", "c", "d"}, ["e"] = []string = {"f", "g", "h"}}                   chanint = chan int = {99, 11}
        chanstr = chan string = {"spongepants", "squarebob"}
        ptrvar = <optimized out>
        slicevar = []string
        strvar = "abc"
        END
        BEGIN goroutine 1 bt
        #0  main.main () at /tmp/TestGdbPython44043474/001/main.go:26
        END
        BEGIN goroutine all bt
        #0  main.main () at /tmp/TestGdbPython44043474/001/main.go:26
        #0  runtime.gopark (unlockf={void (runtime.g *, void *, bool *)} 0xc000038fb8, lock=0x1584a0 <runtime.forcegc>, reason=17 '\021', traceEv=20 '\024', traceskip=1) at /home/jalbrecht/src/goroot/src/runtime/proc.go:364
        #1  0x000000000004ce4c in runtime.goparkunlock (lock=<optimized out>, reason=<optimized out>, traceEv=<optimized out>, traceskip=<optimized out>) at /home/jalbrecht/src/goroot/src/runtime/proc.go:369
        #2  runtime.forcegchelper () at /home/jalbrecht/src/goroot/src/runtime/proc.go:302
        #3  0x000000000007bec2 in runtime.goexit () at /home/jalbrecht/src/goroot/src/runtime/asm_s390x.s:742
        #0  runtime.gopark (unlockf={void (runtime.g *, void *, bool *)} 0xc0000347a8, lock=0x158620 <runtime.sweep>, reason=12 '\f', traceEv=20 '\024', traceskip=1) at /home/jalbrecht/src/goroot/src/runtime/proc.go:364
        #1  0x00000000000366fa in runtime.goparkunlock (lock=<optimized out>, reason=<optimized out>, traceEv=<optimized out>, traceskip=<optimized out>) at /home/jalbrecht/src/goroot/src/runtime/proc.go:369
        #2  runtime.bgsweep (c=chan int) at /home/jalbrecht/src/goroot/src/runtime/mgcsweep.go:278
        #3  0x0000000000029448 in runtime.gcenable.func1 () at /home/jalbrecht/src/goroot/src/runtime/mgc.go:178
        #4  0x000000000007bec2 in runtime.goexit () at /home/jalbrecht/src/goroot/src/runtime/asm_s390x.s:742
        #0  runtime.gopark (unlockf={void (runtime.g *, void *, bool *)} 0xc000034f88, lock=0x158660 <runtime.scavenger>, reason=13 '\r', traceEv=20 '\024', traceskip=2) at /home/jalbrecht/src/goroot/src/runtime/proc.go:364
        #1  0x00000000000341fc in runtime.goparkunlock (lock=<optimized out>, reason=<optimized out>, traceEv=<optimized out>, traceskip=<optimized out>) at /home/jalbrecht/src/goroot/src/runtime/proc.go:369
        #2  runtime.(*scavengerState).park (s=0x158660 <runtime.scavenger>) at /home/jalbrecht/src/goroot/src/runtime/mgcscavenge.go:389
        #3  0x0000000000034884 in runtime.bgscavenge (c=chan int) at /home/jalbrecht/src/goroot/src/runtime/mgcscavenge.go:617
        #4  0x00000000000293c8 in runtime.gcenable.func2 () at /home/jalbrecht/src/goroot/src/runtime/mgc.go:179
        #5  0x000000000007bec2 in runtime.goexit () at /home/jalbrecht/src/goroot/src/runtime/asm_s390x.s:742
        Traceback (most recent call last):
          File "/home/jalbrecht/src/goroot/src/runtime/runtime-gdb.py", line 543, in invoke
            self.invoke_per_goid(goid, cmd)
          File "/home/jalbrecht/src/goroot/src/runtime/runtime-gdb.py", line 558, in invoke_per_goid
            gdb.parse_and_eval('$pc = {0}'.format(str(pc)))                                                                         
        gdb.error: PC not saved
        Error occurred in Python command: PC not saved                                                                              
        END
        No breakpoint at main.go:15.
        Breakpoint 2 at 0xa66f4: file /tmp/TestGdbPython44043474/001/main.go, line 29.

        Thread 1 "a.exe" received signal SIGSEGV, Segmentation fault.
        0x0000000000000000 in ?? ()
        BEGIN goroutine 1 bt at the end                                                                                             
        No such goroutine:  1
        END                                                                                                                    
    runtime-gdb_test.go:105: malformed backtrace at line 0: No such goroutine:  1
FAIL
exit status 1
FAIL    runtime 1802.724s