feat(causal): offcpu audit bucket — the @50 deficit located (RFC 007)

GPU sweep decomposed the ~23ms/700ms @50 injection deficit: every
ledger bucket is ~zero (drop park 0, discards 0, drop yield ~0.3ms),
books balance at absorbed+forgiven = 4x injected in all 48 cells, and
the 0%-cell contamination signature is absent. The probe pins the
residual: eff 0.933-0.943, a constant 22-27µs missing per site entry
= ~4.9 slice-expiry yields/entry x ~5.6µs runqueue wait. The
"deficit" is runnable off-CPU time inside the site — wall time the
probe's ground truth counts but on-CPU attribution correctly skips
(Coz model: speeding the site's code does not shrink queue-wait).

Measure-only reclassification, no behaviour change: a yield in the
target site stashes (tsc, experiment epoch) on the slot; the next
on_resume counts the gap into OFFCPU_IN_SITE_{CYCLES,N} (would-be
delta terms, MAX_SAMPLE_CYCLES-capped) iff the epoch still matches
and the word is live — a gap straddling end()/a same-word begin()
(live in the probe's 50,50 schedule) is dropped, never a leaked
cooldown. Parks excluded: blocked time is forgiveness territory.
New offcpu column in render_ledger_audit; LedgerCounters and
ExperimentResult grow the two fields. Fidelity footer now states
the on-CPU basis (deliberate wording change to the pinned summary;
the substring pin test still holds). +2 tests (counted gap; epoch
straddle) + render assert.
This commit is contained in:
Claude (sandbox)
2026-07-13 12:46:15 +00:00
parent 9bfeb2c6a2
commit 0ee3fe7330
3 changed files with 169 additions and 6 deletions
+67 -6
View File
@@ -48,6 +48,12 @@ mod inner {
/// across scheduler threads (jar Q7, v1: plain Relaxed atomics). /// across scheduler threads (jar Q7, v1: plain Relaxed atomics).
static EXPERIMENT: AtomicU64 = AtomicU64::new(0); static EXPERIMENT: AtomicU64 = AtomicU64::new(0);
/// Monotone experiment-window counter, bumped by every `begin()`. Lets
/// the offcpu-gap stash (RFC 007) tell apart two windows with an
/// identical site+pct word — live in the attrib probe's 50,50 schedule
/// — so a gap straddling `end()`/`begin()` never counts a cooldown.
static EXPERIMENT_EPOCH: AtomicU64 = AtomicU64::new(0);
/// Global virtual-delay ledger, in TSC cycles: the total delay every /// Global virtual-delay ledger, in TSC cycles: the total delay every
/// actor *should* have experienced since startup. Grows while a sample /// actor *should* have experienced since startup. Grows while a sample
/// lands in the experiment's target site; each actor's `Slot` ledger /// lands in the experiment's target site; each actor's `Slot` ledger
@@ -103,6 +109,13 @@ mod inner {
static DISCARD_OVERMAX_N: AtomicU64 = AtomicU64::new(0); static DISCARD_OVERMAX_N: AtomicU64 = AtomicU64::new(0);
/// In-site samples dropped because the thread's clock was unarmed. /// In-site samples dropped because the thread's clock was unarmed.
static DISCARD_UNARMED_N: AtomicU64 = AtomicU64::new(0); static DISCARD_UNARMED_N: AtomicU64 = AtomicU64::new(0);
/// Would-be attribution over runnable off-CPU gaps inside the target
/// site (yield-descheduled -> resumed within the same window). Not a
/// loss: on-CPU-only attribution is the Coz model — queue-wait is not
/// shrunk by speeding the site's code — but counted so the audit books
/// close against wall in-site time (the located @50 "deficit").
static OFFCPU_IN_SITE_CYCLES: AtomicU64 = AtomicU64::new(0);
static OFFCPU_IN_SITE_N: AtomicU64 = AtomicU64::new(0);
fn sites() -> &'static Mutex<Vec<&'static str>> { fn sites() -> &'static Mutex<Vec<&'static str>> {
SITES.get_or_init(|| Mutex::new(Vec::new())) SITES.get_or_init(|| Mutex::new(Vec::new()))
@@ -387,10 +400,30 @@ mod inner {
/// its debt: it must pay by spinning at its next check. Forgiving on /// its debt: it must pay by spinning at its next check. Forgiving on
/// every resume would make any yield-cadence actor delay-immune and /// every resume would make any yield-cadence actor delay-immune and
/// experiments inert (found live on a 24-core run: nothing slowed). /// experiments inert (found live on a 24-core run: nothing slowed).
/// - If the deschedule was a *yield* in the live experiment's target
/// site, count the off-CPU gap it opened into the offcpu audit bucket
/// (RFC 007: the located @50 deficit — runnable queue-wait is wall
/// time in-site that on-CPU attribution correctly skips). Same-window
/// only, enforced by the experiment epoch; measure-only.
/// - Arm this thread's sample clock so the first interval of the resume /// - Arm this thread's sample clock so the first interval of the resume
/// excludes scheduler time. /// excludes scheduler time.
#[inline] #[inline]
pub(crate) fn on_resume(slot: &crate::runtime::Slot) { pub(crate) fn on_resume(slot: &crate::runtime::Slot) {
let (desched_tsc, desched_epoch) = slot.take_causal_desched();
if desched_tsc != 0 && desched_epoch == EXPERIMENT_EPOCH.load(Ordering::Relaxed) {
// Same epoch ⇒ no `begin()` since the stash; a nonzero word ⇒
// no `end()` either — the gap closed inside its own window.
let exp = EXPERIMENT.load(Ordering::Relaxed);
if exp != 0 {
let pct = exp & 0xffff_ffff;
let gap = preempt::rdtsc()
.saturating_sub(desched_tsc)
.min(MAX_SAMPLE_CYCLES);
OFFCPU_IN_SITE_CYCLES
.fetch_add(gap.saturating_mul(pct) / 100, Ordering::Relaxed);
OFFCPU_IN_SITE_N.fetch_add(1, Ordering::Relaxed);
}
}
if slot.take_causal_parked() { if slot.take_causal_parked() {
let global = GLOBAL_DELAY.load(Ordering::Relaxed); let global = GLOBAL_DELAY.load(Ordering::Relaxed);
let mine = slot.causal_delay(); let mine = slot.causal_delay();
@@ -417,6 +450,9 @@ mod inner {
/// Slice-expiry yields sample at the same checkpoint that deschedules /// Slice-expiry yields sample at the same checkpoint that deschedules
/// them, so their tails are ~zero by construction; a fat yield bucket /// them, so their tails are ~zero by construction; a fat yield bucket
/// therefore points at explicit `yield_now` calls or requeued parks. /// therefore points at explicit `yield_now` calls or requeued parks.
///
/// Yields additionally stash the deschedule instant on the slot so
/// `on_resume` can count the runnable off-CPU gap (offcpu bucket).
pub(crate) fn on_deschedule(slot: &crate::runtime::Slot, real_park: bool) { pub(crate) fn on_deschedule(slot: &crate::runtime::Slot, real_park: bool) {
let exp = EXPERIMENT.load(Ordering::Relaxed); let exp = EXPERIMENT.load(Ordering::Relaxed);
if exp == 0 { if exp == 0 {
@@ -427,11 +463,19 @@ mod inner {
if pct == 0 || slot.causal_site() != target { if pct == 0 || slot.causal_site() != target {
return; return;
} }
let now = preempt::rdtsc();
if !real_park {
// Runnable gap opens here; `on_resume` closes and counts it
// (offcpu bucket). Parks are excluded: blocked time is already
// represented by forgiveness, and blocked wall time is not
// queue-wait.
slot.set_causal_desched(now, EXPERIMENT_EPOCH.load(Ordering::Relaxed));
}
let last = LAST_SAMPLE_TSC.with(|c| c.get()); let last = LAST_SAMPLE_TSC.with(|c| c.get());
if last == 0 { if last == 0 {
return; return;
} }
let interval = preempt::rdtsc().saturating_sub(last).min(MAX_SAMPLE_CYCLES); let interval = now.saturating_sub(last).min(MAX_SAMPLE_CYCLES);
let would_be = interval.saturating_mul(pct) / 100; let would_be = interval.saturating_mul(pct) / 100;
if real_park { if real_park {
DROP_PARK_N.fetch_add(1, Ordering::Relaxed); DROP_PARK_N.fetch_add(1, Ordering::Relaxed);
@@ -447,6 +491,7 @@ mod inner {
// ----------------------------------------------------------------------- // -----------------------------------------------------------------------
fn begin(site: u32, pct: u32) { fn begin(site: u32, pct: u32) {
EXPERIMENT_EPOCH.fetch_add(1, Ordering::Relaxed);
EXPERIMENT.store(((site as u64) << 32) | pct as u64, Ordering::Relaxed); EXPERIMENT.store(((site as u64) << 32) | pct as u64, Ordering::Relaxed);
} }
@@ -474,6 +519,8 @@ mod inner {
pub discard_overmax_cycles: u64, pub discard_overmax_cycles: u64,
pub discard_overmax_n: u64, pub discard_overmax_n: u64,
pub discard_unarmed_n: u64, pub discard_unarmed_n: u64,
pub offcpu_in_site_cycles: u64,
pub offcpu_in_site_n: u64,
} }
impl LedgerCounters { impl LedgerCounters {
@@ -497,6 +544,10 @@ mod inner {
.saturating_sub(before.discard_overmax_cycles), .saturating_sub(before.discard_overmax_cycles),
discard_overmax_n: self.discard_overmax_n.saturating_sub(before.discard_overmax_n), discard_overmax_n: self.discard_overmax_n.saturating_sub(before.discard_overmax_n),
discard_unarmed_n: self.discard_unarmed_n.saturating_sub(before.discard_unarmed_n), discard_unarmed_n: self.discard_unarmed_n.saturating_sub(before.discard_unarmed_n),
offcpu_in_site_cycles: self
.offcpu_in_site_cycles
.saturating_sub(before.offcpu_in_site_cycles),
offcpu_in_site_n: self.offcpu_in_site_n.saturating_sub(before.offcpu_in_site_n),
} }
} }
} }
@@ -513,6 +564,8 @@ mod inner {
discard_overmax_cycles: DISCARD_OVERMAX_CYCLES.load(Ordering::Relaxed), discard_overmax_cycles: DISCARD_OVERMAX_CYCLES.load(Ordering::Relaxed),
discard_overmax_n: DISCARD_OVERMAX_N.load(Ordering::Relaxed), discard_overmax_n: DISCARD_OVERMAX_N.load(Ordering::Relaxed),
discard_unarmed_n: DISCARD_UNARMED_N.load(Ordering::Relaxed), discard_unarmed_n: DISCARD_UNARMED_N.load(Ordering::Relaxed),
offcpu_in_site_cycles: OFFCPU_IN_SITE_CYCLES.load(Ordering::Relaxed),
offcpu_in_site_n: OFFCPU_IN_SITE_N.load(Ordering::Relaxed),
} }
} }
@@ -592,6 +645,8 @@ mod inner {
pub discard_overmax_cycles: u64, pub discard_overmax_cycles: u64,
pub discard_overmax_n: u64, pub discard_overmax_n: u64,
pub discard_unarmed_n: u64, pub discard_unarmed_n: u64,
pub offcpu_in_site_cycles: u64,
pub offcpu_in_site_n: u64,
} }
/// Run the plan synchronously on the calling (OS) thread: for every /// Run the plan synchronously on the calling (OS) thread: for every
@@ -671,6 +726,8 @@ mod inner {
discard_overmax_cycles: audit.discard_overmax_cycles, discard_overmax_cycles: audit.discard_overmax_cycles,
discard_overmax_n: audit.discard_overmax_n, discard_overmax_n: audit.discard_overmax_n,
discard_unarmed_n: audit.discard_unarmed_n, discard_unarmed_n: audit.discard_unarmed_n,
offcpu_in_site_cycles: audit.offcpu_in_site_cycles,
offcpu_in_site_n: audit.offcpu_in_site_n,
}); });
controller_sleep(plan.cooldown); controller_sleep(plan.cooldown);
} }
@@ -753,9 +810,10 @@ mod inner {
/// site buys you nothing — the RFC's headline answer. /// site buys you nothing — the RFC's headline answer.
/// ///
/// Ends with a one-line fidelity note (RFC 007 Validation): reported /// Ends with a one-line fidelity note (RFC 007 Validation): reported
/// impacts are conservative — the controller undershoots ideal injection /// impacts are conservative — attribution counts on-CPU site time only,
/// at high speedup pcts, so gains are lower bounds; site *rankings* are /// so runnable queue-wait inside the site (the located @50 "deficit",
/// unaffected. /// eff ≈ 0.93 live) is never injected and gains are lower bounds; site
/// *rankings* are unaffected.
pub fn render_summary(results: &[ExperimentResult]) -> String { pub fn render_summary(results: &[ExperimentResult]) -> String {
use std::fmt::Write; use std::fmt::Write;
let mut s = String::new(); let mut s = String::new();
@@ -789,7 +847,7 @@ mod inner {
if !results.is_empty() { if !results.is_empty() {
let _ = writeln!( let _ = writeln!(
s, s,
"note: impacts are lower bounds — undershoot grows with speedup pct; rankings unaffected" "note: impacts are lower bounds — site time counts on-CPU only (runnable queue-wait is not attributed); rankings unaffected"
); );
} }
s s
@@ -812,7 +870,8 @@ mod inner {
let _ = writeln!( let _ = writeln!(
s, s,
"site {:<22} @{:>2}% injected {:>7.1}ms absorbed {:>7.1}ms forgiven {:>7.1}ms \ "site {:<22} @{:>2}% injected {:>7.1}ms absorbed {:>7.1}ms forgiven {:>7.1}ms \
drop park {:>6.2}ms/{:<4} yield {:>6.2}ms/{:<4} discard >max {:>6.2}ms/{:<3} unarmed {}", drop park {:>6.2}ms/{:<4} yield {:>6.2}ms/{:<4} offcpu {:>6.2}ms/{:<5} \
discard >max {:>6.2}ms/{:<3} unarmed {}",
r.site, r.site,
r.speedup_pct, r.speedup_pct,
ms(r.injected_cycles), ms(r.injected_cycles),
@@ -822,6 +881,8 @@ mod inner {
r.drop_park_n, r.drop_park_n,
ms(r.drop_yield_cycles), ms(r.drop_yield_cycles),
r.drop_yield_n, r.drop_yield_n,
ms(r.offcpu_in_site_cycles),
r.offcpu_in_site_n,
ms(r.discard_overmax_cycles), ms(r.discard_overmax_cycles),
r.discard_overmax_n, r.discard_overmax_n,
r.discard_unarmed_n r.discard_unarmed_n
+34
View File
@@ -467,6 +467,18 @@ pub(crate) struct Slot {
/// history. Written by the owning scheduler thread at the deschedule / /// history. Written by the owning scheduler thread at the deschedule /
/// resume boundary only — same single-writer discipline as `causal_delay`. /// resume boundary only — same single-writer discipline as `causal_delay`.
causal_parked: AtomicBool, causal_parked: AtomicBool,
/// RFC 007 — TSC at this actor's last *runnable* (yield) deschedule
/// while it sat in the live experiment's target site; 0 = no gap
/// pending. Paired with `causal_desched_epoch`; written on the
/// deschedule path, consumed at the next resume — same single-writer
/// discipline as `causal_delay`.
causal_desched_tsc: AtomicU64,
/// RFC 007 — experiment epoch live at that deschedule (see
/// `causal::EXPERIMENT_EPOCH`): the resume counts the gap only into
/// the same window, so one straddling `end()` — or a later `begin()`
/// with an identical site+pct word — is dropped instead of leaking a
/// cooldown across windows.
causal_desched_epoch: AtomicU64,
/// Cold lifecycle data. See [`SlotCold`]. /// Cold lifecycle data. See [`SlotCold`].
pub(crate) cold: RawMutex<SlotCold>, pub(crate) cold: RawMutex<SlotCold>,
} }
@@ -484,6 +496,8 @@ impl Slot {
causal_site: AtomicU32::new(0), causal_site: AtomicU32::new(0),
causal_delay: AtomicU64::new(0), causal_delay: AtomicU64::new(0),
causal_parked: AtomicBool::new(true), causal_parked: AtomicBool::new(true),
causal_desched_tsc: AtomicU64::new(0),
causal_desched_epoch: AtomicU64::new(0),
cold: RawMutex::new(SlotCold { cold: RawMutex::new(SlotCold {
actor: None, actor: None,
waiters: Vec::new(), waiters: Vec::new(),
@@ -577,6 +591,8 @@ impl Slot {
// True, not false: the first resume of a fresh actor is a "wake" — // True, not false: the first resume of a fresh actor is a "wake" —
// it must not owe the process's accumulated delay history. // it must not owe the process's accumulated delay history.
self.causal_parked.store(true, Ordering::Relaxed); self.causal_parked.store(true, Ordering::Relaxed);
self.causal_desched_tsc.store(0, Ordering::Relaxed);
self.causal_desched_epoch.store(0, Ordering::Relaxed);
} }
/// RFC 007 — mark that this actor's deschedule was a genuine park. /// RFC 007 — mark that this actor's deschedule was a genuine park.
@@ -597,6 +613,24 @@ impl Slot {
self.causal_parked.swap(false, Ordering::Relaxed) self.causal_parked.swap(false, Ordering::Relaxed)
} }
/// RFC 007 — stash the runnable-deschedule instant and the experiment
/// epoch it happened under (offcpu-gap audit; see `causal::on_resume`).
#[cfg_attr(not(feature = "smarm-causal"), allow(dead_code))]
#[inline]
pub(crate) fn set_causal_desched(&self, tsc: u64, epoch: u64) {
self.causal_desched_tsc.store(tsc, Ordering::Relaxed);
self.causal_desched_epoch.store(epoch, Ordering::Relaxed);
}
/// RFC 007 — consume the stash: `(tsc, epoch)`; `(0, _)` = none pending.
#[cfg_attr(not(feature = "smarm-causal"), allow(dead_code))]
#[inline]
pub(crate) fn take_causal_desched(&self) -> (u64, u64) {
let tsc = self.causal_desched_tsc.swap(0, Ordering::Relaxed);
let epoch = self.causal_desched_epoch.load(Ordering::Relaxed);
(tsc, epoch)
}
/// RFC 007 — current causal site id (0 = none). Single-writer: only the /// RFC 007 — current causal site id (0 = none). Single-writer: only the
/// on-CPU actor's thread writes, via the site-guard enter/exit. /// on-CPU actor's thread writes, via the site-guard enter/exit.
#[cfg_attr(not(feature = "smarm-causal"), allow(dead_code))] #[cfg_attr(not(feature = "smarm-causal"), allow(dead_code))]
+68
View File
@@ -902,10 +902,78 @@ fn ledger_audit_renders_per_cell() {
discard_overmax_cycles: 5_000, discard_overmax_cycles: 5_000,
discard_overmax_n: 1, discard_overmax_n: 1,
discard_unarmed_n: 0, discard_unarmed_n: 0,
offcpu_in_site_cycles: 20_000,
offcpu_in_site_n: 3,
}]; }];
let s = render_ledger_audit(&results); let s = render_ledger_audit(&results);
assert!(s.contains("ledger audit"), "missing header: {s}"); assert!(s.contains("ledger audit"), "missing header: {s}");
assert!(s.contains("audit-render-site"), "missing site line: {s}"); assert!(s.contains("audit-render-site"), "missing site line: {s}");
assert!(s.contains("absorbed"), "missing absorbed column: {s}"); assert!(s.contains("absorbed"), "missing absorbed column: {s}");
assert!(s.contains("forgiven"), "missing forgiven column: {s}"); assert!(s.contains("forgiven"), "missing forgiven column: {s}");
assert!(s.contains("offcpu"), "missing offcpu column: {s}");
}
/// A runnable (yield) deschedule inside the target site opens an off-CPU
/// gap; the resume closing it lands in the same experiment window, so the
/// audit counts it. RFC 007: this is the located @50 deficit — runnable
/// queue-wait is real wall time in-site that on-CPU attribution correctly
/// skips; the bucket exists so the books close instead of leaving a
/// silent ~7% residual.
#[test]
fn audit_counts_offcpu_runnable_gap_in_target_site() {
let _s = serial();
smarm::init(smarm::Config::exact(1)).run(|| {
smarm::causal::begin_experiment_for_test("audit-offcpu-site", 50);
let c0 = smarm::causal::ledger_counters();
let h = smarm::spawn(|| {
let _g = smarm::causal_site!("audit-offcpu-site");
smarm::check!(); // arm
smarm::yield_now(); // runnable gap: deschedule -> resume
smarm::check!();
});
h.join().unwrap();
let c1 = smarm::causal::ledger_counters();
smarm::causal::end_experiment_for_test();
assert!(
c1.offcpu_in_site_n > c0.offcpu_in_site_n,
"in-site runnable gap recorded no offcpu event"
);
assert!(
c1.offcpu_in_site_cycles > c0.offcpu_in_site_cycles,
"in-site runnable gap carried no cycles"
);
});
}
/// An off-CPU gap that straddles `end()` — even into a later window with
/// an identical site+pct word (live in the attrib probe's 50,50 schedule)
/// — is dropped, not counted: the stash carries the experiment *epoch*,
/// so a straddling resume can never leak a cooldown across windows.
#[test]
fn audit_offcpu_gap_across_windows_not_counted() {
let _s = serial();
smarm::init(smarm::Config::exact(1)).run(|| {
smarm::causal::begin_experiment_for_test("audit-offcpu-straddle", 50);
let c0 = smarm::causal::ledger_counters();
let h = smarm::spawn(|| {
let _g = smarm::causal_site!("audit-offcpu-straddle");
smarm::check!();
smarm::yield_now(); // stash carries window A's epoch
smarm::check!();
});
// FIFO on exact(1): let h run to its yield, then close window A and
// open a same-word window B before h resumes.
smarm::yield_now();
smarm::causal::end_experiment_for_test();
smarm::causal::begin_experiment_for_test("audit-offcpu-straddle", 50);
h.join().unwrap();
let c1 = smarm::causal::ledger_counters();
smarm::causal::end_experiment_for_test();
assert_eq!(
c1.offcpu_in_site_n, c0.offcpu_in_site_n,
"gap straddling windows must not be counted"
);
});
} }