Add debug logging to systrap futex waits.

In general it is probably a good idea to set a timeout on any futex waits that
the sentry is doing. For now just output some helpful logs about what the shared
memory looks like; in the future we may want to do something more useful on
ETIMEDOUT events.

PiperOrigin-RevId: 518919966
This commit is contained in:
Konstantin Bogomolov
2023-03-23 11:44:22 -07:00
committed by gVisor bot
parent fa7aa5b4e2
commit f727f06c81
7 changed files with 75 additions and 20 deletions
@@ -163,5 +163,7 @@ func (sc *sharedContext) resetAcked() {
}
func (sc *sharedContext) sleepOnState(state sysmsg.ContextState) {
sc.shared.SleepOnState(state)
if errno := sc.shared.SleepOnState(state, sc); errno != 0 {
panic(fmt.Sprintf("error waiting for state: %v", errno))
}
}
+2 -2
View File
@@ -743,7 +743,7 @@ func (s *subprocess) switchToApp(c *context, ac *arch.Context64) (isSyscall bool
restoreFPState(msg, ctx, sysThread.fpuStateToMsgOffset, c, ac)
msg.EnableSentryFastPath()
sysThread.waitEvent(sysmsg.ThreadStateDone)
sysThread.waitEvent(sysmsg.ThreadStateDone, ctx)
// Check if there's been an error.
if msg.Err != 0 {
@@ -1084,7 +1084,7 @@ func (s *subprocess) createSysmsgThread(tregs *arch.Registers, c *context, ac *a
}
if !contextDecouplingExp {
sysThread.waitEvent(sysmsg.ThreadStateNone)
sysThread.waitEvent(sysmsg.ThreadStateNone, c.sharedContext)
if msg := sysThread.msg; msg.Err != 0 {
panic(fmt.Sprintf("stub thread failed: %v (line %v)", msg.Err, msg.Line))
}
+2
View File
@@ -131,6 +131,8 @@ go_library(
"//pkg/cpuid",
"//pkg/errors",
"//pkg/hostarch",
"//pkg/log",
"//pkg/sentry/platform/interrupt",
"@org_golang_x_sys//unix:go_default_library",
],
)
+6 -3
View File
@@ -152,9 +152,8 @@ type Msg struct {
// State indicates to the sentry what the sysmsg thread is doing at a given
// moment.
State ThreadState
// ContextID is the ID of the ThreadContext struct that the current
// sysmsg thread is is processing. This ID is used in the {sig|sys}handler
// to find the offset to the correct ThreadContext struct location.
// Context is a pointer to the ThreadContext struct that the current sysmsg
// thread is processing.
Context uint64
// FaultJump is the size of a faulted instruction.
@@ -350,6 +349,7 @@ func (m *Msg) String() string {
fmt.Fprintf(&b, " err %x line %d debug %x", m.Err, m.Line, m.Debug)
fmt.Fprintf(&b, " app stack %x", m.AppStack)
fmt.Fprintf(&b, " context %x", m.Context)
fmt.Fprintf(&b, " ThreadID %d", m.ThreadID)
b.WriteString("}")
return b.String()
@@ -361,6 +361,9 @@ func (c *ThreadContext) String() string {
fmt.Fprintf(&b, " fault addr %x syscall %d", c.SignalInfo.Addr(), c.SignalInfo.Syscall())
fmt.Fprintf(&b, " ip %x sp %x", c.Regs.InstructionPointer(), c.Regs.StackPointer())
fmt.Fprintf(&b, " FPStateChanged %d Regs %+v", c.FPStateChanged, c.Regs)
fmt.Fprintf(&b, " Interrupt %d", c.Interrupt)
fmt.Fprintf(&b, " ThreadID %d LastThreadID %d", c.ThreadID, c.LastThreadID)
fmt.Fprintf(&b, " SentryFastPath %d Acked %d", c.SentryFastPath, c.Acked)
fmt.Fprintf(&b, " signo: %d, siginfo: %+v", c.Signo, c.SignalInfo)
fmt.Fprintf(&b, " debug %d", atomic.LoadUint64(&c.Debug))
b.WriteString("}")
@@ -15,21 +15,69 @@
package sysmsg
import (
"fmt"
"syscall"
"unsafe"
"golang.org/x/sys/unix"
"gvisor.dev/gvisor/pkg/abi/linux"
"gvisor.dev/gvisor/pkg/log"
"gvisor.dev/gvisor/pkg/sentry/platform/interrupt"
)
// SleepOnState makes the caller sleep on the ThreadContext.State futex.
func (c *ThreadContext) SleepOnState(curState ContextState) {
_, _, errno := unix.Syscall6(unix.SYS_FUTEX, uintptr(unsafe.Pointer(&c.State)),
linux.FUTEX_WAIT, uintptr(curState), 0, 0, 0)
if errno != 0 && errno != unix.EAGAIN && errno != unix.EINTR {
panic(fmt.Sprintf("error waiting for state: %v", errno))
const maxFutexSleepSeconds = 60
// SleepOnState makes the caller sleep on the Msg.State futex.
func (m *Msg) SleepOnState(curState ThreadState, interruptor interrupt.Receiver) syscall.Errno {
futexTimeout := unix.Timespec{
Sec: maxFutexSleepSeconds,
Nsec: 0,
}
sentInterruptOnce := false
errno := syscall.Errno(0)
for {
_, _, errno = unix.Syscall6(unix.SYS_FUTEX, uintptr(unsafe.Pointer(&m.State)),
linux.FUTEX_WAIT, uintptr(curState), uintptr(unsafe.Pointer(&futexTimeout)), 0, 0)
if errno == unix.ETIMEDOUT {
interruptor.NotifyInterrupt()
if !sentInterruptOnce {
log.Warningf("Systrap task goroutine has been waiting on Msg.State futex too long. Msg: %s", m.String())
}
sentInterruptOnce = true
} else {
break
}
}
if errno == unix.EAGAIN || errno == unix.EINTR {
errno = 0
}
return errno
}
// SleepOnState makes the caller sleep on the ThreadContext.State futex.
func (c *ThreadContext) SleepOnState(curState ContextState, interruptor interrupt.Receiver) syscall.Errno {
futexTimeout := unix.Timespec{
Sec: maxFutexSleepSeconds,
Nsec: 0,
}
sentInterruptOnce := false
errno := syscall.Errno(0)
for {
_, _, errno = unix.Syscall6(unix.SYS_FUTEX, uintptr(unsafe.Pointer(&c.State)),
linux.FUTEX_WAIT, uintptr(curState), uintptr(unsafe.Pointer(&futexTimeout)), 0, 0)
if errno == unix.ETIMEDOUT {
interruptor.NotifyInterrupt()
if !sentInterruptOnce {
log.Warningf("Systrap task goroutine has been waiting on ThreadContext.State futex too long. ThreadContext: %s", c.String())
}
sentInterruptOnce = true
} else {
break
}
}
if errno == unix.EAGAIN || errno == unix.EINTR {
errno = 0
}
return errno
}
// WakeSysmsgThread calls futex wake on Sysmsg.State.
+3 -2
View File
@@ -24,6 +24,7 @@ import (
"gvisor.dev/gvisor/pkg/seccomp"
"gvisor.dev/gvisor/pkg/sentry/arch"
"gvisor.dev/gvisor/pkg/sentry/memmap"
"gvisor.dev/gvisor/pkg/sentry/platform/interrupt"
"gvisor.dev/gvisor/pkg/sentry/platform/systrap/sysmsg"
)
@@ -116,7 +117,7 @@ func (p *sysmsgThread) mapPrivateStack(addr uintptr, size uintptr) error {
return err
}
func (p *sysmsgThread) waitEvent(switchToState sysmsg.ThreadState) {
func (p *sysmsgThread) waitEvent(switchToState sysmsg.ThreadState, interruptor interrupt.Receiver) {
msg := p.msg
wakeup := false
acked := atomic.LoadUint32(&msg.AckedEvents)
@@ -127,7 +128,7 @@ func (p *sysmsgThread) waitEvent(switchToState sysmsg.ThreadState) {
acked--
}
if errno := futexWaitForState(msg, sysmsg.ThreadStateEvent, wakeup, acked); errno != 0 {
if errno := futexWaitForState(msg, sysmsg.ThreadStateEvent, wakeup, acked, interruptor); errno != 0 {
panic(fmt.Sprintf("error waiting for state: %v", errno))
}
}
@@ -24,6 +24,7 @@ import (
"golang.org/x/sys/unix"
"gvisor.dev/gvisor/pkg/abi/linux"
"gvisor.dev/gvisor/pkg/sentry/arch"
"gvisor.dev/gvisor/pkg/sentry/platform/interrupt"
"gvisor.dev/gvisor/pkg/sentry/platform/systrap/sysmsg"
)
@@ -101,7 +102,7 @@ func exitsyscall()
const deepSleepTimeout = uint64(80000)
const handshakeTimeout = uint64(1000)
func futexWaitForState(msg *sysmsg.Msg, state sysmsg.ThreadState, wakeup bool, acked uint32) syscall.Errno {
func futexWaitForState(msg *sysmsg.Msg, state sysmsg.ThreadState, wakeup bool, acked uint32, interruptor interrupt.Receiver) syscall.Errno {
slowPath := false
errno := syscall.Errno(0)
start := cputicks()
@@ -141,12 +142,10 @@ func futexWaitForState(msg *sysmsg.Msg, state sysmsg.ThreadState, wakeup bool, a
}
if slowPath {
_, _, errno = unix.Syscall6(unix.SYS_FUTEX, uintptr(unsafe.Pointer(&msg.State)),
linux.FUTEX_WAIT, uintptr(curState), 0, 0, 0)
if errno != 0 && errno != unix.EAGAIN && errno != unix.EINTR {
errno = msg.SleepOnState(curState, interruptor)
if errno != 0 {
break
}
errno = 0
} else {
spinloop()
}