From 7574e4f6428591429ef68f6dbbc2534b99af64d0 Mon Sep 17 00:00:00 2001 From: Konstantin Bogomolov Date: Fri, 6 May 2022 12:18:45 -0700 Subject: [PATCH] Add KVM specific metrics. This change adds counter and timer metrics useful for analyzing the KVM platform. PiperOrigin-RevId: 447043888 --- pkg/metric/metric.go | 7 +-- pkg/sentry/kernel/task.go | 14 ++++++ pkg/sentry/kernel/task_run.go | 2 + pkg/sentry/kernel/task_syscall.go | 1 + pkg/sentry/platform/kvm/BUILD | 1 + .../platform/kvm/address_space_amd64.go | 2 + pkg/sentry/platform/kvm/bluepill_unsafe.go | 2 + pkg/sentry/platform/kvm/context.go | 1 + pkg/sentry/platform/kvm/machine.go | 43 +++++++++++++++++++ pkg/sentry/platform/kvm/machine_unsafe.go | 2 + 10 files changed, 72 insertions(+), 3 deletions(-) diff --git a/pkg/metric/metric.go b/pkg/metric/metric.go index 2f819dfcb..d038f95d6 100644 --- a/pkg/metric/metric.go +++ b/pkg/metric/metric.go @@ -417,7 +417,7 @@ func MustCreateNewUint64NanosecondsMetric(name string, sync bool, description st // This must be called with the correct number of field values or it will panic. //go:nosplit func (m *Uint64Metric) Value(fieldValues ...string) uint64 { - key := m.fieldMapper.lookup(fieldValues...) + key := m.fieldMapper.lookupConcat(fieldValues, nil) return m.fields[key].Load() } @@ -425,14 +425,15 @@ func (m *Uint64Metric) Value(fieldValues ...string) uint64 { // This must be called with the correct number of field values or it will panic. //go:nosplit func (m *Uint64Metric) Increment(fieldValues ...string) { - m.IncrementBy(1, fieldValues...) + key := m.fieldMapper.lookupConcat(fieldValues, nil) + m.fields[key].Add(1) } // IncrementBy increments the metric by v. // This must be called with the correct number of field values or it will panic. //go:nosplit func (m *Uint64Metric) IncrementBy(v uint64, fieldValues ...string) { - key := m.fieldMapper.lookup(fieldValues...) + key := m.fieldMapper.lookupConcat(fieldValues, nil) m.fields[key].Add(v) } diff --git a/pkg/sentry/kernel/task.go b/pkg/sentry/kernel/task.go index 5d817ed3e..a4b966207 100644 --- a/pkg/sentry/kernel/task.go +++ b/pkg/sentry/kernel/task.go @@ -24,6 +24,7 @@ import ( "gvisor.dev/gvisor/pkg/bpf" "gvisor.dev/gvisor/pkg/errors/linuxerr" "gvisor.dev/gvisor/pkg/hostarch" + "gvisor.dev/gvisor/pkg/metric" "gvisor.dev/gvisor/pkg/sentry/fs" "gvisor.dev/gvisor/pkg/sentry/inet" "gvisor.dev/gvisor/pkg/sentry/kernel/auth" @@ -595,6 +596,19 @@ type Task struct { userCounters *userCounters } +// Task related metrics +var ( + // syscallCounter is a metric that tracks how many syscalls the sentry has + // executed. + syscallCounter = metric.MustCreateNewUint64Metric( + "/task/syscalls", false, "The number of syscalls the sentry has executed for the user.") + + // faultCounter is a metric that tracks how many faults the sentry has had to + // handle. + faultCounter = metric.MustCreateNewUint64Metric( + "/task/faults", false, "The number of faults the sentry has handled.") +) + func (t *Task) savePtraceTracer() *Task { return t.ptraceTracer.Load().(*Task) } diff --git a/pkg/sentry/kernel/task_run.go b/pkg/sentry/kernel/task_run.go index 7e5f4071f..628c64225 100644 --- a/pkg/sentry/kernel/task_run.go +++ b/pkg/sentry/kernel/task_run.go @@ -261,6 +261,8 @@ func (app *runApp) execute(t *Task) taskRunState { // an application-generated signal and we should continue execution // normally. if at.Any() { + faultCounter.Increment() + region := trace.StartRegion(t.traceContext, faultRegion) addr := hostarch.Addr(info.Addr()) err := t.MemoryManager().HandleUserFault(t, addr, at, hostarch.Addr(t.Arch().Stack())) diff --git a/pkg/sentry/kernel/task_syscall.go b/pkg/sentry/kernel/task_syscall.go index 900a9de18..edd36e519 100644 --- a/pkg/sentry/kernel/task_syscall.go +++ b/pkg/sentry/kernel/task_syscall.go @@ -253,6 +253,7 @@ func (t *Task) doSyscall() taskRunState { } } + syscallCounter.Increment() return t.doSyscallEnter(sysno, args) } diff --git a/pkg/sentry/platform/kvm/BUILD b/pkg/sentry/platform/kvm/BUILD index 7e769354a..10c64d415 100644 --- a/pkg/sentry/platform/kvm/BUILD +++ b/pkg/sentry/platform/kvm/BUILD @@ -92,6 +92,7 @@ go_library( "//pkg/cpuid", "//pkg/hostarch", "//pkg/log", + "//pkg/metric", "//pkg/procid", "//pkg/ring0", "//pkg/ring0/pagetables", diff --git a/pkg/sentry/platform/kvm/address_space_amd64.go b/pkg/sentry/platform/kvm/address_space_amd64.go index d11d38679..c65845b1f 100644 --- a/pkg/sentry/platform/kvm/address_space_amd64.go +++ b/pkg/sentry/platform/kvm/address_space_amd64.go @@ -16,9 +16,11 @@ package kvm // invalidate is the implementation for Invalidate. func (as *addressSpace) invalidate() { + timer := asInvalidateDuration.Start() as.dirtySet.forEach(as.machine, func(c *vCPU) { if c.active.get() == as { // If this happens to be active, c.BounceToKernel() // ... force a kernel transition. } }) + timer.Finish() } diff --git a/pkg/sentry/platform/kvm/bluepill_unsafe.go b/pkg/sentry/platform/kvm/bluepill_unsafe.go index 3eaaba7a6..4920b78d5 100644 --- a/pkg/sentry/platform/kvm/bluepill_unsafe.go +++ b/pkg/sentry/platform/kvm/bluepill_unsafe.go @@ -110,10 +110,12 @@ func bluepillHandler(context unsafe.Pointer) { } for { + hostExitCounter.Increment() _, _, errno := unix.RawSyscall(unix.SYS_IOCTL, uintptr(c.fd), _KVM_RUN, 0) // escapes: no. switch errno { case 0: // Expected case. case unix.EINTR: + interruptCounter.Increment() // First, we process whatever pending signal // interrupted KVM. Since we're in a signal handler // currently, all signals are masked and the signal diff --git a/pkg/sentry/platform/kvm/context.go b/pkg/sentry/platform/kvm/context.go index 250e78588..fbaf7b6f8 100644 --- a/pkg/sentry/platform/kvm/context.go +++ b/pkg/sentry/platform/kvm/context.go @@ -85,6 +85,7 @@ restart: // Increment the number of user exits. cpu.userExits.Add(1) + userExitCounter.Increment() // Release resources. c.machine.Put(cpu) diff --git a/pkg/sentry/platform/kvm/machine.go b/pkg/sentry/platform/kvm/machine.go index 882653062..2a7500be1 100644 --- a/pkg/sentry/platform/kvm/machine.go +++ b/pkg/sentry/platform/kvm/machine.go @@ -19,12 +19,14 @@ import ( "runtime" gosync "sync" "sync/atomic" + "time" "golang.org/x/sys/unix" "gvisor.dev/gvisor/pkg/abi/linux" "gvisor.dev/gvisor/pkg/atomicbitops" "gvisor.dev/gvisor/pkg/hostarch" "gvisor.dev/gvisor/pkg/log" + "gvisor.dev/gvisor/pkg/metric" "gvisor.dev/gvisor/pkg/procid" "gvisor.dev/gvisor/pkg/ring0" "gvisor.dev/gvisor/pkg/ring0/pagetables" @@ -101,6 +103,40 @@ const ( vCPUWaiter uint32 = 1 << 2 ) +var ( + // hostExitCounter is a metric that tracks how many times the sentry + // performed a host to guest world switch. + hostExitCounter = metric.MustCreateNewUint64Metric( + "/kvm/host_exits", false, "The number of times the sentry performed a host to guest world switch.") + + // userExitCounter is a metric that tracks how many times the sentry has + // had an exit from userspace. Analogous to vCPU.userExits. + userExitCounter = metric.MustCreateNewUint64Metric( + "/kvm/user_exits", false, "The number of times the sentry has had an exit from userspace.") + + // interruptCounter is a metric that tracks how many times execution returned + // to the KVM host to handle a pending signal. + interruptCounter = metric.MustCreateNewUint64Metric( + "/kvm/interrupts", false, "The number of times the signal handler was invoked.") + + // mmapCallCounter is a metric that tracks how many times the function + // seccompMmapSyscall has been called. + mmapCallCounter = metric.MustCreateNewUint64Metric( + "/kvm/mmap_calls", false, "The number of times seccompMmapSyscall has been called.") + + // getVCPUFastPathDuration are durations of acquiring a VCPU + // (using machine.Get()). + getVCPUDuration = metric.MustRegisterTimerMetric("/kvm/get_vcpu", + metric.NewExponentialBucketer(20, uint64(time.Nanosecond*10), 1, 2), + "Duration of acquiring a VCPU, not including the fastest reuse path.", + metric.NewField("acquisition_type", []string{"fast_reused", "reused", "unused", "stolen"})) + + // asInvalidateDuration are durations of calling addressSpace.invalidate(). + asInvalidateDuration = metric.MustRegisterTimerMetric("/kvm/address_space_invalidate", + metric.NewExponentialBucketer(15, uint64(time.Nanosecond*100), 1, 2), + "Duration of calling addressSpace.invalidate().") +) + // vCPU is a single KVM vCPU. type vCPU struct { // CPU is the kernel CPU data. @@ -405,6 +441,8 @@ func (m *machine) Destroy() { // the corrent context in guest, the vCPU of it must be the same as what // Get() returns. func (m *machine) Get() *vCPU { + timer := getVCPUDuration.Start() + m.mu.RLock() runtime.LockOSThread() tid := procid.Current() @@ -413,6 +451,7 @@ func (m *machine) Get() *vCPU { if c := m.vCPUsByTID[tid]; c != nil { c.lock() m.mu.RUnlock() + timer.Finish("fast_reused") return c } @@ -432,6 +471,7 @@ func (m *machine) Get() *vCPU { if c := m.vCPUsByTID[tid]; c != nil { c.lock() m.mu.Unlock() + timer.Finish("reused") return c } @@ -443,6 +483,7 @@ func (m *machine) Get() *vCPU { m.vCPUsByTID[tid] = c m.mu.Unlock() c.loadSegments(tid) + timer.Finish("unused") return c } } @@ -455,6 +496,7 @@ func (m *machine) Get() *vCPU { m.vCPUsByTID[tid] = c m.mu.Unlock() c.loadSegments(tid) + timer.Finish("unused") return c } @@ -481,6 +523,7 @@ func (m *machine) Get() *vCPU { m.vCPUsByTID[tid] = c m.mu.Unlock() c.loadSegments(tid) + timer.Finish("stolen") return c } diff --git a/pkg/sentry/platform/kvm/machine_unsafe.go b/pkg/sentry/platform/kvm/machine_unsafe.go index f5cf98edb..0bfad3881 100644 --- a/pkg/sentry/platform/kvm/machine_unsafe.go +++ b/pkg/sentry/platform/kvm/machine_unsafe.go @@ -202,6 +202,8 @@ func seccompMmapSync() { // //go:nosplit func seccompMmapHandler(context unsafe.Pointer) { + mmapCallCounter.Increment() + addr, length, errno := seccompMmapSyscall(context) if errno != 0 { return