runtime: access violation in gentraceback on windows/386

[bcmills]

#!watchflakes
post <- builder ~ `windows` && `fatal error: unexpected signal during runtime execution\n\[signal 0xc0000005 .*` && `^runtime\.gentraceback`

greplogs --dashboard -md -l -e '(?ms)^fatal error: unexpected signal during runtime execution\n\[signal 0xc0000005.*^runtime\.gentraceback'

2021-12-13T18:45:54-2580d0e/windows-386-2012

##### ../misc/cgo/test
PASS
scatter = 01199220
sqrt is: 0
hello from C
ok  	misc/cgo/test	15.271s
PASS
scatter = 00402290
sqrt is: 0
hello from C
ok  	misc/cgo/test	14.725s
PASS
scatter = 01409220
sqrt is: 0
hello from C
ok  	misc/cgo/test	15.264s
PASS
scatter = 013C9220
sqrt is: 0
hello from C
ok  	misc/cgo/test	14.413s
Exception 0x200c7 0xf0030de8 0xcc483ff 0x0
PC=0x0

fatal error: unexpected signal during runtime execution
[signal 0xc0000005 code=0x0 addr=0x0 pc=0x12399a4]

runtime stack:
runtime.throw({0x136e0a5, 0x2a})
	C:/workdir/go/src/runtime/panic.go:992 +0x64 fp=0x3540f9ec sp=0x3540f9d8 pc=0x1217394
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:249 +0x26d fp=0x3540fa10 sp=0x3540f9ec pc=0x122bf0d
runtime.gentraceback(0x0, 0x0, 0x0, 0x134002d0, 0x0, 0x0, 0x64, 0x0, 0x0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:94 +0x154 fp=0x3540fbfc sp=0x3540fa10 pc=0x12399a4
runtime.traceback1(0x0, 0x0, 0x0, 0x134002d0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:835 +0x1a2 fp=0x3540fcdc sp=0x3540fbfc pc=0x123bf82
runtime.tracebacktrap(0x0, 0x0, 0x0, 0x134002d0)
	C:/workdir/go/src/runtime/traceback.go:799 +0x7e fp=0x3540fcf4 sp=0x3540fcdc pc=0x123bdce
runtime.winthrow(0x1315baa, 0x13433a80, 0x134002d0)
	C:/workdir/go/src/runtime/signal_windows.go:234 +0x202 fp=0x3540fd20 sp=0x3540fcf4 pc=0x122b8e2
runtime.lastcontinuehandler(0x1315baa, 0x13433a80, 0x134002d0)
	C:/workdir/go/src/runtime/signal_windows.go:198 +0x58 fp=0x3540fd30 sp=0x3540fd20 pc=0x122b6c8
sigtramp()
	C:/workdir/go/src/runtime/sys_windows_386.s:127 +0x77 fp=0x3540fd34 sp=0x3540fd30 pc=0x12458c7

goroutine 17 [running, locked to thread]:
fatal error: unexpected signal during runtime execution
panic during panic
[signal 0xc0000005 code=0x0 addr=0x0 pc=0x1239e7c]

runtime stack:
runtime.throw({0x136e0a5, 0x2a})
	C:/workdir/go/src/runtime/panic.go:992 +0x64 fp=0x3540f658 sp=0x3540f644 pc=0x1217394
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:249 +0x26d fp=0x3540f67c sp=0x3540f658 pc=0x122bf0d
runtime.gentraceback(0xffffffff, 0xffffffff, 0x0, 0x134002d0, 0x0, 0x0, 0x64, 0x0, 0x0, 0x0)
	C:/workdir/go/src/runtime/traceback.go:232 +0x62c fp=0x3540f868 sp=0x3540f67c pc=0x1239e7c
runtime.traceback1(0xffffffff, 0xffffffff, 0x0, 0x134002d0, 0x0)
	C:/workdir/go/src/runtime/traceback.go:835 +0x1a2 fp=0x3540f948 sp=0x3540f868 pc=0x123bf82
runtime.traceback(...)
	C:/workdir/go/src/runtime/traceback.go:782
runtime.tracebackothers(0x134001e0)
	C:/workdir/go/src/runtime/traceback.go:1027 +0x8f fp=0x3540f978 sp=0x3540f948 pc=0x123cc1f
runtime.dopanic_m(0x134001e0, 0x1217394, 0x3540f9d8)
	C:/workdir/go/src/runtime/panic.go:1192 +0x23f fp=0x3540f9a0 sp=0x3540f978 pc=0x1217b1f
runtime.fatalthrow.func1()
	C:/workdir/go/src/runtime/panic.go:1047 +0x4b fp=0x3540f9c0 sp=0x3540f9a0 pc=0x12175fb
runtime.fatalthrow()
	C:/workdir/go/src/runtime/panic.go:1044 +0x5a fp=0x3540f9d8 sp=0x3540f9c0 pc=0x121759a
runtime.throw({0x136e0a5, 0x2a})
	C:/workdir/go/src/runtime/panic.go:992 +0x64 fp=0x3540f9ec sp=0x3540f9d8 pc=0x1217394
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:249 +0x26d fp=0x3540fa10 sp=0x3540f9ec pc=0x122bf0d
runtime.gentraceback(0x0, 0x0, 0x0, 0x134002d0, 0x0, 0x0, 0x64, 0x0, 0x0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:94 +0x154 fp=0x3540fbfc sp=0x3540fa10 pc=0x12399a4
runtime.traceback1(0x0, 0x0, 0x0, 0x134002d0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:835 +0x1a2 fp=0x3540fcdc sp=0x3540fbfc pc=0x123bf82
runtime.tracebacktrap(0x0, 0x0, 0x0, 0x134002d0)
	C:/workdir/go/src/runtime/traceback.go:799 +0x7e fp=0x3540fcf4 sp=0x3540fcdc pc=0x123bdce
runtime.winthrow(0x1315baa, 0x13433a80, 0x134002d0)
	C:/workdir/go/src/runtime/signal_windows.go:234 +0x202 fp=0x3540fd20 sp=0x3540fcf4 pc=0x122b8e2
runtime.lastcontinuehandler(0x1315baa, 0x13433a80, 0x134002d0)
	C:/workdir/go/src/runtime/signal_windows.go:198 +0x58 fp=0x3540fd30 sp=0x3540fd20 pc=0x122b6c8
sigtramp()
	C:/workdir/go/src/runtime/sys_windows_386.s:127 +0x77 fp=0x3540fd34 sp=0x3540fd30 pc=0x12458c7
*** Test killed: ran too long (11m0s).
exit status 1
FAIL	misc/cgo/test	660.032s

2021-10-29T17:13:13-645d078/windows-386-2008
2020-12-22T20:00:00-c9fb4eb/windows-386-2008
2020-03-25T14:19:25-91b8b13/windows-386-2008

[bcmills]

CC @bufflig @alexbrainman @cherrymui

At first I thought this might have something to do with #49681, but some of the failures are much older.

[cherrymui]

Yeah, this looks different from #49681 . It looks like it panics again while printing traceback from a fault.

[bufflig]

Is the fact that is prints "Test killed: ran too long" relevant? I mean is this something that happens when we try to kill the test, or does the test end up in an infinite loop?

[bcmills]

I mean is this something that happens when we try to kill the test, or does the test end up in an infinite loop?

Not clear to me. It may be that this failure mode tends to occur when the signal terminating the test arrives on top of another signal or vice-versa — that would at least explain the presence of the gentraceback in the stack.

The Test killed: ran too long message comes from here:
https://cs.opensource.google/go/go/+/master:src/cmd/go/internal/test/test.go;l=1397-1412;drc=7bdbc73be1d10a9b32cb5edc6b9d0c93805f059c

That suggests that perhaps the binary did deadlock after printing the panic during panic stack.

[bcmills]

greplogs -l -e '(?ms)^fatal error: unexpected signal during runtime execution\n\[signal 0xc0000005.*^runtime\.gentraceback' --since=2021-12-14
2022-05-10T23:13:45-f12461c/windows-386-2008

(CC @golang/windows @golang/runtime)

[cherrymui]

It looks like the traceback is called with PC=SP=LR=0. It faults when it tries to read from the SP. Maybe the signal context is wrong? I search for exception 0x200c7 but couldn't find anything useful. So perhaps the exception code is also wrong?

Perhaps the exception handler shouldn't be called in the first place? I don't know what caused it to be called (with seemingly wrong arguments).

[bcmills]

2022-08-08T14:11:19-6e9925c/windows-386-2012:

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
Exception 0xc7 0xcccccccc 0xcccccccc 0x0
PC=0x0

fatal error: unexpected signal during runtime execution
[signal 0xc0000005 code=0x0 addr=0x0 pc=0x465d7a]

runtime stack:
runtime.throw({0x7f14e7, 0x2a})
	C:/workdir/go/src/runtime/panic.go:1047 +0x4d fp=0x328ffbdc sp=0x328ffbc8 pc=0x44047d
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:250 +0x23b fp=0x328ffc00 sp=0x328ffbdc pc=0x455fab
runtime.gentraceback(0x0, 0x0, 0x0, 0x142ca4b0, 0x0, 0x0, 0x64, 0x0, 0x0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:95 +0x16a fp=0x328ffe10 sp=0x328ffc00 pc=0x465d7a
runtime.traceback1(0x0, 0x0, 0x0, 0x142ca4b0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:846 +0x1a2 fp=0x328ffef0 sp=0x328ffe10 pc=0x468562
runtime.tracebacktrap(0x0, 0x0, 0x0, 0x142ca4b0)
	C:/workdir/go/src/runtime/traceback.go:810 +0x7e fp=0x328fff08 sp=0x328ffef0 pc=0x4683ae
runtime.winthrow(0x750df4, 0x12860ad0, 0x142ca4b0)
	C:/workdir/go/src/runtime/signal_windows.go:235 +0x202 fp=0x328fff34 sp=0x328fff08 pc=0x4559b2
runtime.lastcontinuehandler(0x750df4, 0x12860ad0, 0x142ca4b0)
	C:/workdir/go/src/runtime/signal_windows.go:198 +0x58 fp=0x328fff44 sp=0x328fff34 pc=0x455798
sigtramp()
	C:/workdir/go/src/runtime/sys_windows_386.s:127 +0x77 fp=0x328fff48 sp=0x328fff44 pc=0x477657

goroutine 136158 [running]:
fatal error: unexpected signal during runtime execution
panic during panic
[signal 0xc0000005 code=0x0 addr=0x0 pc=0x46631f]

runtime stack:
runtime.throw({0x7f14e7, 0x2a})
	C:/workdir/go/src/runtime/panic.go:1047 +0x4d fp=0x328ff824 sp=0x328ff810 pc=0x44047d
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:250 +0x23b fp=0x328ff848 sp=0x328ff824 pc=0x455fab
runtime.gentraceback(0xffffffff, 0xffffffff, 0x0, 0x142ca4b0, 0x0, 0x0, 0x64, 0x0, 0x0, 0x0)
	C:/workdir/go/src/runtime/traceback.go:236 +0x70f fp=0x328ffa58 sp=0x328ff848 pc=0x46631f
runtime.traceback1(0xffffffff, 0xffffffff, 0x0, 0x142ca4b0, 0x0)
	C:/workdir/go/src/runtime/traceback.go:846 +0x1a2 fp=0x328ffb38 sp=0x328ffa58 pc=0x468562
runtime.traceback(...)
	C:/workdir/go/src/runtime/traceback.go:793
runtime.tracebackothers(0x14502000)
	C:/workdir/go/src/runtime/traceback.go:1038 +0x8f fp=0x328ffb68 sp=0x328ffb38 pc=0x46921f
runtime.dopanic_m(0x14502000, 0x44047d, 0x328ffbc8)
	C:/workdir/go/src/runtime/panic.go:1271 +0x22f fp=0x328ffb90 sp=0x328ffb68 pc=0x440cef
runtime.fatalthrow.func1()
	C:/workdir/go/src/runtime/panic.go:1125 +0x4b fp=0x328ffbb0 sp=0x328ffb90 pc=0x4407cb
runtime.fatalthrow(0x2)
	C:/workdir/go/src/runtime/panic.go:1122 +0x6b fp=0x328ffbc8 sp=0x328ffbb0 pc=0x44076b
runtime.throw({0x7f14e7, 0x2a})
	C:/workdir/go/src/runtime/panic.go:1047 +0x4d fp=0x328ffbdc sp=0x328ffbc8 pc=0x44047d
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:250 +0x23b fp=0x328ffc00 sp=0x328ffbdc pc=0x455fab
runtime.gentraceback(0x0, 0x0, 0x0, 0x142ca4b0, 0x0, 0x0, 0x64, 0x0, 0x0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:95 +0x16a fp=0x328ffe10 sp=0x328ffc00 pc=0x465d7a
runtime.traceback1(0x0, 0x0, 0x0, 0x142ca4b0, 0x2)
	C:/workdir/go/src/runtime/traceback.go:846 +0x1a2 fp=0x328ffef0 sp=0x328ffe10 pc=0x468562
runtime.tracebacktrap(0x0, 0x0, 0x0, 0x142ca4b0)
	C:/workdir/go/src/runtime/traceback.go:810 +0x7e fp=0x328fff08 sp=0x328ffef0 pc=0x4683ae
runtime.winthrow(0x750df4, 0x12860ad0, 0x142ca4b0)
	C:/workdir/go/src/runtime/signal_windows.go:235 +0x202 fp=0x328fff34 sp=0x328fff08 pc=0x4559b2
runtime.lastcontinuehandler(0x750df4, 0x12860ad0, 0x142ca4b0)
	C:/workdir/go/src/runtime/signal_windows.go:198 +0x58 fp=0x328fff44 sp=0x328fff34 pc=0x455798
sigtramp()
	C:/workdir/go/src/runtime/sys_windows_386.s:127 +0x77 fp=0x328fff48 sp=0x328fff44 pc=0x477657
*** Test killed: ran too long (6m0s).
FAIL	runtime	360.016s