diff --git a/pkg/sentry/platform/systrap/BUILD b/pkg/sentry/platform/systrap/BUILD index 05e81c470..ab3678984 100644 --- a/pkg/sentry/platform/systrap/BUILD +++ b/pkg/sentry/platform/systrap/BUILD @@ -40,6 +40,7 @@ go_library( "filters_arm64.go", "lib_amd64.s", "lib_arm64.s", + "metrics.go", "shared_context.go", "shared_context_norace.go", "shared_context_race.go", @@ -68,6 +69,8 @@ go_library( "systrap_amd64.go", "systrap_arm64.go", "systrap_arm64_unsafe.go", + "systrap_profiling.go", + "systrap_profiling_fake.go", "systrap_unsafe.go", ], visibility = ["//:sandbox"], @@ -80,6 +83,7 @@ go_library( "//pkg/hostarch", "//pkg/log", "//pkg/memutil", + "//pkg/metric", "//pkg/pool", "//pkg/refs", "//pkg/safecopy", diff --git a/pkg/sentry/platform/systrap/context_queue.go b/pkg/sentry/platform/systrap/context_queue.go index cb771882f..8b2002b74 100644 --- a/pkg/sentry/platform/systrap/context_queue.go +++ b/pkg/sentry/platform/systrap/context_queue.go @@ -44,6 +44,9 @@ type contextQueue struct { // numActiveThreads indicates to the sentry how many stubs are running. // It is changed only by stub threads. numActiveThreads uint32 + // numSpinningThreads indicates to the sentry how many stubs are waiting + // to receive a context from the queue, and are not doing useful work. + numSpinningThreads uint32 // numThreadsToWakeup is the number of threads requested by Sentry to wake up. // The Sentry increments it and stub threads decrements. numThreadsToWakeup uint32 @@ -53,10 +56,9 @@ type contextQueue struct { // active contexts and contexts that are running in the Sentry. numAwakeContexts uint32 - fastPathDisabledTS uint64 - fastPathFailedInRow uint32 - fastPathDisabled uint32 - ringbuffer [maxContextQueueEntries]uint64 + fastPathDisabled uint32 + usedFastPath uint32 + ringbuffer [maxContextQueueEntries]uint64 } const ( @@ -75,13 +77,13 @@ func (q *contextQueue) init() { idx := ^uint32(0) - maxContextQueueEntries*4 atomic.StoreUint32(&q.start, idx) atomic.StoreUint32(&q.end, idx) - atomic.StoreUint64(&q.fastPathDisabledTS, 0) - atomic.StoreUint32(&q.fastPathFailedInRow, 0) atomic.StoreUint32(&q.numActiveThreads, 0) + atomic.StoreUint32(&q.numSpinningThreads, 0) atomic.StoreUint32(&q.numThreadsToWakeup, 0) atomic.StoreUint32(&q.numActiveContexts, 0) atomic.StoreUint32(&q.numAwakeContexts, 0) - atomic.StoreUint32(&q.fastPathDisabled, 0) + atomic.StoreUint32(&q.fastPathDisabled, 1) + atomic.StoreUint32(&q.usedFastPath, 0) } func (q *contextQueue) isEmpty() bool { @@ -92,8 +94,13 @@ func (q *contextQueue) queuedContexts() uint32 { return (atomic.LoadUint32(&q.end) + maxContextQueueEntries - atomic.LoadUint32(&q.start)) % maxContextQueueEntries } -func (q *contextQueue) add(ctx *sharedContext, stubFastPathEnabled bool) uint32 { - if stubFastPathEnabled { +// add puts the the given ctx onto the context queue, and records a state of +// the subprocess after insertion to see if there are more active stub threads +// or more waiting contexts. +func (q *contextQueue) add(ctx *sharedContext) { + ctx.startWaitingTS = cputicks() + + if fpState.stubFastPath() { q.enableFastPath() } else { q.disableFastPath() @@ -103,14 +110,17 @@ func (q *contextQueue) add(ctx *sharedContext, stubFastPathEnabled bool) uint32 next := atomic.AddUint32(&q.end, 1) if (next % maxContextQueueEntries) == (atomic.LoadUint32(&q.start) % maxContextQueueEntries) { - // should be unreacheable + // should be unreachable panic("contextQueue is full") } idx := next - 1 next = idx % maxContextQueueEntries v := (uint64(idx) << contextQueueIndexShift) + uint64(contextID) atomic.StoreUint64(&q.ringbuffer[next], v) - return next // remove me + + if atomic.SwapUint32(&q.usedFastPath, 0) != 0 { + fpState.usedStubFastPath.Store(true) + } } func (q *contextQueue) disableFastPath() { @@ -120,3 +130,7 @@ func (q *contextQueue) disableFastPath() { func (q *contextQueue) enableFastPath() { atomic.StoreUint32(&q.fastPathDisabled, 0) } + +func (q *contextQueue) fastPathEnabled() bool { + return atomic.LoadUint32(&q.fastPathDisabled) == 0 +} diff --git a/pkg/sentry/platform/systrap/metrics.go b/pkg/sentry/platform/systrap/metrics.go new file mode 100644 index 000000000..f982aee13 --- /dev/null +++ b/pkg/sentry/platform/systrap/metrics.go @@ -0,0 +1,580 @@ +// Copyright 2023 The gVisor Authors. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package systrap + +import ( + "time" + + "gvisor.dev/gvisor/pkg/atomicbitops" + "gvisor.dev/gvisor/pkg/hostarch" +) + +// This file contains all logic related to context switch latency metrics. +// +// Latency metrics are the main method by which fastpath for both stub threads +// and the sentry is enabled and disabled. We measure latency in CPU cycles. +// +// The high level overview of metric collection looks like this: +// 1a) When a context is switched from the sentry to the stub, the sentry +// records the time it was put into the context queue. +// 1b) When a stub thread picks up the context from the context queue, the stub +// thread records the time when it's about to switch back to user code. +// Getting the diff between these timestamps gives us the stub-bound latency. +// +// 2a) When a stub thread gives back a context to the sentry for handling, +// it records the time just before notifying the sentry task goroutine. +// 2b) When the task goroutine sees that it has been notified, it records the +// time. +// Getting the diff between these timestamps gives us the sentry-bound latency. +// +// 3) Both latencies are recorded at once via recordLatency(). This means +// there is a delay on getting stubBoundLatencies. In practice this should not +// matter that much due to our relatively large latency measurement periods. +// +// There is a bucket array for each latency type, where each bucket is of size +// `bucketIncrements`. Latencies are collected in time periods of length +// `recordingPeriod`, and measurements for the current period are stored +// in the `latencies` variable. + +type latencyBuckets [numLatencyBuckets]atomicbitops.Uint64 +type cpuTicks uint64 + +const ( + numLatencyBuckets = 80 + bucketIncrements = 2048 + + // minNecessaryRecordings defines the minimum amount of recordings we + // want to see in latencyBuckets in order to get a reasonable median. + minNecessaryRecordings = 5 +) + +// latencyRecorder is used to collect latency metrics. +type latencyRecorder struct { + stubBound latencyBuckets + sentryBound latencyBuckets +} + +// latencies stores the latency counts for the current measurement period. +var latencies latencyRecorder + +// record increments the correct bucket assigned to the given latency l. +// +//go:nosplit +func (b *latencyBuckets) record(l cpuTicks) { + bucket := l / bucketIncrements + if bucket >= numLatencyBuckets { + bucket = numLatencyBuckets - 1 + } + b[bucket].Add(1) +} + +// getMedian returns a latency measure in the range of +// [bucketIncrements, numLatencyBuckets * bucketIncrements], or 0 if unable to +// find a median in the latencyBuckets. +func (b *latencyBuckets) getMedian() cpuTicks { + i := 0 + j := numLatencyBuckets - 1 + var totalForwards, totalBackwards uint64 + for i <= j { + if totalForwards < totalBackwards { + totalForwards += b[i].Load() + i++ + } else { + totalBackwards += b[j].Load() + j-- + } + } + if totalForwards+totalBackwards < minNecessaryRecordings { + return 0 + } + return cpuTicks(max(uint64(i), 1) * bucketIncrements) +} + +// merge combines two latencyBuckets instances. +func (b *latencyBuckets) merge(other *latencyBuckets) { + for i := 0; i < numLatencyBuckets; i++ { + b[i].Add(other[i].Load()) + } +} + +// reset zeroes all buckets. +func (b *latencyBuckets) reset() { + for i := 0; i < numLatencyBuckets; i++ { + b[i].Store(0) + } +} + +// recordLatency records the latency of both the sentry->stub and the +// stub->sentry context switches. +// For the stub->sentry context switch, the final timestamp is taken by this +// function. +// Preconditions: +// - ctx.isAcked() is true. +// +//go:nosplit +func (sc *sharedContext) recordLatency() { + // Record stub->sentry latency. + sentryBoundLatency := sc.getStateChangedTimeDiff() + if sentryBoundLatency != 0 { + latencies.sentryBound.record(sentryBoundLatency) + } + + // Record sentry->stub latency. + stubBoundLatency := sc.getAckedTimeDiff() + if stubBoundLatency != 0 { + latencies.stubBound.record(stubBoundLatency) + } + + updateDebugMetrics(stubBoundLatency, sentryBoundLatency) +} + +// When a measurement period ends, the latencies are used to determine the fast +// path state. Fastpath is independently enabled for both the sentry and stub +// threads, and is modeled as the following state machine: +// +// +----------StubFPOff,SentryFPOff-------+ +// | ^ ^ | +// V | | V +// +-->StubFPOn,SentryFPOff StubFPOff,SentryFPOn<--+ +// | | ^ | ^ | +// | V | V | | +// | StubFPOn,SentryFPOn StubFPOn,SentryFPOn | +// | LastEnabledSentryFP LastEnabledStubFP | +// | | | | +// | | | | +// | +---------> StubFPOn,SentryFPOn <-------+ | +// | | | | +// |______________________________| |___________________________| +// +// The default state is to have both stub and sentry fastpath OFF. +// A state transition to enable one fastpath is done when +// fpState.(stub|sentry)FPBackoff reaches 0. (stub|sentry)FPBackoff is +// decremented every recording period that the corresponding fastpath is +// disabled. +// A state transition to disable one fastpath is decided through the predicates +// shouldDisableStubFP or shouldDisableSentryFP, and activated with +// disableStubFP or disableSentryFP. +// +// Why have 3 states for both FPs being ON? The logic behind that is to do with +// the fact that fastpaths are interdependent. Enabling one fastpath can have +// negative effects on the latency metrics of the other in the event that there +// are not enough CPUs to run the fastpath. So it's very possible that the system +// finds itself in a state where it's beneficial to run one fastpath but not the +// other based on the workload it's doing. For this case, we need to remember +// what the last stable state was to return to, because the metrics will likely +// be bad enough for both sides to be eligible for being disabled. +// +// Once the system establishes that having both the stub and sentry fastpath ON +// is acceptable, it does prioritize disabling stub fastpath over disabling +// sentry fastpath, because the sentry fastpath at most takes one thread to spin. + +const ( + recordingPeriod = 400 * time.Microsecond + fastPathBackoffMin = 2 + maxRecentFPFailures = 9 + numConsecutiveFailsToDisableFP = 2 +) + +// fastPathState is used to keep track of long term metrics that span beyond +// one measurement period. +type fastPathState struct { + // stubBoundBaselineLatency and sentryBoundBaselineLatency record all + // latency measures recorded during periods when their respective + // fastpath was OFF. + stubBoundBaselineLatency latencyBuckets + sentryBoundBaselineLatency latencyBuckets + + // stubFPBackoff and sentryFPBackoff are the periods remaining until + // the system attempts to use the fastpath again. + stubFPBackoff int + sentryFPBackoff int + + // stubFPRecentFailures and sentryFPRecentFailures are counters in the + // range [0, maxRecentFPFailures] that are incremented by + // disable(Stub|Sentry)FP and decremented by (stub|sentry)FPSuccess. + // They are used to set the backoffs. + stubFPRecentFailures int + sentryFPRecentFailures int + + consecutiveStubFPFailures int + consecutiveSentryFPFailures int + + _ [hostarch.CacheLineSize]byte + // stubFastPathEnabled is a global flag referenced in other parts of + // systrap to determine if the stub fast path is enabled or not. + stubFastPathEnabled atomicbitops.Bool + + _ [hostarch.CacheLineSize]byte + // sentryFastPathEnabled is a global flag referenced in other parts of + // systrap to determine if the sentry fastpath is enabled or not. + sentryFastPathEnabled atomicbitops.Bool + + _ [hostarch.CacheLineSize]byte + // nrMaxAwakeStubThreads is the maximum number of awake stub threads over + // all subprocesses at the this moment. + nrMaxAwakeStubThreads atomicbitops.Uint32 + + // usedStubFastPath and usedSentryFastPath are reset every recording + // period, and are populated in case the system actually used the + // fastpath (i.e. stub or dispatcher spun for some time without work). + _ [hostarch.CacheLineSize]byte + usedStubFastPath atomicbitops.Bool + _ [hostarch.CacheLineSize]byte + usedSentryFastPath atomicbitops.Bool + + _ [hostarch.CacheLineSize]byte + // curState is the current fastpath state function, which is called at + // the end of every recording period. + curState func(*fastPathState) +} + +var ( + fpState = fastPathState{ + stubFPBackoff: fastPathBackoffMin, + sentryFPBackoff: fastPathBackoffMin, + curState: sentryOffStubOff, + } + + // fastPathContextLimit is the maximum number of contexts after which the fast + // path in stub threads is disabled. Its value can be higher than the number of + // CPU-s, because the Sentry is running with higher priority than stub threads, + // deepSleepTimeout is much shorter than the Linux scheduler timeslice, so the + // only thing that matters here is whether the Sentry handles syscall faster + // than the overhead of scheduling another stub thread. + fastPathContextLimit = uint32(maxSysmsgThreads * 2) +) + +// controlFastPath is used to spawn a goroutine when creating the Systrap +// platform. +func controlFastPath() { + for { + time.Sleep(recordingPeriod) + + fpState.curState(&fpState) + // Reset FP trackers. + fpState.usedStubFastPath.Store(false) + fpState.usedSentryFastPath.Store(false) + } +} + +// getBackoff returns the number of recording periods that fastpath should remain +// disabled for, based on the num of recentFailures. +func getBackoff(recentFailures int) int { + return 1 << recentFailures +} + +//go:nosplit +func (s *fastPathState) sentryFastPath() bool { + return s.sentryFastPathEnabled.Load() +} + +//go:nosplit +func (s *fastPathState) stubFastPath() bool { + return s.stubFastPathEnabled.Load() && (s.nrMaxAwakeStubThreads.Load() <= fastPathContextLimit) +} + +// enableSentryFP is a wrapper to unconditionally enable sentry FP and increment +// a debug metric. +func (s *fastPathState) enableSentryFP() { + s.sentryFastPathEnabled.Store(true) + numTimesSentryFastPathEnabled.Increment() +} + +// disableSentryFP returns true if the sentry fastpath was able to be disabled. +// +// It takes two calls to disableSentryFP without any calls to sentryFPSuccess in +// between to disable the sentry fastpath. This is done in order to mitigate the +// effects of outlier measures due to rdtsc inaccuracies. +func (s *fastPathState) disableSentryFP() bool { + s.consecutiveSentryFPFailures++ + if s.consecutiveSentryFPFailures < numConsecutiveFailsToDisableFP { + return false + } + s.consecutiveSentryFPFailures = 0 + s.sentryFastPathEnabled.Store(false) + numTimesSentryFastPathDisabled.Increment() + + s.sentryFPBackoff = getBackoff(s.sentryFPRecentFailures) + s.sentryFPRecentFailures = min(maxRecentFPFailures, s.sentryFPRecentFailures+1) + return true +} + +// enableStubFP is a wrapper to unconditionally enable stub FP and increment +// a debug metric. +func (s *fastPathState) enableStubFP() { + s.stubFastPathEnabled.Store(true) + numTimesStubFastPathEnabled.Increment() +} + +// disableStubFP returns true if the stub fastpath was able to be disabled. +// +// It takes two calls to disableStubFP without any calls to stubFPSuccess in +// between to disable the stub fastpath. This is done in order to mitigate the +// effects of outlier measures due to rdtsc inaccuracies. +func (s *fastPathState) disableStubFP() bool { + s.consecutiveStubFPFailures++ + if s.consecutiveStubFPFailures < numConsecutiveFailsToDisableFP { + return false + } + s.consecutiveStubFPFailures = 0 + s.stubFastPathEnabled.Store(false) + numTimesStubFastPathDisabled.Increment() + + s.stubFPBackoff = getBackoff(s.stubFPRecentFailures) + s.stubFPRecentFailures = min(maxRecentFPFailures, s.stubFPRecentFailures+1) + return true +} + +func (s *fastPathState) sentryFPSuccess() { + s.sentryFPRecentFailures = max(0, s.sentryFPRecentFailures-1) + s.consecutiveSentryFPFailures = 0 +} + +func (s *fastPathState) stubFPSuccess() { + s.stubFPRecentFailures = max(0, s.stubFPRecentFailures-1) + s.consecutiveStubFPFailures = 0 +} + +// shouldDisableSentryFP returns true if the metrics indicate sentry fastpath +// should be disabled. +func (s *fastPathState) shouldDisableSentryFP(stubMedian, sentryMedian cpuTicks) bool { + if !s.usedSentryFastPath.Load() { + return false + } + stubBaseline := s.stubBoundBaselineLatency.getMedian() + sentryBaseline := s.sentryBoundBaselineLatency.getMedian() + if sentryMedian < sentryBaseline { + // Assume the number of productive stubs is the core count on the + // system, not counting the 1 core taken by the dispatcher for + // the fast path. + n := cpuTicks(maxSysmsgThreads - 1) + // If the sentry fastpath is causing the stub latency to be + // higher than normal, the point at which it's considered to be + // too high is when the time saved via the sentry fastpath is + // less than the time lost via higher stub latency (with some + // error margin). Assume that all possible stub threads are + // active for this comparison. + diff := (sentryBaseline - sentryMedian) * n + errorMargin := stubBaseline / 8 + return (stubMedian > stubBaseline) && (stubMedian-stubBaseline) > (diff+errorMargin) + } + // Running the fastpath resulted in higher sentry latency than baseline? + // This does not happen often, but it is an indication that the fastpath + // wasn't used to full effect: for example the dispatcher kept changing, + // and that there was not enough CPU to place a new dispatcher fast + // enough. + // + // If there isn't enough CPU we will most likely see large stub latency + // regressions, and should disable the fastpath. + return stubMedian > (stubBaseline + stubBaseline/2) +} + +// shouldDisableStubFP returns true if the metrics indicate stub fastpath should +// be disabled. +func (s *fastPathState) shouldDisableStubFP(stubMedian, sentryMedian cpuTicks) bool { + if !s.usedStubFastPath.Load() { + return false + } + stubBaseline := s.stubBoundBaselineLatency.getMedian() + sentryBaseline := s.sentryBoundBaselineLatency.getMedian() + if stubMedian < stubBaseline { + // If the stub fastpath is causing the sentry latency to be + // higher than normal, the point at which it's considered to be + // too high is when the time saved via the stub fastpath is + // less than the time lost via higher sentry latency (with some + // error margin). Unlike the stub latency, the sentry latency is + // largely dependent on one thread (the dispatcher). + diff := stubBaseline - stubMedian + errorMargin := sentryBaseline / 8 + return (sentryMedian > sentryBaseline) && (sentryMedian-sentryBaseline) > (diff+errorMargin) + } + // Running the fastpath resulted in higher stub latency than baseline? + // This is either an indication that there isn't enough CPU to schedule + // stub threads to run the fastpath, or the user workload has changed to + // be such that it returns less often to the sentry. + // + // If there isn't enough CPU we will most likely see large sentry latency + // regressions, and should disable the fastpath. + return sentryMedian > (sentryBaseline + sentryBaseline/2) +} + +// The following functions are used for state transitions in the sentry/stub +// fastpath state machine described above. + +func sentryOffStubOff(s *fastPathState) { + periodStubBoundMedian := latencies.stubBound.getMedian() + s.stubBoundBaselineLatency.merge(&latencies.stubBound) + latencies.stubBound.reset() + if periodStubBoundMedian != 0 { + s.stubFPBackoff = max(s.stubFPBackoff-1, 0) + } + + periodSentryBoundMedian := latencies.sentryBound.getMedian() + s.sentryBoundBaselineLatency.merge(&latencies.sentryBound) + latencies.sentryBound.reset() + if periodSentryBoundMedian != 0 { + s.sentryFPBackoff = max(s.sentryFPBackoff-1, 0) + } + + if s.sentryFPBackoff == 0 { + s.enableSentryFP() + s.curState = sentryOnStubOff + } else if s.stubFPBackoff == 0 { + s.enableStubFP() + s.curState = sentryOffStubOn + } +} + +func sentryOnStubOff(s *fastPathState) { + periodStubBoundMedian := latencies.stubBound.getMedian() + periodSentryBoundMedian := latencies.sentryBound.getMedian() + if periodStubBoundMedian == 0 || periodSentryBoundMedian == 0 { + return + } + + if s.shouldDisableSentryFP(periodStubBoundMedian, periodSentryBoundMedian) { + if s.disableSentryFP() { + s.curState = sentryOffStubOff + } + } else { + s.sentryFPSuccess() + // If we are going to keep sentry FP on that means stub latency + // was fine; update the baseline. + s.stubBoundBaselineLatency.merge(&latencies.stubBound) + latencies.stubBound.reset() + s.stubFPBackoff = max(s.stubFPBackoff-1, 0) + if s.stubFPBackoff == 0 { + s.enableStubFP() + s.curState = sentryOnStubOnLastEnabledStub + } + } + latencies.sentryBound.reset() +} + +func sentryOffStubOn(s *fastPathState) { + periodStubBoundMedian := latencies.stubBound.getMedian() + periodSentryBoundMedian := latencies.sentryBound.getMedian() + if periodStubBoundMedian == 0 || periodSentryBoundMedian == 0 { + return + } + + if s.shouldDisableStubFP(periodStubBoundMedian, periodSentryBoundMedian) { + if s.disableStubFP() { + s.curState = sentryOffStubOff + } + } else { + s.stubFPSuccess() + + s.sentryBoundBaselineLatency.merge(&latencies.sentryBound) + latencies.sentryBound.reset() + s.sentryFPBackoff = max(s.sentryFPBackoff-1, 0) + if s.sentryFPBackoff == 0 { + s.enableSentryFP() + s.curState = sentryOnStubOnLastEnabledSentry + } + } + latencies.stubBound.reset() +} + +func sentryOnStubOnLastEnabledSentry(s *fastPathState) { + periodStubBoundMedian := latencies.stubBound.getMedian() + periodSentryBoundMedian := latencies.sentryBound.getMedian() + if periodStubBoundMedian == 0 || periodSentryBoundMedian == 0 { + return + } + + latencies.stubBound.reset() + latencies.sentryBound.reset() + + if s.shouldDisableSentryFP(periodStubBoundMedian, periodSentryBoundMedian) { + if s.disableSentryFP() { + s.curState = sentryOffStubOn + } + } else { + s.curState = sentryOnStubOn + s.sentryFPSuccess() + s.stubFPSuccess() + } +} + +func sentryOnStubOnLastEnabledStub(s *fastPathState) { + periodStubBoundMedian := latencies.stubBound.getMedian() + periodSentryBoundMedian := latencies.sentryBound.getMedian() + if periodStubBoundMedian == 0 || periodSentryBoundMedian == 0 { + return + } + + latencies.stubBound.reset() + latencies.sentryBound.reset() + + if s.shouldDisableStubFP(periodStubBoundMedian, periodSentryBoundMedian) { + if s.disableStubFP() { + s.curState = sentryOnStubOff + } + } else { + s.curState = sentryOnStubOn + s.sentryFPSuccess() + s.stubFPSuccess() + } +} + +func sentryOnStubOn(s *fastPathState) { + periodStubBoundMedian := latencies.stubBound.getMedian() + periodSentryBoundMedian := latencies.sentryBound.getMedian() + if periodStubBoundMedian == 0 || periodSentryBoundMedian == 0 { + return + } + + latencies.stubBound.reset() + latencies.sentryBound.reset() + + // Prioritize disabling stub fastpath over sentry fastpath, since sentry + // only spins with one thread. + if s.shouldDisableStubFP(periodStubBoundMedian, periodSentryBoundMedian) { + if s.disableStubFP() { + s.curState = sentryOnStubOff + } + } else if s.shouldDisableSentryFP(latencies.stubBound.getMedian(), latencies.sentryBound.getMedian()) { + if s.disableSentryFP() { + s.curState = sentryOffStubOn + } + } else { + s.sentryFPSuccess() + s.stubFPSuccess() + } +} + +// Profiling metrics intended for debugging purposes. +var ( + numTimesSentryFastPathDisabled = SystrapProfiling.MustCreateNewUint64Metric("/systrap/numTimesSentryFastPathDisabled", false, "") + numTimesSentryFastPathEnabled = SystrapProfiling.MustCreateNewUint64Metric("/systrap/numTimesSentryFastPathEnabled", false, "") + numTimesStubFastPathDisabled = SystrapProfiling.MustCreateNewUint64Metric("/systrap/numTimesStubFastPathDisabled", false, "") + numTimesStubFastPathEnabled = SystrapProfiling.MustCreateNewUint64Metric("/systrap/numTimesStubFastPathEnabled", false, "") + numTimesStubKicked = SystrapProfiling.MustCreateNewUint64Metric("/systrap/numTimesStubKicked", false, "") + + stubLatWithin1kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/stubLatWithin1kUS", false, "") + stubLatWithin5kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/stubLatWithin5kUS", false, "") + stubLatWithin10kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/stubLatWithin10kUS", false, "") + stubLatWithin20kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/stubLatWithin20kUS", false, "") + stubLatWithin40kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/stubLatWithin40kUS", false, "") + stubLatGreater40kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/stubLatGreater40kUS", false, "") + + sentryLatWithin1kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/sentryLatWithin1kUS", false, "") + sentryLatWithin5kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/sentryLatWithin5kUS", false, "") + sentryLatWithin10kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/sentryLatWithin10kUS", false, "") + sentryLatWithin20kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/sentryLatWithin20kUS", false, "") + sentryLatWithin40kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/sentryLatWithin40kUS", false, "") + sentryLatGreater40kUS = SystrapProfiling.MustCreateNewUint64Metric("/systrap/sentryLatGreater40kUS", false, "") +) diff --git a/pkg/sentry/platform/systrap/shared_context.go b/pkg/sentry/platform/systrap/shared_context.go index 8cc97db96..0c37ceb04 100644 --- a/pkg/sentry/platform/systrap/shared_context.go +++ b/pkg/sentry/platform/systrap/shared_context.go @@ -16,7 +16,6 @@ package systrap import ( "fmt" - "runtime" "strconv" "sync" "sync/atomic" @@ -30,7 +29,8 @@ import ( ) const ( - ackReset uint32 = 0 + ackReset uint64 = 0 + stateChangedReset uint64 = 0 ) // sharedContext is an abstraction for interactions that the sentry has to @@ -108,7 +108,6 @@ func (sc *sharedContext) release() { } if !sc.sleeping { sc.subprocess.decAwakeContexts() - } sc.subprocess.threadContextPool.Put(uint64(sc.contextID)) sc.subprocess.DecRef(sc.subprocess.release) @@ -183,11 +182,40 @@ func (sc *sharedContext) disableSentryFastPath() { } func (sc *sharedContext) isAcked() bool { - return atomic.LoadUint32(&sc.shared.Acked) != ackReset + return atomic.LoadUint64(&sc.shared.AckedTime) != ackReset } -func (sc *sharedContext) resetAcked() { - atomic.StoreUint32(&sc.shared.Acked, ackReset) +// getAckedTimeDiff returns the time difference between when this context was +// put into the context queue, and when this context was acked by a stub thread. +// Precondition: must be called after isAcked() == true. +// +//go:nosplit +func (sc *sharedContext) getAckedTimeDiff() cpuTicks { + ackedAt := atomic.LoadUint64(&sc.shared.AckedTime) + if ackedAt < uint64(sc.startWaitingTS) { + log.Warningf("likely memory tampering detected: found a condition where ackedAt (%d) < startWaitingTS (%d)", ackedAt, uint64(sc.startWaitingTS)) + return 0 + } + return cpuTicks(ackedAt - uint64(sc.startWaitingTS)) +} + +// getStateChangedTimeDiff returns the time difference between the time the +// context state got changed by a stub thread, and now. +// +//go:nosplit +func (sc *sharedContext) getStateChangedTimeDiff() cpuTicks { + changedAt := atomic.LoadUint64(&sc.shared.StateChangedTime) + now := uint64(cputicks()) + if now < changedAt { + log.Warningf("likely memory tampering detected: found a condition where now (%d) < changedAt (%d)", now, changedAt) + return 0 + } + return cpuTicks(now - changedAt) +} + +func (sc *sharedContext) resetLatencyMeasures() { + atomic.StoreUint64(&sc.shared.AckedTime, ackReset) + atomic.StoreUint64(&sc.shared.StateChangedTime, stateChangedReset) } const ( @@ -243,60 +271,23 @@ type fastPathDispatcher struct { // entrants contains new contexts that haven't been added to `list` yet. // +checklocks:mu entrants contextList - - // fastPathDisabledTS is the time stamp when the stub fast path was - // disabled. It is zero if the fast path is enabled. - fastPathDisabledTS atomic.Uint64 } var dispatcher fastPathDispatcher -// fastPathContextLimit is the maximum number of contexts after which the fast -// path in stub threads is disabled. Its value can be higher than the number of -// CPU-s, because the Sentry is running with higher priority than stub threads, -// deepSleepTimeout is much shorter than the Linux scheduler timeslice, so the -// only thing that matters here is whether the Sentry handles syscall faster -// than the overhead of scheduling another stub thread. -var fastPathContextLimit = uint32(runtime.GOMAXPROCS(0) * 2) - -// fastPathDisabledTimeout is the timeout after which the fast path in stub -// processes will be re-enabled. -const fastPathDisabledTimeout = uint64(200 * 1000 * 1000) // 100ms for 2GHz. - -// nrMaxAwakeStubThreads is the maximum number of awake stub threads over all -// subprocesses at the this moment. -var nrMaxAwakeStubThreads atomic.Uint32 - -// stubFastPathEnabled returns true if the fast path in stub processes is -// enabled. If the fast path is disabled, it revises whether it has to be -// re-enabled or not. -func (q *fastPathDispatcher) stubFastPathEnabled() bool { - ts := q.fastPathDisabledTS.Load() - if ts != 0 { - if uint64(cputicks())-ts < fastPathDisabledTimeout { - return false - } - if nrMaxAwakeStubThreads.Load() > fastPathContextLimit { - q.fastPathDisabledTS.Store(uint64(cputicks())) - return false - } - q.fastPathDisabledTS.Store(0) - } - return true -} - -// disableStubFastPath disables the fast path over all subprocesses with active -// contexts. -func (q *fastPathDispatcher) disableStubFastPath() { - q.fastPathDisabledTS.Store(uint64(cputicks())) -} - -// deep_sleep_timeout is the timeout after which we stops polling and fall asleep. -// -// The value is 40µs for 2GHz CPU. This timeout matches the sentry<->stub round -// trip in the pure deep sleep case. -const deepSleepTimeout = uint64(80000) -const handshakeTimeout = uint64(1000) +const ( + // deepSleepTimeout is the timeout after which both stub threads and the + // dispatcher consider whether to stop polling. They need to have elapsed + // this timeout twice in a row in order to stop, so the actual timeout + // can be considered to be (deepSleepTimeout*2). Falling asleep after two + // shorter timeouts instead of one long timeout is done in order to + // mitigate the effects of rdtsc inaccuracies. + // + // The value is 20µs for 2GHz CPU. 40µs matches the sentry<->stub + // round trip in the pure deep sleep case. + deepSleepTimeout = uint64(40000) + handshakeTimeout = uint64(1000) +) // loop is processing contexts in the queue. Only one instance of it can be // running, because it has exclusive access to the list. @@ -305,16 +296,13 @@ const handshakeTimeout = uint64(1000) func (q *fastPathDispatcher) loop(target *sharedContext) { done := false processed := 0 + firstTimeout := false slowPath := false - start := cputicks() + startedSpinning := cputicks() for { var ctx, next *sharedContext q.mu.Lock() - if processed != 0 || !q.entrants.Empty() { - start = cputicks() - slowPath = false - } q.nr -= processed // Add new contexts to the list. q.list.PushBackList(&q.entrants) @@ -329,6 +317,7 @@ func (q *fastPathDispatcher) loop(target *sharedContext) { break } + slowPath = !fpState.sentryFastPath() || slowPath processed = 0 now := cputicks() for ctx = q.list.Front(); ctx != nil; ctx = next { @@ -355,20 +344,26 @@ func (q *fastPathDispatcher) loop(target *sharedContext) { } ctx.sync.Receiver().Notify(event) } - if processed == 0 { - if uint64(cputicks()-start) > deepSleepTimeout { - slowPath = true - // Do one more run to notify all contexts. - // q.list has to be empty at the end. - continue - } - yield() + + if processed != 0 { + startedSpinning = now + firstTimeout = false + } else { + fpState.usedSentryFastPath.Store(true) } + // If dispatcher has been spinning for too long, send this + // dispatcher to sleep. + if uint64(now-startedSpinning) > deepSleepTimeout { + slowPath = firstTimeout + firstTimeout = true + } + + yield() } } func (q *fastPathDispatcher) waitFor(ctx *sharedContext) syncevent.Set { - events := syncevent.Set(0) + events := syncevent.NoEvents q.mu.Lock() q.entrants.PushBack(ctx) diff --git a/pkg/sentry/platform/systrap/subprocess.go b/pkg/sentry/platform/systrap/subprocess.go index 2cafc36d6..4dab9e8fc 100644 --- a/pkg/sentry/platform/systrap/subprocess.go +++ b/pkg/sentry/platform/systrap/subprocess.go @@ -701,10 +701,7 @@ func (s *subprocess) incAwakeContexts() { if nr > uint32(maxSysmsgThreads) { return } - nr = nrMaxAwakeStubThreads.Add(1) - if nr > fastPathContextLimit { - dispatcher.disableStubFastPath() - } + fpState.nrMaxAwakeStubThreads.Add(1) } func (s *subprocess) decAwakeContexts() { @@ -712,7 +709,7 @@ func (s *subprocess) decAwakeContexts() { if nr >= uint32(maxSysmsgThreads) { return } - nrMaxAwakeStubThreads.Add(^uint32(0)) + fpState.nrMaxAwakeStubThreads.Add(^uint32(0)) } // switchToApp is called from the main SwitchToApp entrypoint. @@ -747,10 +744,9 @@ func (s *subprocess) switchToApp(c *context, ac *arch.Context64) (isSyscall bool ctx.sleeping = false s.incAwakeContexts() } - stubFastPathEnabled := dispatcher.stubFastPathEnabled() ctx.setState(sysmsg.ContextStateNone) - s.contextQueue.add(ctx, stubFastPathEnabled) - s.waitOnState(ctx, stubFastPathEnabled) + s.contextQueue.add(ctx) + s.waitOnState(ctx) // Check if there's been an error. threadID := ctx.threadID() @@ -789,12 +785,10 @@ func (s *subprocess) switchToApp(c *context, ac *arch.Context64) (isSyscall bool return false, false, nil } -func (s *subprocess) waitOnState(ctx *sharedContext, stubFastPathEnabled bool) { +func (s *subprocess) waitOnState(ctx *sharedContext) { ctx.kicked = false slowPath := false - start := cputicks() - ctx.startWaitingTS = start - if !stubFastPathEnabled || atomic.LoadUint32(&s.contextQueue.numActiveThreads) == 0 { + if !s.contextQueue.fastPathEnabled() || atomic.LoadUint32(&s.contextQueue.numActiveThreads) == 0 { ctx.kicked = s.kickSysmsgThread() } for curState := ctx.state(); curState == sysmsg.ContextStateNone; curState = ctx.state() { @@ -828,7 +822,8 @@ func (s *subprocess) waitOnState(ctx *sharedContext, stubFastPathEnabled bool) { } } - ctx.resetAcked() + ctx.recordLatency() + ctx.resetLatencyMeasures() ctx.enableSentryFastPath() } @@ -857,6 +852,8 @@ func (s *subprocess) canKickSysmsgThread() (bool, uint32) { return true, nrActiveThreads } +// kickSysmsgThread returns true if it was able to wake up or create a new sysmsg +// stub thread. func (s *subprocess) kickSysmsgThread() bool { kick, _ := s.canKickSysmsgThread() if !kick { @@ -869,6 +866,7 @@ func (s *subprocess) kickSysmsgThread() bool { s.sysmsgThreadsMu.Unlock() return false } + numTimesStubKicked.Increment() atomic.AddUint32(&s.contextQueue.numThreadsToWakeup, 1) if s.numSysmsgThreads < maxSysmsgThreads && s.numSysmsgThreads < int(nrThreads) { s.numSysmsgThreads++ @@ -884,7 +882,7 @@ func (s *subprocess) kickSysmsgThread() bool { } s.contextQueue.wakeupSysmsgThread() - return false + return true } // syscall executes the given system call without handling interruptions. diff --git a/pkg/sentry/platform/systrap/sysmsg/sysmsg.go b/pkg/sentry/platform/systrap/sysmsg/sysmsg.go index cd6853b60..dd061d7c8 100644 --- a/pkg/sentry/platform/systrap/sysmsg/sysmsg.go +++ b/pkg/sentry/platform/systrap/sysmsg/sysmsg.go @@ -250,9 +250,15 @@ type ThreadContext struct { // goroutine used for this thread context is busy-polling for a response // instead of using FUTEX_WAIT. SentryFastPath uint32 - // Acked is used by sysmsg threads to signal to the sentry that this context + // AckedTime is used by sysmsg threads to signal to the sentry that this context // has been picked up from the context queue and is actively being worked on. - Acked uint32 + // The stub thread puts down the timestamp at which it has started processing + // this context. + AckedTime uint64 + // StateChangedTime is the time when the ThreadContext.State changed, as + // recorded by the stub thread when it gave it back to the sentry + // (the sentry does not populate this field except to reset it). + StateChangedTime uint64 // TLS is a pointer to a thread local storage. // It is is only populated on ARM64. TLS uint64 @@ -300,7 +306,7 @@ func (c *ThreadContext) String() string { 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, " SentryFastPath %d Acked %d", c.SentryFastPath, c.AckedTime) fmt.Fprintf(&b, " signo: %d, siginfo: %+v", c.Signo, c.SignalInfo) fmt.Fprintf(&b, " debug %d", atomic.LoadUint64(&c.Debug)) b.WriteString("}") diff --git a/pkg/sentry/platform/systrap/sysmsg/sysmsg.h b/pkg/sentry/platform/systrap/sysmsg/sysmsg.h index cce2a5a81..bcce52c5f 100644 --- a/pkg/sentry/platform/systrap/sysmsg/sysmsg.h +++ b/pkg/sentry/platform/systrap/sysmsg/sysmsg.h @@ -93,7 +93,8 @@ struct thread_context { uint32_t thread_id; uint32_t last_thread_id; uint32_t sentry_fast_path; - uint32_t acked; + uint64_t acked_time; + uint64_t state_changed_time; uint64_t tls; uint64_t debug; }; diff --git a/pkg/sentry/platform/systrap/sysmsg/sysmsg_lib.c b/pkg/sentry/platform/systrap/sysmsg/sysmsg_lib.c index 65fbbb272..69fc85f9d 100644 --- a/pkg/sentry/platform/systrap/sysmsg/sysmsg_lib.c +++ b/pkg/sentry/platform/systrap/sysmsg/sysmsg_lib.c @@ -45,12 +45,12 @@ struct context_queue { uint32_t start; uint32_t end; uint32_t num_active_threads; + uint32_t num_spinning_threads; uint32_t num_threads_to_wakeup; uint32_t num_active_contexts; uint32_t num_awake_contexts; - uint64_t fast_path_disalbed_ts; - uint32_t fast_path_failed_in_row; uint32_t fast_path_disabled; + uint32_t used_fast_path; uint64_t ringbuffer[MAX_CONTEXT_QUEUE_ENTRIES]; }; @@ -113,22 +113,33 @@ void memcpy(uint8_t *dest, uint8_t *src, size_t n) { // MAX_SPINNING_THREADS is half of SPINNING_QUEUE_SIZE to be sure that the tail // doesn't catch the head. More details are in spinning_queue_remove_first. #define MAX_SPINNING_THREADS (SPINNING_QUEUE_SIZE / 2) + +// MAX_RE_ENQUEUE defines the amount of time a given entry in the spinning queue +// needs to reach timeout in order to be removed. Re-enqueuing a timeout is done +// in order to mitigate rdtsc inaccuracies. +#define MAX_RE_ENQUEUE 2 + struct spinning_queue { uint32_t start; uint32_t end; uint64_t start_times[SPINNING_QUEUE_SIZE]; + uint8_t num_times_re_enqueued[SPINNING_QUEUE_SIZE]; }; struct spinning_queue *__export_spinning_queue_addr; // spinning_queue_push adds a new thread to the queue. It returns false if the -// queue if full. -static bool spinning_queue_push() __attribute__((warn_unused_result)); -static bool spinning_queue_push(void) { +// queue is full, or if re_enqueue_times has reached MAX_RE_ENQUEUE. +static bool spinning_queue_push(uint8_t re_enqueue_times) + __attribute__((warn_unused_result)); +static bool spinning_queue_push(uint8_t re_enqueue_times) { struct spinning_queue *queue = __export_spinning_queue_addr; uint32_t idx, start, end; BUILD_BUG_ON(sizeof(struct spinning_queue) > SPINNING_QUEUE_MEM_SIZE); + if (re_enqueue_times >= MAX_RE_ENQUEUE) { + return false; + } end = atomic_add(&queue->end, 1); start = atomic_load(&queue->start); @@ -138,12 +149,15 @@ static bool spinning_queue_push(void) { } idx = end - 1; + atomic_store(&queue->num_times_re_enqueued[idx % SPINNING_QUEUE_SIZE], + re_enqueue_times); atomic_store(&queue->start_times[idx % SPINNING_QUEUE_SIZE], rdtsc()); return true; } // spinning_queue_pop() removes one thread from a queue that has been spinning // the shortest time. +// However it doesn't take into account the spinning re-enqueue. static void spinning_queue_pop() { struct spinning_queue *queue = __export_spinning_queue_addr; @@ -162,6 +176,7 @@ static bool spinning_queue_remove_first(uint64_t timeout) { struct spinning_queue *queue = __export_spinning_queue_addr; uint64_t ts; uint32_t idx; + uint8_t re_enqueue = 0; while (1) { idx = atomic_load(&queue->start); @@ -173,12 +188,15 @@ static bool spinning_queue_remove_first(uint64_t timeout) { // twice of the maximum number of threads, so we can zero the element and be // sure that nobody is trying to set it in a non-zero value. atomic_store(&queue->start_times[idx % SPINNING_QUEUE_SIZE], 0); + re_enqueue = + atomic_load(&queue->num_times_re_enqueued[idx % SPINNING_QUEUE_SIZE]); if (atomic_compare_exchange(&queue->start, &idx, idx + 1)) { break; } } - return true; + if (timeout == 0) return true; + return !spinning_queue_push(re_enqueue + 1); } struct thread_context *queue_get_context(struct sysmsg *sysmsg) { @@ -210,30 +228,27 @@ struct thread_context *queue_get_context(struct sysmsg *sysmsg) { } struct thread_context *ctx = thread_context_addr(context_id); sysmsg->context = ctx; - atomic_store(&ctx->acked, 1); + atomic_store(&ctx->acked_time, rdtsc()); atomic_store(&ctx->thread_id, sysmsg->thread_id); return ctx; } return NULL; } -#define FAILED_FAST_PATH_LIMIT 5 -#define FAILED_FAST_PATH_TIMEOUT 20000000 // 10ms - // get_context_fast sets nr_active_threads_p only if it deactivates the thread. static struct thread_context *get_context_fast(struct sysmsg *sysmsg, struct context_queue *queue, uint32_t *nr_active_threads_p) { uint32_t nr_active_threads, nr_awake_contexts; - if (!spinning_queue_push()) return NULL; + if (!spinning_queue_push(0)) return NULL; + atomic_store(&queue->used_fast_path, 1); while (1) { struct thread_context *ctx; ctx = queue_get_context(sysmsg); if (ctx) { - atomic_store(&queue->fast_path_failed_in_row, 0); spinning_queue_pop(); return ctx; } @@ -257,10 +272,6 @@ static struct thread_context *get_context_fast(struct sysmsg *sysmsg, } if (spinning_queue_remove_first(__export_deep_sleep_timeout)) { - uint32_t nr = atomic_add(&queue->fast_path_failed_in_row, 1); - if (nr >= FAILED_FAST_PATH_LIMIT) { - atomic_store(&queue->fast_path_disalbed_ts, rdtsc()); - } break; } spinloop(); @@ -295,41 +306,29 @@ struct thread_context *get_context(struct sysmsg *sysmsg) { struct context_queue *queue = __export_context_queue_addr; uint32_t nr_active_threads; + struct thread_context *ctx; for (;;) { - struct thread_context *ctx; + atomic_add(&queue->num_spinning_threads, 1); // Change sysmsg thread state just to indicate thread is not asleep. atomic_store(&sysmsg->state, THREAD_STATE_PREP); ctx = queue_get_context(sysmsg); if (ctx) { - atomic_store(&queue->fast_path_failed_in_row, 0); - return ctx; + goto exit; } - uint64_t slow_path_ts = atomic_load(&queue->fast_path_disalbed_ts); - bool fast_path_enabled = true; - - if (!slow_path_ts) { - if (rdtsc() - slow_path_ts > FAILED_FAST_PATH_TIMEOUT) { - atomic_store(&queue->fast_path_failed_in_row, 0); - atomic_store(&queue->fast_path_disalbed_ts, 0); - } else { - fast_path_enabled = false; - } - } - if (atomic_load(&queue->fast_path_disabled) != 0) { - fast_path_enabled = false; - } + bool fast_path_enabled = atomic_load(&queue->fast_path_disabled) == 0; nr_active_threads = NR_IF_THREAD_IS_ACTIVE; if (fast_path_enabled) { ctx = get_context_fast(sysmsg, queue, &nr_active_threads); - if (ctx) return ctx; + if (ctx) goto exit; } if (nr_active_threads == NR_IF_THREAD_IS_ACTIVE) { nr_active_threads = atomic_sub(&queue->num_active_threads, 1); } + atomic_sub(&queue->num_spinning_threads, 1); atomic_store(&sysmsg->state, THREAD_STATE_ASLEEP); uint32_t nr_active_contexts = atomic_load(&queue->num_active_contexts); // We have to make another attempt to get a context here to prevent TOCTTOU @@ -360,6 +359,9 @@ struct thread_context *get_context(struct sysmsg *sysmsg) { } } } +exit: + atomic_sub(&queue->num_spinning_threads, 1); + return ctx; } // switch_context signals the sentry that the old context is ready to be worked @@ -373,6 +375,7 @@ struct thread_context *switch_context(struct sysmsg *sysmsg, atomic_sub(&queue->num_active_contexts, 1); atomic_store(&ctx->thread_id, INVALID_THREAD_ID); atomic_store(&ctx->last_thread_id, sysmsg->thread_id); + atomic_store(&ctx->state_changed_time, rdtsc()); atomic_store(&ctx->state, new_context_state); if (atomic_load(&ctx->sentry_fast_path) == 0) { int ret = sys_futex(&ctx->state, FUTEX_WAKE, 1, NULL, NULL, 0); diff --git a/pkg/sentry/platform/systrap/systrap.go b/pkg/sentry/platform/systrap/systrap.go index 261ed4e86..e5869845c 100644 --- a/pkg/sentry/platform/systrap/systrap.go +++ b/pkg/sentry/platform/systrap/systrap.go @@ -102,6 +102,10 @@ var ( // stubInitialized controls one-time stub initialization. stubInitialized sync.Once + // latencyMonitoring controls one-time initialization of the fastpath + // control goroutine. + latencyMonitoring sync.Once + // archState stores architecture-specific details used in the platform. archState sysmsg.ArchState ) @@ -337,6 +341,10 @@ func New() (*Systrap, error) { initSysmsgThreadPriority() }) + latencyMonitoring.Do(func() { + go controlFastPath() + }) + return &Systrap{memoryFile: mf}, nil } diff --git a/pkg/sentry/platform/systrap/systrap_profiling.go b/pkg/sentry/platform/systrap/systrap_profiling.go new file mode 100644 index 000000000..42760aba4 --- /dev/null +++ b/pkg/sentry/platform/systrap/systrap_profiling.go @@ -0,0 +1,60 @@ +// Copyright 2023 The gVisor Authors. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//go:build systrap_profiling +// +build systrap_profiling + +package systrap + +import ( + "gvisor.dev/gvisor/pkg/metric" +) + +// SystrapProfiling is a builder that produces conditionally compiled metrics. +// Metrics made from this are compiled and active at runtime when the +// "systrap_profiling" go-tag is specified at compilation. +var SystrapProfiling = metric.RealMetricBuilder{} + +//go:nosplit +func updateDebugMetrics(stubBoundLat, sentryBoundLat cpuTicks) { + if stubBoundLat == 0 { + } else if stubBoundLat < 2000 { + stubLatWithin1kUS.Increment() + } else if stubBoundLat < 10000 { + stubLatWithin5kUS.Increment() + } else if stubBoundLat < 20000 { + stubLatWithin10kUS.Increment() + } else if stubBoundLat < 40000 { + stubLatWithin20kUS.Increment() + } else if stubBoundLat < 80000 { + stubLatWithin40kUS.Increment() + } else { + stubLatGreater40kUS.Increment() + } + + if sentryBoundLat == 0 { + } else if sentryBoundLat < 2000 { + sentryLatWithin1kUS.Increment() + } else if sentryBoundLat < 10000 { + sentryLatWithin5kUS.Increment() + } else if sentryBoundLat < 20000 { + sentryLatWithin10kUS.Increment() + } else if sentryBoundLat < 40000 { + sentryLatWithin20kUS.Increment() + } else if sentryBoundLat < 80000 { + sentryLatWithin40kUS.Increment() + } else { + sentryLatGreater40kUS.Increment() + } +} diff --git a/pkg/sentry/platform/systrap/systrap_profiling_fake.go b/pkg/sentry/platform/systrap/systrap_profiling_fake.go new file mode 100644 index 000000000..c2b5617a6 --- /dev/null +++ b/pkg/sentry/platform/systrap/systrap_profiling_fake.go @@ -0,0 +1,30 @@ +// Copyright 2023 The gVisor Authors. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//go:build !systrap_profiling +// +build !systrap_profiling + +package systrap + +import ( + "gvisor.dev/gvisor/pkg/metric" +) + +// SystrapProfiling is a builder that produces conditionally compiled metrics. +// Metrics made from this are compiled and active at runtime when the +// "systrap_profiling" go-tag is specified at compilation. +var SystrapProfiling = metric.FakeMetricBuilder{} + +//go:nosplit +func updateDebugMetrics(stubBoundLat, sentryBoundLat cpuTicks) {}