It looks like we've hit this a few times:

$ greplogs -dashboard -E "stack split at bad time" -l -md | grep linux-mips
2016-12-21T12:27:41-0ef4815/linux-mipsle
2017-04-21T14:34:10-bb6309c/linux-mipsle
2017-08-13T17:33:10-816deac/linux-mipsle

In all three, it's been something around syscalls, though all of the details differ. In all cases the traceback of the crashing goroutine is curiously truncated.

2017-08-13: The crash appears to happen when syscall.Syscall calls runtime.exitsyscall, but exitsyscall is marked nosplit, so it doesn't even have a morestack prologue. However, there may be other runtime frames in there since newstack manually calls traceback to print the traceback, but the default behavior is to hide runtime frames, so we may just not be seeing them.

The arguments are also odd: SYS_READ is 4003 (0xfa3), which appears as the second argument to syscall.Syscall rather than the first. The next argument of syscall.Syscall is supposed to be the FD, which is a completely reasonable 5 in the traceback, but none of the printed arguments to syscall.readlen is 5. My guess here is that the traceback code maybe got confused somehow by syscall.Syscall and went off the rails.

The location of the failure is also odd. The exact location in syscall.Syscall indicates that the read syscall failed, but the only place we use readlen is in forkExec in exec_unix.go, and I can't think of any reason why that read could fail.

Unfortunately, I haven't been able to reproduce the binary to check the specific PCs because this is the dist binary, so it was compiled with the bootstrap compiler on 2017-08-13 and I don't know what that was (ping @bradfitz).

2017-04-21: It's not even at a call, though, again, maybe the traceback is messed up. I tried to track down the morebuf PC. I can't locally build a cgo-enabled runtime_test linux/mipsle binary (and there seems to be no hope of reaching the linux-mipsle gomote), so I assumed syscall.Syscall was being called by readlen (the arguments suggest it is), assumed 0x48ff68 was the return address of the call to syscall.Syscall in readlen (because syscall.Syscall declares a zero-sized frame, but exitsyscall takes a dummy argument, that dummy argument should line up with syscall.Syscall's saved LR), and used that as a relocation delta against the non-cgo binary I could build locally. Unfortunately, that put me in the middle of entersyscallblock_handoff, which is called on the system stack, so isn't the culprit.

Change https://golang.org/cl/79518 mentions this issue: runtime: print runtime frames in throwsplit trace

Change https://golang.org/cl/79517 mentions this issue: runtime: call throw on systemstack in exitsyscall

Change https://golang.org/cl/79815 mentions this issue: runtime: fix final stack split in exitsyscall

Hello @aclements, gently pinging here to see if there is more work that needs to be done for Go1.10 for this issue.

I wish I knew what to do; then I would do more for Go1.10. :)

It looks like it's happened a few more times recently:
2017-11-22T21:16:29-c6c0f47/linux-mipsle
2017-11-30T14:39:19-4435fcf/linux-mipsle
2017-12-05T18:22:53-eb441e6/linux-mipsle
2017-12-05T18:42:38-49fec9b/linux-mipsle

These failures are all essentially the same. As before, they're all around system calls. And, as before, the traceback doesn't make much sense. runtime.reentersyscall is nosplit, so it can't be calling morestack, and reentersyscall doesn't call reentersyscall.

@cherrymui and I spent some time digging into the new failures. Some observations:

According to morebuf and the stack trace, the call to the stack-splitting function is at reentersyscall+0xe4. This corresponds to the nil check of p.ptr() in if _g_.m.p.ptr().runSafePointFn != 0. This could in principle cause a SIGSEGV that turns into a synthesized call to sigpanic from this PC, and sigpanic can indeed split the stack. If sched.pc from the panic message is sigpanic, that would confirm this, but I still haven't had any luck building any of the failing binaries. I'm going to make a CL to add this symbolization directly to the panic so we can hopefully catch it in the wild.

The traceback claims reentersyscall is being called from reentersyscall+0x74, which is a call, but to runtime.casgstatus. We're not sure what to make of that. Given that the traceback cuts off at that point, it's probably failing to walk to stack and simply found the remnants of some earlier call.

We also noticed that syscall.Syscall on mipsle isn't technically following the MIPS C calling convention, which is supposed to always save space for registers on the stack (even those passed in registers), and always save at least 16 bytes for the argument space. syscall.Syscall doesn't save any space. Fixing this would be non-trivial because Go's calling convention places the saved LR in this argument scratch space, so we'd need to move that around. It also doesn't seem to matter both because it would be really weird for the kernel to scribble over this space, and because none of the runtime syscalls reserve this space and they seem to be fine.

Change https://golang.org/cl/84115 mentions this issue: runtime: symbolize morestack caller in throwsplit panic

(from earlier failure)

The arguments are also odd: SYS_READ is 4003 (0xfa3), which appears as the second argument to syscall.Syscall rather than the first.

The "first arg" there, 0x48a528, looks pretty much like a PC. This suggests there is an off-by-one error somewhere, because one word below the first arg is the saved LR.

preparePanic subtracts 4 from SP and stores the faulting address there. The traceback code handles this specially if it sees sigpanic's PC (https://go.googlesource.com/go/+/67295d6eb0b9ef8d40fcddf052d18ebaa03566e4/src/runtime/traceback.go#482). But if it is sigpanic's prolog try to grow the stack but failed, we're not really in sigpanic yet and the traceback code doesn't do this. This causes argp off by one word and prints a saved LR as first arg.

This also agrees with what we see in more recent failures:

runtime.reentersyscall(0x48d588, 0x48d588)
	/data/mipsle/go/src/runtime/proc.go:2811 +0xe4 fp=0x91152c4 sp=0x91152a8 pc=0x43dab4
runtime.reentersyscall(0x0, 0x0)
	/data/mipsle/go/src/runtime/proc.go:2790 +0x74 fp=0x91152e0 sp=0x91152c4 pc=0x43da44

It appears that reentersyscall get called with two identical args, but it cannot. In fact, reentersyscall can be called by entersyscall with getcallerpc() as its first arg, which is also the saved LR on entersyscall's frame. The off-by-one error makes them appears as two args. So the actual call stack may be

reentersyscall
entersyscall
function at 0x48d588 (probably syscall.Syscall?)

The traceback code thinks reentersyscall recurse to itself because it uses the LR saved by preparePanic as its return address, which is whatever in the LR register when the fault happened, which happens to be the return address of casgstatus in reentersyscall. From there, the backtrace goes far off. This also explains why the backtrace is always truncated.

This hasn't happened against yet since 2017-12-05, so no diagnostics, unfortunately. However, I think @cherrymui's theory is pretty sound.

This got me thinking that sigpanic itself really ought to be nosplit, since it can be "called" from contexts where it's unsafe to grow the stack. Then, if throwsplit is set, it should switch to the system stack and throw rather than attempt any further handling of the signal panic (which may grow the stack).

Of course, that wouldn't help with whatever underlying issue is causing the signal here (assuming that's what's really going on), but it would help debug issues like these.

Change https://golang.org/cl/87595 mentions this issue: runtime: don't grow the stack on sigpanic if unsafe

Change https://golang.org/cl/89016 mentions this issue: runtime: print hexdump on traceback failure

Still no new reproductions since 2017-12-05T18:42:38-49fec9b/linux-mipsle.

Hasn't happened in six months. I don't know what fixed this, but I'm calling it fixed.