From 6fe45b175f908f43847058691b0254a3c404aba9 Mon Sep 17 00:00:00 2001 From: Transaction Science Date: Mon, 12 Oct 2026 09:14:58 -0400 Subject: [PATCH 1/5] jouleclaw-energy: a process reads itself only once the reading thread has left its core The kernel adds a thread's CPU energy to its process's count (proc_pid_rusage ri_energy_nj) only when the thread leaves a core. A process reading its own count does not take the reading thread off its core, so the read is short of what that thread spent since it last left: a span's first read put up to a scheduling quantum of energy from before the span inside it, and its last read left the span's tail out. Both were sealed HwShunt. Measured against a reader that sleeps before its own reads and checks the process's context-switch count rose, 40 spans of each kind a run, three runs a host (macOS 27.0.1): - 1 ms of the reading thread's CPU: on an M5 Max at a load average of about 90, 25, 31 and 27 spans read no advance or under three quarters of the work; on an idle M3 Ultra, all 40 read no advance, every run; - a 2 ms sleep straight after 8 ms of CPU: on the M5 Max 25, 26 and 31 spans read the CPU before them as the sleep's energy, up to 18 mJ; on the M3 Ultra all 40 read the whole burn, 42 to 53 mJ for a sleep. ProcessCpuCounter now sleeps before each read of its own process (50 us, then 200 us, 1 ms, 5 ms) and reads only once the reading thread's own energy count (proc_pidinfo PROC_PIDTHREADCOUNTS, layout-gated: 88 bytes and two performance levels on both hosts) rose across a sleep. A read whose thread was not seen to leave is EnergyError::NotFolded, no reading: measure() gives no figure, read() fails, and a ProcessSpanMeter span falls back to the host meter. The fold is inside process::energy_nj, the one call span.rs makes for the CPU half, so it holds whatever order span.rs takes its readings in. The counter is Unavailable where the thread's count does not read, and the liveness probe still reads with no sleep. With it, all 40 spans of each kind agreed on both hosts: at least 95% of the work on the loaded M5 Max and 97% on the quiet M3 Ultra, at most 0.5% of the burn before a sleep; and under 40 busy loops on the M3 Ultra (220 runs), at least 84% and at most 2% (the oracle's window also holds both readers' own reads, which do not shrink with the work). A read costs about 80 us on the quiet M3 Ultra, about 200 to 330 us at the median under the busy loops, and 81 to 154 us at the median on the M5 Max at a load average of 135, against 1 us. tests/process_cpu_short_span.rs is the test that fails without the fold. Co-Authored-By: Claude Opus 5.5 --- jouleclaw/SPEC.md | 15 +- .../jouleclaw-energy/MEASURED_ENERGY.md | 24 + .../crates/jouleclaw-energy/src/lib.rs | 20 +- .../crates/jouleclaw-energy/src/process.rs | 450 +++++++++++++++++- .../crates/jouleclaw-energy/src/span.rs | 4 + .../tests/process_cpu_short_span.rs | 228 +++++++++ 6 files changed, 719 insertions(+), 22 deletions(-) create mode 100644 jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/tests/process_cpu_short_span.rs diff --git a/jouleclaw/SPEC.md b/jouleclaw/SPEC.md index 4c632c300..dde682244 100644 --- a/jouleclaw/SPEC.md +++ b/jouleclaw/SPEC.md @@ -121,7 +121,20 @@ Realistic floors: sales talk; the spec is honest about this. - Apple Silicon, per process (macOS 27.0.1, unprivileged): the process's own CPU energy (`proc_pid_rusage`, nJ, live) is - `HwShunt`. Its GPU energy is `HwShunt` in two cases only: an exact + `HwShunt`. The kernel adds a thread's energy to that count only + when the thread leaves a core, and a process's read of its own + count does not take the reading thread off its core, so such a read + is short of what that thread spent since it last left one: up to a + scheduling quantum, missing from a span that ends there and, spent + before it, inside a span that starts there (measured: of 40 spans + over 1 ms of the reading thread's CPU, 25 to 31 read nothing or + under three quarters of it). An implementation **MUST** take each + read of its own process only once it has checked that the reading + thread left its core just before it — the reference counter sleeps, + and reads only once that thread's own energy count (`proc_pidinfo`, + `PROC_PIDTHREADCOUNTS`) rose across a sleep — and a span with an + end not so checked **MUST NOT** be graded a hardware reading: it is + estimated. Its GPU energy is `HwShunt` in two cases only: an exact zero when its own GPU time (I/O Registry) did not move, and the IOReport `GPU Energy` rail (nJ, live) when it had at least 99% of every GPU client's GPU time over the span. A shared GPU gives no diff --git a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/MEASURED_ENERGY.md b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/MEASURED_ENERGY.md index 81516b19e..7735d227b 100644 --- a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/MEASURED_ENERGY.md +++ b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/MEASURED_ENERGY.md @@ -71,6 +71,30 @@ two live sources replace the frozen rails: | `process-cpu` ([`process`](src/process.rs)) | `proc_pid_rusage` `ri_energy_nj` | this process's CPU | **HwShunt** while live | | `ProcessGpuCounter` ([`process_gpu`](src/process_gpu.rs), `ioreport`) | this process's `accumulatedGPUTime` (I/O Registry `IOAccelerator` user clients); IOReport `GPU Energy` (nJ) | this process's GPU | **HwShunt**: 0 µJ exact with no GPU time; the rail at ≥ 99% of every client's GPU time; else no figure | +The CPU count is read only once the reading thread is seen to have left its +core. The kernel adds a thread's energy to its process's count when the thread +leaves a core, and a process reading itself does not make the reading thread +leave, so a read from a thread that has been running is short of what it spent +since it last left: up to a scheduling quantum, missing from a span that ends +there and, spent before it, inside a span that starts there. `process-cpu` +sleeps before each read of its own process (50 µs, then 200 µs, 1 ms, 5 ms) +until the reading thread's own energy count (`proc_pidinfo`, +`PROC_PIDTHREADCOUNTS`) rose across a sleep; a read whose thread was not seen +to leave is no reading (`NotFolded`), and its span falls back to the host +meter. `tests/process_cpu_short_span.rs` holds 1 ms spans, and sleeps metered +straight after a burn, against a reader that folds by its own rule, 40 spans +of each a run. Without the sleep: on an M5 Max at a load average of 90 to 135, +25 to 31 of the 1 ms spans read nothing or under three quarters of the work, +and 25 to 31 of the sleeps read the burn before them (up to 18 mJ); on an idle +M3 Ultra, all 40 of the 1 ms spans read nothing and all 40 of the sleeps read +the whole burn before them (42 to 53 mJ). With it, every span read at least +95% of the work on the loaded M5 Max and 97% on the quiet M3 Ultra, and no +sleep more than 0.5% of the burn; under 40 busy loops on the M3 Ultra (220 +runs) every span read at least 84% (the rest is the two readers' own reads) +and no sleep more than 2%. A read costs about 80 µs on the quiet M3 Ultra, +about 200 to 330 µs at the median under the busy loops, and 81 to 154 µs at +the median on the loaded M5 Max (1 µs without the sleep). + The GPU rail is machine-wide and is never split by GPU time: energy is not proportional to it. On this host a GGUF decode drew ~1.9 W per GPU-second alone while another session's job drew ~17 W, so a time-share split charged the decode diff --git a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/lib.rs b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/lib.rs index c306fe7d3..e8e440062 100644 --- a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/lib.rs +++ b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/lib.rs @@ -35,7 +35,11 @@ //! for an unprivileged reader where IOReport's CPU rails are not. It covers this //! process's threads only, so it is not in [`meter::detect_meter`] (for work //! wherever it runs, a subprocess included); [`meter::detect_in_process_meter`] -//! prefers it, for work that runs on this process's own threads. +//! prefers it, for work that runs on this process's own threads. Each read it +//! takes of its own process waits until the reading thread is seen to have +//! left its core, since the kernel counts a thread's energy into its +//! process's only then; a read not so checked is no reading +//! ([`EnergyError::NotFolded`]). //! //! On Apple Silicon (macOS, the `ioreport` feature) it also reads this //! process's own GPU energy (`process_gpu::ProcessGpuCounter`, domain @@ -349,6 +353,20 @@ pub enum EnergyError { /// not see the work: that is not a reading, and never a zero. #[error("the counter did not advance across the work: not a reading")] NotAdvanced, + /// A process's read of its own CPU-energy count was not taken, because + /// the reading thread was not seen to leave its core before it. The + /// kernel adds a thread's energy to its process's count only when the + /// thread leaves a core, so a read from a thread still on one is short of + /// what that thread spent since it last left: up to a scheduling quantum, + /// which would be missing from a window that ends there and — spent + /// before it — inside a window that starts there. That is not a reading + /// of that end (`process`), and a window with such an end has no figure + /// from the counter. + #[error( + "the reading thread was not seen to leave its core before a read of its own process: the count could be \ + short of what the thread spent since it last did — not a reading" + )] + NotFolded, /// A counter's reading at a window's boundary was not current: the IOReport /// GPU rail held while the GPU was busy (it can hold for hundreds of /// milliseconds and then catch up in one step), so a window bounded by that diff --git a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/process.rs b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/process.rs index 698f82291..a4ff9ce33 100644 --- a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/process.rs +++ b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/process.rs @@ -37,6 +37,78 @@ //! and cached ([`process_cpu_liveness`]); about 0.3 s where it is live, about //! 1 s where it is not. A counter that is not live meters nothing. //! +//! **Every read of this process by itself is taken once the reading thread is +//! seen to have left its core.** The kernel adds a thread's CPU energy to its +//! process's count only when the thread leaves a core — a context switch, or +//! the end of its quantum, about 10 ms of its CPU — and a process reading +//! ITSELF does not make the reading thread leave: its CPU time is current at +//! the read, its energy is not. So a read from a thread that has been running +//! is short of what that thread spent since it last left a core: a window's +//! first read then puts up to a quantum of energy from BEFORE the window +//! inside it, and its last read leaves the window's tail out. Measured (M5 +//! Max, macOS 27.0.1, load average about 90, 40 windows a run over three +//! runs, against an independent reader that slept before each of its own +//! reads): of windows over 1 ms of the reading thread's CPU, opened just +//! after that thread had left a core, 25 to 31 read no advance at all or +//! under three quarters of the independent reader's window around them; and +//! of windows over a 2 ms sleep opened straight after 8 ms of that thread's +//! CPU, 25 to 31 read the tail of the CPU before them as the sleep's energy, +//! up to 18 mJ for a sleep. On an idle M3 Ultra (macOS 27.0.1), where nothing +//! but its own quantum takes a running thread off its core, all 40 of the +//! 1 ms windows read no advance, and all 40 of the sleeps read the whole 8 ms +//! before them, 42 to 53 mJ, in each of three runs. +//! +//! So before each such read the reading thread sleeps, and the read is taken +//! only once the thread is SEEN to have left its core over a sleep +//! ([`FOLD_SLEEPS`]: 50 µs, then 200 µs, 1 ms and 5 ms). A sleep alone is no +//! proof: one whose timer fires before the thread has blocked returns with +//! the thread still on its core. The proof is the reading thread's own energy +//! count (`proc_pidinfo`'s `PROC_PIDTHREADCOUNTS`, [`this_thread_energy_nj`]), +//! which the kernel moves only when it adds that thread's energy to the +//! process's: a rise across a sleep is the thread having left its core after +//! the work before the read. Not the process's context-switch count, which +//! any other thread's switch moves. A read whose thread was not seen to leave +//! within those sleeps is [`EnergyError::NotFolded`], no reading: a window +//! with one at either end has no figure from this counter, and its caller +//! estimates (a span, [`crate::span`], falls back to the host meter). Never a +//! short figure graded as a hardware reading. +//! +//! With the sleep, the same windows on the same hosts: all 40 of the 1 ms +//! windows read at least 95% of the independent reader's window on the M5 +//! Max (load average about 135, four runs) and at least 97% on the quiet M3 +//! Ultra, and all 40 of the sleeps under 0.5% of the window that held the +//! CPU before them, on both. Under 40 busy loops on the M3 Ultra (220 runs +//! of 40 windows of each kind), every 1 ms window read at least 84% — the +//! rest is the two readers' own reads and wake-ups, which do not shrink +//! with the work — and no sleep more than 2%. +//! +//! What a read costs: two reads of the thread's count (well under a +//! microsecond each), the sleep, and the wait for a core after it. Measured, +//! 200 reads a run: on the quiet M3 Ultra 79 to 88 µs at the median and +//! 109 µs at most, and under 40 busy loops there 193 to 335 µs at the median +//! over 110 runs and 11 ms at most; on the M5 Max at a load average of about +//! 135, 81 to 154 µs at the median, 0.3 to 2.7 ms at the 95th percentile, +//! and up to 13 ms (a read with no sleep: 1 µs). A read whose thread is +//! never seen to leave takes all four sleeps (6.25 ms) and their waits +//! before it fails. A window also +//! holds the energy of its own closing read's wake-up, a few tens of +//! microjoules (17 µJ for a window over a 200 ms sleep, on the M3 Ultra): +//! most of the figure for a window over much less than a millisecond of +//! work, which is then a reading of what this process spent between its two +//! reads and not of that work alone. So a caller with many short pieces of +//! work meters them in one window around the lot, not one each. The liveness +//! probe reads with no sleep: it asks only whether the count keeps advancing +//! under a burn, which it does at each quantum. +//! +//! Only the reading thread is seen to leave. Another thread of this process +//! that is on a core at a read is short by what it spent since it last left +//! one, so its share of a window can be off by up to a quantum at each end: +//! work that runs on the thread that opens and closes the window is read +//! whole, and work on other threads to within a quantum each, at each end. +//! And only reads of THIS process: a counter that reads another process (a +//! child, a process tree) cannot make that process's threads leave their +//! cores, and nothing here sleeps for one. +//! //! **A read that did not advance is not a reading.** No work runs on zero //! energy, so a window over which the counter held did not see the work. //! [`ProcessCpuCounter::measure`] reports such a window as @@ -95,12 +167,129 @@ fn rusage_energy_nj(pid: libc::pid_t) -> Option { Some(unsafe { info.assume_init() }.ri_energy_nj) } -/// This process's cumulative CPU energy, in nanojoules. -pub(crate) fn energy_nj() -> Option { +/// This process's cumulative CPU energy, in nanojoules, as the kernel's count +/// stands now: read with no sleep before it, so short of what the reading +/// thread spent since it last left a core. The liveness probe's reader, and +/// the last step of [`self_read_nj`]; no figure is made of it alone. +fn raw_energy_nj() -> Option { // SAFETY: `getpid` has no preconditions and cannot fail. rusage_energy_nj(unsafe { libc::getpid() }) } +/// The sleeps the reading thread takes, in turn, before a read of its own +/// process, until one is seen to take it off its core ([`left_its_core`]). +/// Growing: a sleep whose timer fired before the thread blocked is followed +/// by one that much more surely blocks. 6.25 ms in all, on a read whose +/// thread is never seen to leave. +const FOLD_SLEEPS: [Duration; 4] = + [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1), Duration::from_millis(5)]; + +/// Whether the reading thread was seen to leave its core: it takes each of +/// `sleeps` in turn, reading its own energy count (`count`: production reads +/// [`this_thread_energy_nj`]) either side, and stops at the first sleep +/// across which the count rose. The kernel moves that count only when it adds +/// the thread's energy to its process's, so a rise across a sleep is the +/// thread having left its core after everything it did before the sleep. A +/// count that cannot be read, that held across every sleep, or that fell, is +/// no such evidence: `false`, and no read is made of the process on it. +fn left_its_core(sleeps: &[Duration], mut count: impl FnMut() -> Option, mut sleep: impl FnMut(Duration)) -> bool { + for &d in sleeps { + let Some(before) = count() else { return false }; + sleep(d); + match count() { + Some(after) if after > before => return true, + Some(_) => {} + None => return false, + } + } + false +} + +/// `PROC_PIDTHREADCOUNTS`: the `proc_pidinfo` flavor that returns one thread's +/// counts, asked by its 64-bit thread id. In the kernel's +/// `` (macOS 13 and later), not in the SDK's public +/// header, so the result is used only in the one layout [`thread_energy_nj`] +/// knows. +const PROC_PIDTHREADCOUNTS: libc::c_int = 34; + +/// The calling thread's own cumulative CPU energy, in nanojoules, from the +/// bytes `proc_pidinfo(PROC_PIDTHREADCOUNTS)` wrote into `buf`, of which the +/// call returned `wrote`. The kernel writes `struct proc_threadcounts`: a +/// `uint16_t` count of CPU performance levels and six bytes of padding, then +/// for each level five `uint64_t`s — instructions, cycles, user time, system +/// time and energy in nJ. The energy is summed over the levels. +/// +/// `None` unless the call wrote exactly that header and one 40-byte record +/// for each level it names, at least one: any other size is a layout this +/// code does not know, and is read as no count rather than as a field +/// misread. Measured (M5 Max, macOS 27.0.1): 88 bytes, two levels. +fn thread_energy_nj(buf: &[u8], wrote: libc::c_int) -> Option { + const HEADER: usize = 8; + const LEVEL: usize = 40; + const ENERGY: usize = 32; + let levels = usize::from(u16::from_ne_bytes([*buf.first()?, *buf.get(1)?])); + let size = HEADER + levels * LEVEL; + if levels == 0 || size > buf.len() || usize::try_from(wrote).ok() != Some(size) { + return None; + } + let mut nj = 0u64; + for level in 0..levels { + let at = HEADER + level * LEVEL + ENERGY; + let energy: [u8; 8] = buf[at..at + 8].try_into().ok()?; + nj = nj.saturating_add(u64::from_ne_bytes(energy)); + } + Some(nj) +} + +/// The calling thread's own cumulative CPU energy, in nanojoules: the count +/// [`left_its_core`] watches. `None` if the thread's id or its counts cannot +/// be read, or the counts come back in a layout [`thread_energy_nj`] does not +/// know. +fn this_thread_energy_nj() -> Option { + let mut tid: u64 = 0; + // SAFETY: `tid` is writable, and `pthread_self` is the calling thread. + if unsafe { libc::pthread_threadid_np(libc::pthread_self(), &mut tid) } != 0 { + return None; + } + let mut buf = [0u8; 512]; + // SAFETY: `buf` is writable for its length, which the call is given; + // `getpid` has no preconditions. + let wrote = unsafe { + libc::proc_pidinfo(libc::getpid(), PROC_PIDTHREADCOUNTS, tid, buf.as_mut_ptr().cast(), buf.len() as libc::c_int) + }; + thread_energy_nj(&buf, wrote) +} + +/// One read of this process by itself, as every figure here takes it: its +/// cumulative CPU energy in nanojoules, read once the reading thread is seen +/// to have left its core ([`left_its_core`] over [`FOLD_SLEEPS`]), so the +/// count holds all that thread spent before the read. A thread not seen to +/// leave is [`EnergyError::NotFolded`], and the process is not read: there is +/// then no reading at this end of a window, and no figure for the window. +pub(crate) fn self_read_nj() -> Result { + self_read_with(this_thread_energy_nj, std::thread::sleep, raw_energy_nj) +} + +/// [`self_read_nj`] on its parts: the reading thread's own energy count, the +/// sleep, and the read of the process. The tests script all three. +fn self_read_with( + count: impl FnMut() -> Option, + sleep: impl FnMut(Duration), + read: impl FnOnce() -> Option, +) -> Result { + if !left_its_core(&FOLD_SLEEPS, count, sleep) { + return Err(EnergyError::NotFolded); + } + read().ok_or_else(|| EnergyError::Platform("proc_pid_rusage failed".to_string())) +} + +/// [`self_read_nj`], for a caller that keeps a window's two readings and +/// hands them to [`window_uj`] ([`crate::span`]): `None` where there is no +/// reading, whichever of its two reasons it has. +pub(crate) fn energy_nj() -> Option { + self_read_nj().ok() +} + /// How many times this process has run the real liveness probe. Read through /// [`crate::process_cpu_probe_runs`] by the test that pins the probe to one run /// per process. @@ -111,38 +300,82 @@ pub(crate) static REAL_RUNS: AtomicUsize = AtomicUsize::new(0); /// (it burns that thread's CPU for about 0.3 s where the counter is live, about /// 1 s where it is not); every later call, every [`ProcessCpuCounter::new`] and /// every [`crate::meter::detect_in_process_meter`] reuse the answer. +/// +/// [`CounterLiveness::Unavailable`], with no probe run, where the calling +/// thread's own energy count does not read ([`this_thread_energy_nj`]): every +/// read this counter takes of its own process is checked against that count +/// ([`self_read_nj`]), so a counter without it could never give a figure. pub fn process_cpu_liveness() -> CounterLiveness { static LIVENESS: OnceLock = OnceLock::new(); *LIVENESS.get_or_init(|| { REAL_RUNS.fetch_add(1, Ordering::SeqCst); - probe_reader(energy_nj) + liveness_given(this_thread_energy_nj().is_some(), || probe_reader(raw_energy_nj)) }) } +/// The counter's liveness on a host where the reading thread's own energy +/// count `reads` or does not: what `probe` finds where it does, and +/// `Unavailable`, the probe not run, where it does not. +fn liveness_given(thread_count_reads: bool, probe: impl FnOnce() -> CounterLiveness) -> CounterLiveness { + if thread_count_reads { + probe() + } else { + CounterLiveness::Unavailable + } +} + /// One run of the liveness probe over `read`, a reader of a cumulative counter: /// the shared probe ([`crate::liveness::probe`]) over one channel, burning /// [`PROBE_TICK`] of this thread's CPU time between samples. Production passes -/// [`energy_nj`]; the tests pass readers that hold or fail. +/// [`raw_energy_nj`] (the count as it stands, no sleep before a sample: the +/// rule asks whether it keeps advancing under the burn, which it does at each +/// quantum); the tests pass readers that hold or fail. fn probe_reader(read: impl Fn() -> Option) -> CounterLiveness { crate::liveness::probe(|| read().map(|_| (1, || read().map(|nj| vec![nj]))), PROBE_TICK) } -/// The energy of a window of work from the counter's raw readings, in nJ, -/// before and after it, as whole µJ: or why it is not a reading. A failed read -/// is not a zero; a counter that went backwards wrapped or was reset; and one -/// that did not advance by a whole µJ — the resolution of the figure — did not -/// see the work, which runs on more than zero energy. +/// The energy of a window of work from this process's readings of itself, in +/// nJ, before and after it ([`energy_nj`]), as whole µJ: or why it is not a +/// reading. An end with no reading (`None`) is not a zero, and leaves the +/// window with no figure; a counter that went backwards wrapped or was reset; +/// and one that did not advance by a whole µJ — the resolution of the figure — +/// did not see the work, which runs on more than zero energy. pub(crate) fn window_uj(before_nj: Option, after_nj: Option) -> Result { let (Some(before), Some(after)) = (before_nj, after_nj) else { - return Err(EnergyError::Platform("proc_pid_rusage failed".to_string())); + return Err(EnergyError::Platform( + "no reading of this process at an end of the window: the reading thread was not seen to leave its core, \ + or proc_pid_rusage failed" + .to_string(), + )); }; - match after.checked_sub(before).map(|nj| nj / 1_000) { + advance_uj(before, after) +} + +/// How far the counter advanced between two readings in nJ, as whole µJ, or +/// why that is no reading: it went backwards ([`EnergyError::CounterWrap`]), +/// or advanced by less than a whole µJ ([`EnergyError::NotAdvanced`]). +fn advance_uj(before_nj: u64, after_nj: u64) -> Result { + match after_nj.checked_sub(before_nj).map(|nj| nj / 1_000) { None => Err(EnergyError::CounterWrap), Some(0) => Err(EnergyError::NotAdvanced), Some(uj) => Ok(uj), } } +/// A window of `work` between two reads of the counter by `read`: the work's +/// result, and how far the counter advanced across it, or why there is no +/// figure — the first of the two reads that gave none, else what +/// [`advance_uj`] says. `work` runs whatever the first read gave; the second +/// is taken only when the first gave a reading. +fn window_over( + mut read: impl FnMut() -> Result, + work: impl FnOnce() -> T, +) -> (T, Result) { + let before = read(); + let out = work(); + (out, before.and_then(|before| read().and_then(|after| advance_uj(before, after)))) +} + /// This process's own CPU energy counter (macOS): see the module docs for its /// domain, which is exactly this process's threads' CPU energy. pub struct ProcessCpuCounter { @@ -182,22 +415,26 @@ impl ProcessCpuCounter { /// Run `work` and meter it: its result, and the CPU energy this process's /// threads spent while it ran, in µJ — a hardware reading over /// [`EnergyDomain::ProcessCpu`] — or why there is no figure: the counter is - /// not live ([`EnergyError::NoCounter`]), a read failed, the counter went + /// not live ([`EnergyError::NoCounter`]), the calling thread was not seen + /// to leave its core before one of the two reads + /// ([`EnergyError::NotFolded`]: that read could be short of what the + /// thread had spent, so there is none), a read failed, the counter went /// backwards ([`EnergyError::CounterWrap`]), or it did not advance by a /// whole µJ while the work ran ([`EnergyError::NotAdvanced`]: not a /// reading, never a zero). /// /// Every thread of this process is in the figure, the work's and any other /// running at the same time; no other process's, and none of the GPU's. - /// `work` runs whether or not the counter is live. + /// Work on the calling thread is read whole; another thread's, to within + /// what it spent since it last left a core at each read (the module + /// docs). Each of the two reads sleeps at least 50 µs first + /// ([`self_read_nj`]), outside the figure at the start and inside it at + /// the end. `work` runs whether or not the counter is live. pub fn measure(&self, work: impl FnOnce() -> T) -> (T, Result) { if !self.is_available() { return (work(), Err(EnergyError::NoCounter(EnergyDomain::ProcessCpu))); } - let before = energy_nj(); - let out = work(); - let after = energy_nj(); - (out, window_uj(before, after)) + window_over(self_read_nj, work) } } @@ -227,8 +464,10 @@ impl EnergyCounter for ProcessCpuCounter { } fn min_window_ns(&self) -> u64 { - // It moves about every 0.5 ms under load; below ~1 ms a window may - // straddle no update at all. + // A read holds all the reading thread spent before it, so a window + // of any length reads that thread's work whole. It also holds its + // closing read's own wake-up, a few tens of µJ: below ~1 ms of work + // that is a large part of the figure. 1_000_000 } @@ -236,7 +475,10 @@ impl EnergyCounter for ProcessCpuCounter { if !self.is_available() { return Err(EnergyError::NoCounter(EnergyDomain::ProcessCpu)); } - let nj = energy_nj().ok_or_else(|| EnergyError::Platform("proc_pid_rusage failed".to_string()))?; + // Taken once this thread is seen to have left its core, or not at all + // (`NotFolded`): a caller that subtracts two of these gets a window + // that holds this thread's work whole. + let nj = self_read_nj()?; let timestamp_ns = SystemTime::now() .duration_since(UNIX_EPOCH) .map(|d| d.as_nanos() as u64) @@ -319,6 +561,174 @@ mod tests { assert!(matches!(window_uj(Some(1), None), Err(EnergyError::Platform(_)))); } + /// The rule for seeing the reading thread leave its core: each sleep in + /// turn until the thread's own count rose across one. A count that held + /// across every sleep, fell, or could not be read is not a thread seen to + /// leave — and an unreadable count ends the wait at once. + #[test] + fn a_thread_is_seen_to_leave_only_by_its_own_count_rising_across_a_sleep() { + use std::cell::RefCell; + let sleeps = [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1)]; + // The thread's count at each read in turn, and the sleeps taken. + let seen = |counts: &[Option]| { + let mut counts = counts.iter().copied(); + let slept = RefCell::new(Vec::new()); + let left = left_its_core(&sleeps, || counts.next().flatten(), |d| slept.borrow_mut().push(d)); + (left, slept.into_inner()) + }; + assert_eq!(seen(&[Some(40), Some(41)]), (true, vec![sleeps[0]]), "rose across the first sleep"); + assert_eq!( + seen(&[Some(40), Some(40), Some(40), Some(40), Some(40), Some(90)]), + (true, sleeps.to_vec()), + "held across two sleeps that did not take it off its core, rose across the third" + ); + assert_eq!(seen(&[Some(40); 6]), (false, sleeps.to_vec()), "held across every sleep"); + assert_eq!(seen(&[Some(40), Some(39), Some(39), Some(39), Some(39), Some(39)]), (false, sleeps.to_vec()), "fell"); + assert_eq!(seen(&[None]), (false, vec![]), "unreadable before the first sleep: no sleep taken"); + assert_eq!(seen(&[Some(40), None]), (false, vec![sleeps[0]]), "unreadable after a sleep: no further sleep"); + assert!(!left_its_core(&[], || Some(1), |_| panic!("slept")), "no sleep, nothing seen"); + } + + /// A read of this process by itself is taken only once the reading thread + /// is seen to leave its core: where it is, the read is the process's + /// count; where its count never rises, the read is `NotFolded` after + /// every sleep, and the process is not read at all; where its count + /// cannot be read, `NotFolded` at once. A failed read of the process + /// after a thread seen to leave is the platform's failure, not a fold's. + #[test] + fn a_self_read_whose_thread_is_not_seen_to_leave_is_no_reading() { + use std::cell::{Cell, RefCell}; + let run = |counts: &[Option], process: Option| { + let mut counts = counts.iter().copied().cycle(); + let slept = RefCell::new(Vec::new()); + let read = Cell::new(false); + let r = self_read_with( + || counts.next().flatten(), + |d| slept.borrow_mut().push(d), + || { + read.set(true); + process + }, + ); + (r, slept.into_inner(), read.get()) + }; + let (r, slept, read) = run(&[Some(7), Some(9)], Some(123_456)); + assert!(matches!(r, Ok(123_456)) && slept == [FOLD_SLEEPS[0]] && read, "{r:?} {slept:?} {read}"); + let (r, slept, read) = run(&[Some(7)], Some(123_456)); + assert!(matches!(r, Err(EnergyError::NotFolded)), "a count that never rose gave {r:?}"); + assert_eq!((slept, read), (FOLD_SLEEPS.to_vec(), false), "every sleep, then no read of the process"); + let (r, slept, read) = run(&[None], Some(123_456)); + assert!(matches!(r, Err(EnergyError::NotFolded)) && slept.is_empty() && !read, "{r:?} {slept:?} {read}"); + let (r, _, read) = run(&[Some(7), Some(9)], None); + assert!(matches!(r, Err(EnergyError::Platform(_))) && read, "{r:?}"); + } + + /// A window is the counter's advance between two reads, and one with no + /// reading at either end has no figure: the reason of the first end + /// without one. The work runs either way, and after a start with no + /// reading the end is not read. + #[test] + fn a_window_with_an_end_not_read_has_no_figure() { + use std::cell::Cell; + let window = |reads: [Result; 2]| { + let (taken, ran) = (Cell::new(0), Cell::new(false)); + let mut reads = reads.into_iter(); + let (out, figure) = window_over( + || { + taken.set(taken.get() + 1); + reads.next().expect("a third read") + }, + || ran.set(true), + ); + assert!(ran.get(), "the work did not run"); + (out, figure, taken.get()) + }; + let ((), figure, taken) = window([Ok(5_000_000), Ok(7_500_999)]); + assert!(matches!(figure, Ok(2_500)) && taken == 2, "{figure:?} after {taken} reads"); + let ((), figure, taken) = window([Err(EnergyError::NotFolded), Ok(7_500_999)]); + assert!(matches!(figure, Err(EnergyError::NotFolded)) && taken == 1, "{figure:?} after {taken} reads"); + let ((), figure, taken) = window([Ok(5_000_000), Err(EnergyError::NotFolded)]); + assert!(matches!(figure, Err(EnergyError::NotFolded)) && taken == 2, "{figure:?} after {taken} reads"); + let ((), figure, _) = window([Ok(5_000_000), Ok(5_000_400)]); + assert!(matches!(figure, Err(EnergyError::NotAdvanced)), "{figure:?}"); + let ((), figure, _) = window([Ok(5_000_000), Ok(4_000_000)]); + assert!(matches!(figure, Err(EnergyError::CounterWrap)), "{figure:?}"); + } + + /// One `proc_threadcounts` as the kernel writes it: a count of `levels` + /// performance levels in its first two bytes, six bytes of padding, and + /// for each level five u64s, the fifth its energy. + fn threadcounts(levels: u16, energy_nj: &[u64]) -> Vec { + let mut buf = vec![0u8; 512]; + buf[..2].copy_from_slice(&levels.to_ne_bytes()); + for (l, nj) in energy_nj.iter().enumerate() { + let record = 8 + l * 40; + for (field, word) in [11u64, 22, 33, 44, *nj].iter().enumerate() { + buf[record + field * 8..record + field * 8 + 8].copy_from_slice(&word.to_ne_bytes()); + } + } + buf + } + + /// The thread's count is read only in the one layout known: a header and + /// one 40-byte record per level it names. Its energy is the fifth u64 of + /// each record, summed. A call that failed, wrote any other size, or + /// names no level or more levels than the buffer holds, is no count. + #[test] + fn the_threads_count_is_read_only_in_the_layout_known() { + // The dev host's shape: two levels, 88 bytes. + assert_eq!(thread_energy_nj(&threadcounts(2, &[1_000, 250]), 88), Some(1_250)); + assert_eq!(thread_energy_nj(&threadcounts(1, &[77]), 48), Some(77)); + assert_eq!(thread_energy_nj(&threadcounts(3, &[1, 2, 4]), 128), Some(7)); + assert_eq!(thread_energy_nj(&threadcounts(2, &[u64::MAX, 9]), 88), Some(u64::MAX), "the sum saturates"); + for (wrote, why) in [(-1, "the call failed"), (0, "nothing written"), (80, "a shorter record"), (96, "a longer one")] { + assert_eq!(thread_energy_nj(&threadcounts(2, &[1_000, 250]), wrote), None, "{why}"); + } + assert_eq!(thread_energy_nj(&threadcounts(0, &[]), 8), None, "no performance level"); + assert_eq!(thread_energy_nj(&threadcounts(13, &[]), 528), None, "more levels than the buffer holds"); + assert_eq!(thread_energy_nj(&[2], 88), None, "a buffer with no header"); + } + + /// A host on which the reading thread's own count does not read has no + /// process counter: `Unavailable`, and the liveness probe is not run. + #[test] + fn a_host_without_the_threads_count_has_no_process_counter() { + assert_eq!(liveness_given(false, || panic!("probed a counter no read could be checked on")), CounterLiveness::Unavailable); + for verdict in [CounterLiveness::Live, CounterLiveness::Frozen, CounterLiveness::Unavailable] { + assert_eq!(liveness_given(true, || verdict), verdict); + } + } + + /// On this host the calling thread's own count reads, in the layout + /// known and with one record per performance level the host reports + /// (`hw.nperflevels`); and a read of this process by itself sees the + /// thread leave its core — the path every figure takes. + #[test] + fn on_this_host_the_reading_thread_is_seen_to_leave_its_core() { + let nj = this_thread_energy_nj().expect("this thread's own energy count"); + let mut tid = 0u64; + let mut buf = [0u8; 512]; + // SAFETY: as in `this_thread_energy_nj`. + let wrote = unsafe { + libc::pthread_threadid_np(libc::pthread_self(), &mut tid); + libc::proc_pidinfo(libc::getpid(), PROC_PIDTHREADCOUNTS, tid, buf.as_mut_ptr().cast(), buf.len() as libc::c_int) + }; + let levels = u16::from_ne_bytes([buf[0], buf[1]]); + let mut host_levels: libc::c_int = 0; + let mut size = std::mem::size_of::(); + // SAFETY: `host_levels` is writable for `size` bytes. + let rc = unsafe { + libc::sysctlbyname(c"hw.nperflevels".as_ptr(), (&mut host_levels as *mut libc::c_int).cast(), &mut size, std::ptr::null_mut(), 0) + }; + eprintln!("process-cpu: this thread's counts: {wrote} bytes, {levels} levels (hw.nperflevels {host_levels}, rc {rc}), {nj} nJ"); + assert_eq!(wrote, 8 + 40 * libc::c_int::from(levels)); + if rc == 0 { + assert_eq!(libc::c_int::from(levels), host_levels); + } + let read = self_read_nj(); + assert!(read.is_ok(), "this thread was not seen to leave its core within {FOLD_SLEEPS:?}: {read:?}"); + } + /// On this host: the counter is live, and 100 ms of this thread's CPU time /// meters as at least 0.05 J (a core at 0.5 W). The process-wide figure /// includes any concurrent test's threads, so the bound here is one-sided; diff --git a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/span.rs b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/span.rs index 968b3c634..5b709853f 100644 --- a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/span.rs +++ b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/src/span.rs @@ -33,6 +33,10 @@ //! fallback's window is the work's own (and the CPU reads), never the //! snapshots' waits — a time-based estimate over those would bill a span of a //! few microseconds of work for up to two seconds of the meter's waiting. +//! Each CPU read sleeps before it reads (`process`: at least 50 µs, until the +//! reading thread is seen to have left its core), so the fallback's window +//! holds those two sleeps as well as the work: about a sixth of a +//! millisecond on an idle host, more on a loaded one. use std::time::Instant; diff --git a/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/tests/process_cpu_short_span.rs b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/tests/process_cpu_short_span.rs new file mode 100644 index 000000000..588622fc8 --- /dev/null +++ b/jouleclaw/jouleclaw-rs/crates/jouleclaw-energy/tests/process_cpu_short_span.rs @@ -0,0 +1,228 @@ +//! Short spans on this process's own CPU-energy counter, against an oracle +//! that takes the reading thread off its core by a rule of its own. +//! +//! The kernel adds a thread's CPU energy to its process's count only when the +//! thread leaves its core, so a process that reads ITSELF from a thread that +//! has been running does not see that thread's latest energy. A span of a +//! millisecond of work then reads nothing at all, or what the thread spent +//! before the span. This file asks the counter for exactly such spans and +//! holds each figure against the test's own window around it. +//! +//! The counter reads every thread of this process, so the file is one test +//! binary with one test, which runs its checks in sequence on one thread. No +//! joule figure, joules per CPU-second or timing floor is asserted: what a +//! millisecond of CPU costs depends on the core class that ran it, and on a +//! loaded host the wall time of everything here stretches. + +#![cfg(target_os = "macos")] + +use std::time::{Duration, Instant}; + +use jouleclaw_energy::process::ProcessCpuCounter; +use jouleclaw_energy::{CounterLiveness, EnergyCounter}; + +/// This thread's CPU time. +fn thread_cpu() -> Duration { + let mut ts = libc::timespec { tv_sec: 0, tv_nsec: 0 }; + // SAFETY: `ts` is a valid, writable timespec for the duration of the call. + let rc = unsafe { libc::clock_gettime(libc::CLOCK_THREAD_CPUTIME_ID, &mut ts) }; + assert_eq!(rc, 0, "the thread CPU clock"); + Duration::new(ts.tv_sec as u64, ts.tv_nsec as u32) +} + +/// Burn `cpu` of this thread's own CPU time (not wall time, so a loaded host +/// that deschedules the thread still gets the whole burn). +fn burn(cpu: Duration) { + let start = thread_cpu(); + let mut x = 1u64; + while thread_cpu() - start < cpu { + for _ in 0..1_000 { + x = std::hint::black_box(x.wrapping_mul(6_364_136_223_846_793_005).wrapping_add(1)); + } + } +} + +/// The oracle's read of this process's cumulative CPU energy, in nJ, +/// independent of the crate: `proc_pid_rusage(getpid(), RUSAGE_INFO_V6)` into +/// a 464-byte buffer, whose `ri_energy_nj` is the u64 at byte offset 336. +fn oracle_energy_nj() -> u64 { + let mut buf = [0u64; 58]; + // SAFETY: `buf` is 464 writable bytes, the size of `rusage_info_v6`; + // `getpid` has no preconditions. + let rc = unsafe { libc::proc_pid_rusage(libc::getpid(), 6, buf.as_mut_ptr() as *mut libc::rusage_info_t) }; + assert_eq!(rc, 0, "the oracle's proc_pid_rusage"); + buf[336 / 8] +} + +/// How many times this process's threads have been switched off a core +/// (`proc_pidinfo(PROC_PIDTASKINFO)`'s `pti_csw`). Only this test's thread +/// runs here, so a rise across a sleep is this thread leaving its core. +fn oracle_switches() -> i64 { + // SAFETY: an all-zero `proc_taskinfo` is a valid value of a struct of + // plain integers. + let mut info: libc::proc_taskinfo = unsafe { std::mem::zeroed() }; + let size = std::mem::size_of::() as libc::c_int; + // SAFETY: `info` is writable for `size` bytes, which the call is given. + let n = unsafe { + libc::proc_pidinfo(libc::getpid(), libc::PROC_PIDTASKINFO, 0, (&mut info as *mut libc::proc_taskinfo).cast(), size) + }; + assert_eq!(n, size, "the oracle's proc_pidinfo(PROC_PIDTASKINFO)"); + i64::from(info.pti_csw) +} + +/// The oracle's own way of taking this thread off its core, so that its +/// energy so far is in the process's count: sleep 1 ms, then 2, 4 and 8, +/// until the process's context-switch count rose across one. Not the +/// counter's rule (which watches this thread's own energy count across far +/// shorter sleeps): the two share no call and no number. +fn oracle_fold() { + for ms in [1, 2, 4, 8] { + let before = oracle_switches(); + std::thread::sleep(Duration::from_millis(ms)); + if oracle_switches() > before { + return; + } + } + panic!("the oracle never saw this thread leave its core across sleeps of 1, 2, 4 and 8 ms"); +} + +/// What one short span came to. +#[derive(Default)] +struct Tally { + /// A figure the check accepts as the span's. + agreed: usize, + /// Each accepted figure as a share of the oracle's window, in parts per + /// thousand: reported, so the margin the check leaves can be seen. + shares: Vec, + /// No figure: the counter said the span was not a reading. + no_figure: usize, + /// A figure that is not the span's — too little of the work, or, for a + /// sleep, the burn before it: the tries, with the figure (µJ) and the + /// oracle's window (nJ). + wrong: Vec<(usize, u64, u64)>, + /// A figure above the oracle's window: more than this process spent + /// around the span, which no read of this process's count can be. + over: Vec<(usize, u64, u64)>, +} + +impl Tally { + fn accept(&mut self, uj: u64, oracle_nj: u64) { + self.agreed += 1; + self.shares.push(uj * 1_000 * 1_000 / oracle_nj.max(1)); + } +} + +#[test] +fn a_short_span_reads_what_an_oracle_that_folds_on_its_own_reads() { + const TRIES: usize = 40; + let counter = ProcessCpuCounter::new(); + assert_eq!(counter.liveness(), CounterLiveness::Live, "this process's CPU-energy counter is not live here"); + + // 1. A millisecond of this thread's CPU, metered. The oracle's window + // opens before the counter's and closes after it, each end read once + // this thread has left its core, so it holds the whole burn and the + // counter's own reads. A figure is the span's when it is no more than + // that window and at least two thirds of it. The rest is the oracle's + // and the counter's own reads and wake-ups, which do not shrink with + // the burn's cost: at most 5% of the window on an M5 Max at a load + // average of 135, under 3% on a quiet M3 Ultra, and up to 16% on that + // M3 Ultra under 40 busy loops (the lowest of 8,800 spans). A counter + // that reads itself without first taking the reading thread off its + // core reads no advance across such a span, or part of the burn. + let mut burned = Tally::default(); + for i in 0..TRIES { + oracle_fold(); + let before = oracle_energy_nj(); + let ((), figure) = counter.measure(|| burn(Duration::from_millis(1))); + oracle_fold(); + let oracle_nj = oracle_energy_nj() - before; + match figure { + Ok(uj) if uj * 1_000 > oracle_nj => burned.over.push((i, uj, oracle_nj)), + Ok(uj) if uj * 1_000 * 3 >= oracle_nj * 2 => burned.accept(uj, oracle_nj), + Ok(uj) => burned.wrong.push((i, uj, oracle_nj)), + Err(_) => burned.no_figure += 1, + } + } + println!( + "short span: 1 ms burn x {TRIES}: {} agreed with the oracle (at least {}/1000 of its window), {} gave no \ + figure, {} gave a figure short of the span's {:?}, {} one over the oracle's window {:?} (try, µJ, oracle nJ)", + burned.agreed, + burned.shares.iter().min().copied().unwrap_or(0), + burned.no_figure, + burned.wrong.len(), + burned.wrong, + burned.over.len(), + burned.over + ); + + // 2. A 2 ms sleep, metered straight after 8 ms of this thread's CPU that + // the span does not cover. The sleep itself costs this process next to + // nothing; the burn before it is still on the thread, not yet in the + // process's count, when the span opens. A counter whose opening read + // does not take the thread off its core first reads that burn's tail + // as the sleep's energy. The oracle's window is the burn and the + // sleep; a figure for the sleep is under a quarter of it (it was at + // most 2% of it over 8,800 spans under 40 busy loops), or (a sleep + // over which nothing of this process ran) not a figure at all. + let mut slept = Tally::default(); + for i in 0..TRIES { + oracle_fold(); + let before = oracle_energy_nj(); + burn(Duration::from_millis(8)); + let ((), figure) = counter.measure(|| std::thread::sleep(Duration::from_millis(2))); + oracle_fold(); + let oracle_nj = oracle_energy_nj() - before; + match figure { + Ok(uj) if uj * 1_000 * 4 < oracle_nj => slept.accept(uj, oracle_nj), + Ok(uj) => slept.wrong.push((i, uj, oracle_nj)), + Err(_) => slept.no_figure += 1, + } + } + println!( + "short span: 2 ms sleep after an 8 ms burn x {TRIES}: {} under a quarter of the oracle's window (at most \ + {}/1000 of it), {} gave no figure, {} read the burn before the span {:?} (try, µJ, oracle nJ)", + slept.agreed, + slept.shares.iter().max().copied().unwrap_or(0), + slept.no_figure, + slept.wrong.len(), + slept.wrong + ); + + // 3. What a read costs: the wall time of each of 200 reads of the + // counter, back to back. Reported, never asserted — on a loaded host + // the wait for a core after the read's sleep is most of it. + let mut micros: Vec = (0..200) + .map(|_| { + let t = Instant::now(); + let _ = counter.read(); + t.elapsed().as_micros() + }) + .collect(); + micros.sort_unstable(); + println!( + "short span: one read of the counter costs {} µs at the median, {} µs at the 95th percentile, {} µs at most \ + (200 reads)", + micros[100], micros[190], micros[199] + ); + + assert!(burned.over.is_empty(), "a span read more than this process spent around it: {:?}", burned.over); + // A tenth of the spans may miss the band. On a loaded host the oracle's + // own reads can land on a costlier core than the burn did, which shrinks + // a correct figure's share of the oracle's window; and a read whose + // thread was not seen to leave its core is no reading by design. A + // counter that does not take the reading thread off its core misses on + // most spans: 25 to 31 of 40 on a loaded host, all 40 on an idle one. + assert!( + (burned.no_figure + burned.wrong.len()) * 10 <= TRIES, + "{} of {TRIES} 1 ms spans were given no figure and {} a figure short of the span's: {:?}", + burned.no_figure, + burned.wrong.len(), + burned.wrong + ); + assert!( + slept.wrong.len() * 10 <= TRIES, + "{} of {TRIES} sleeps were given the energy of the burn before them: {:?}", + slept.wrong.len(), + slept.wrong + ); +} -- 2.54.0 (Apple Git-157) From 1108d507f9f8031da07e7db824d109432fa64859 Mon Sep 17 00:00:00 2001 From: Transaction Science Date: Mon, 12 Oct 2026 15:46:01 -0400 Subject: [PATCH 2/5] jcp-energy: the per-process rung reads its own count only once the metering thread has left its core MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit SPEC §5.1 rung 3 already says it: the kernel adds a thread's energy to its process's count (proc_pid_rusage ri_energy_nj) only when the thread leaves a core, a process's read of its own count does not take the reading thread off its core, and an implementation that relies on the thread having left MUST check that it did. The reference meter did not. Each end of a span was read from a thread still on its core, so a span held up to a scheduling quantum of what the thread spent before it and lacked its own tail, and was graded HwShunt. Measured on an idle M3 Ultra (macOS 27.0.1) against the tests' own reader, which sleeps before each read until the process's context-switch count rose; 40 spans of each kind a run, six runs: - 1 ms of the metering thread's CPU: all 40 showed no rise and were the default-power estimate, every run; - a 2 ms sleep straight after 8 ms of CPU: 39 or 40 were graded HwShunt on the burn before them, about 41 mJ for a sleep. Now ProcessEnergy::read, the read at each end of a Meter span and of a FabricMeter span, sleeps (50 us, then 200 us, 1 ms, 5 ms) until the metering thread's own energy count (proc_pidinfo PROC_PIDTHREADCOUNTS, decoded only in the one layout known: 88 bytes, two performance levels here) rose across a sleep, and only then reads the process. An end whose thread was not seen to leave is not read: the Meter span is the default-power estimate (process_span's existing path, Estimator, no measured figure) and the FabricMeter span reports no CPU figure. The rung opens only where the thread's count reads. The liveness probe still samples with no sleep. The layout decoding and the rule are pure and compiled on every platform. With it, on that host, idle and under 40 busy loops (110 runs): every span of both kinds was read, the work at 84% or more of the tests' own window and the sleep at 6% or less of the window that held the burn. A read costs about 80 us idle and 169 us at the median under the busy loops, against under 1 us. Co-Authored-By: Claude Opus 5.5 --- jcp/README.md | 2 +- jcp/jcp-rs/crates/jcp-energy/src/lib.rs | 570 +++++++++++++++++++++++- 2 files changed, 548 insertions(+), 24 deletions(-) diff --git a/jcp/README.md b/jcp/README.md index 97561d76d..0ac850d4d 100644 --- a/jcp/README.md +++ b/jcp/README.md @@ -45,7 +45,7 @@ jcp/ - **`jcp-trace`** — ingests an agent run's **OpenTelemetry GenAI trace** (`gen_ai.*` semantic conventions: `chat` / `tool` / `retriever` spans with token usage) and its **evaluation assessments** (judge / human / code feedback), attaches **per-span joules** (measured where a meter is present, else `Estimator` from token counts — provenance never silently upgrades), and seals one **`eval/1` JCR-1 receipt**: the per-span token + joule breakdown with the headline `uj_per_accepted_token` at the **weakest** provenance present, the assessments, a deterministic **quality-gate** verdict (the sealed, declarative analog of a CI assert), and a **readiness projection** an ARL validation-axis claim consumes. The observability stacks *record* a trace and *log* a judge score in a table; this is the interop projection that **seals** the same trace, puts a joule on it, and hash-chains it via `EvalLog` — no new cryptography. The **gate is content-addressed**, so the sealed receipt commits to exactly which bar it was judged against (a tamper-evident artifact, not a mutable in-code `assert`), and **`align_threshold` / `Judge`** calibrate a judge's decision threshold to human pass/fail labels — judge alignment as a reproducible number, not a UI click. Behind the `server` feature, a std-only **OTLP `/v1/traces` receiver** lets any OpenTelemetry exporter POST a `gen_ai.*` trace (with its assessments) and get the sealed `eval/1` receipt back the instant the run ends. - **`jcp-intercept`** — **attested interceptor chains**: a composable, ordered pipeline of transforms *around* each model and tool call — the `before_model` / `after_model` / `before_tool` seams an agent's middleware stack runs, composed onion-order (forward in, reverse out) and stopping at the first refusal or human-approval hold. An interceptor may inspect or **rewrite** the request (redact a secret before it reaches the model, trim stale context), **refuse** it, or **hold** it for a human. The difference from the incumbent's arbitrary in-process hooks: every step seals an **`intercept/1`** JCR-1 receipt carrying the request digest **before and after** the step (so a redaction or a trim is provable — the content itself never sealed, only its hash), the seam, the outcome, and the **metered joules** at their honest provenance, hash-chained — the exact transform pipeline that produced a model request becomes reconstructable and verifiable by anyone, and a step cannot run un-sealed. Three reference interceptors — `Redact` (a content transform), `CallLimit` (a guardrail), `Approve` (a human-in-the-loop hold) — each reuse a primitive the family already holds rather than reinventing it. - **`jcp-efficiency`** — the **energy-efficiency spec**, surfaced as a sealed receipt. The dark-factory economics turn on four figures — **joules per accepted token, tokens per second, value per token, and the tokens/joules/dollars spent per COMPLETED, VERIFIED unit of work** — and the incumbents publish, at best, a *rate* (cost per token) that can't tell you whether the spend bought a result. An **`efficiency/1`** JCR-1 receipt records all four at honest provenance, hash-chained, with the one thing the rates omit: the **outcome anchor** (`completed` + a verdict). A measurement that didn't complete is spend that bought nothing, and the receipt says so. `aggregate` then splits value-delivered from total spend across a chain — charging *every* attempt (including the failed ones) against the results actually delivered — so `tokens_per_completed_unit` / `uj_per_completed_unit` / `value_per_joule` become the honest efficiency a "cost per token" number is designed to hide. Integers and strings only (JCR-1 forbids bools/floats); the rate figures recompute from the sealed inputs on read. -- **`jcp-energy`** — the metering ladder (SPEC §5.1): RAPL package counters (Linux powercap, wraparound-corrected, `HwShunt`, only while every package counter is live — `rapl_status()`), NVML GPU energy behind the `nvml` feature (`HwShunt` and `Partial`, since it does not read the CPU's share; only while live — `nvml_status()`), the macOS kernel's per-process CPU energy count (`proc_pid_rusage`'s `ri_energy_nj`; `HwShunt`, whole for in-process CPU work, only while live — `process_energy_status()`; it covers this process's threads, not children, the GPU or DRAM, so a span that reaps a child process or ends with one is `Partial`; it is live on macOS 27.0.1 where IOReport's CPU rails are not), Apple Silicon IOReport (`HwShunt`, only while every CPU energy rail, each die's on a multi-die part, is live — on macOS 27.0.1 that rail is republished in lumps, so there the rung is declined and `ioreport_status()` says why; `Meter::detect_explained()` names the rung selected and why each one above it was declined), a time×power model at a power the host calibrated (`ModelBased`, `Meter::time_power`), and estimates no host calibrated (`Estimator`): time × the documented default power — the rung `Meter::detect()` falls to, always available — and a constant per-op figure. A vendor counter's reading is real but vendor-opaque and relayed by the platform, and it counts as a reading only while the counter is live (SPEC §5). Measured when the platform exposes it, estimated when it doesn't — and the provenance always says which; a hardware backend that fails mid-reading degrades honestly to the default-power estimate. +- **`jcp-energy`** — the metering ladder (SPEC §5.1): RAPL package counters (Linux powercap, wraparound-corrected, `HwShunt`, only while every package counter is live — `rapl_status()`), NVML GPU energy behind the `nvml` feature (`HwShunt` and `Partial`, since it does not read the CPU's share; only while live — `nvml_status()`), the macOS kernel's per-process CPU energy count (`proc_pid_rusage`'s `ri_energy_nj`; `HwShunt`, whole for in-process CPU work, only while live — `process_energy_status()`; it covers this process's threads, not children, the GPU or DRAM, so a span that reaps a child process or ends with one is `Partial`; each end of a span is read only once the metering thread is seen to have left its core, because the kernel counts a thread's energy into its process's only then, and a span with an end not so checked is the estimate, never a reading; it is live on macOS 27.0.1 where IOReport's CPU rails are not), Apple Silicon IOReport (`HwShunt`, only while every CPU energy rail, each die's on a multi-die part, is live — on macOS 27.0.1 that rail is republished in lumps, so there the rung is declined and `ioreport_status()` says why; `Meter::detect_explained()` names the rung selected and why each one above it was declined), a time×power model at a power the host calibrated (`ModelBased`, `Meter::time_power`), and estimates no host calibrated (`Estimator`): time × the documented default power — the rung `Meter::detect()` falls to, always available — and a constant per-op figure. A vendor counter's reading is real but vendor-opaque and relayed by the platform, and it counts as a reading only while the counter is live (SPEC §5). Measured when the platform exposes it, estimated when it doesn't — and the provenance always says which; a hardware backend that fails mid-reading degrades honestly to the default-power estimate. - **`jcp-gateway`** — the **energy-native MCP gateway**: a JCP enforcement point that sits in front of an MCP server so an existing client/server pair keeps its transport while every `tools/call` becomes capability-scoped, joule-budgeted, and sealed. The novel mechanic is two-phase metered enforcement: the call is *authorized* before it runs (no debit, because the cost isn't yet known), the upstream call is **metered** by the sibling Sandbox standard's energy probe (Apple Silicon IOReport, RAPL, NVML — vendor energy counters, whose readings are real but vendor-opaque and relayed by the platform, and which count as readings only while the counter is live for the work, SPEC §5; otherwise the figure is an estimate and is graded as one), and the metered joules are debited from the grant — so the budget that stops a runaway agent is denominated in joules, not a token estimate. Where the upstream server is a local process whose CPU energy the host's kernel counts live (macOS `proc_pid_rusage`), each call is read on that server's own process tree, the work's own process rather than the machine (SPEC §5.1, rung 3): sealed `HwShunt`, and `Whole` only when nothing was seen missing from the tree (no descendant reaped or exited in the span, no GPU client held, no in-process Neural Engine memory, every member read and quiet at both ends) and the operator has declared, with `--upstream-self-contained`, that the server hands no work to a process outside its tree; otherwise `Partial`, with the response's `_meta` naming why. Every decision, allow and deny, seals into a **hash-chained receipt log**: excise, reorder, or splice a receipt and the chain breaks at that point. A denied call never reaches the server (the live 2025–26 MCP exploits land on tool *output*, which the gateway frames as untrusted `data` that can never exercise a capability), and the `jcp-gateway` binary runs it over stdio in front of any MCP-server subprocess. This is the chokepoint the AI-gateway field occupies, on the two axes nobody there holds: the unit of account is the joule, and the audit is cryptographic and tamper-evident rather than a dollar figure and a span. - **`jcp-wire`** — the `jcp/1` wire binding (SPEC §11): 4-byte length prefix + canonical det-CBOR over any byte stream, with TCP and Unix-socket endpoints and a client. The decoder rejects non-canonical bodies, so a message has exactly one wire form. Requests carry the full delegation chain and are **caller-signed** — the endpoint authenticates from the request itself and denies an impersonation `bad-signature`, sealed like any other decision. Responses carry the deterministic decision and the sealed receipt. - **`jcp-threshold`** — threshold actors (SPEC §2.2): a `did:key` whose private key is split k-of-n with FROST (RFC 9591); the group key is an ordinary Ed25519 key, so a 2-of-3 team issues, holds, and signs wire requests with nothing else in JCP changing. Shares come from a trusted dealer or **distributed key generation** — with DKG the group's private key never exists anywhere, not even momentarily. The two-agent rule for irreversible actions, refused by arithmetic rather than policy. diff --git a/jcp/jcp-rs/crates/jcp-energy/src/lib.rs b/jcp/jcp-rs/crates/jcp-energy/src/lib.rs index 374f5c9c2..06a6c1872 100644 --- a/jcp/jcp-rs/crates/jcp-energy/src/lib.rs +++ b/jcp/jcp-rs/crates/jcp-energy/src/lib.rs @@ -46,6 +46,19 @@ //! for an unprivileged reader on macOS 27.0.1, where IOReport's CPU rails //! are not. A span over which it did not advance is the default-power //! estimate. +//! +//! The kernel adds a thread's energy to the count only when the thread +//! leaves a core, and a process's read of its own count does not take the +//! reading thread off its core. So each end of a span is read only once +//! the metering thread is SEEN to have left its core: it sleeps (50 µs, +//! then 200 µs, 1 ms, 5 ms) until its own energy count +//! (`proc_pidinfo`, `PROC_PIDTHREADCOUNTS`) rose across a sleep, which it +//! does only when the kernel adds that thread's energy to the process's. +//! An end whose thread was not seen to leave is not read, and the span is +//! the default-power estimate — never a figure that is short of the +//! span's tail, or holds what the thread spent before the span, graded as +//! a reading (SPEC §5.1 rung 3). The rung is selected only where that +//! count reads. //! 4. **IOReport** (Apple Silicon) — the on-die SoC Energy Model counters via //! Apple's IOReport C API (no sudo, no external binary), `Provenance::HwShunt`. //! Like RAPL and NVML it is a vendor energy counter: the count is a real @@ -1105,6 +1118,118 @@ mod rusage_v6 { } } +/// The byte layout of `struct proc_threadcounts`, which macOS's +/// `proc_pidinfo(pid, PROC_PIDTHREADCOUNTS, thread_id, &counts, size)` fills: +/// one thread's counts, by its 64-bit thread id. The flavor and the struct +/// are in the kernel's `` (macOS 13 and later) and +/// not in the SDK's public header, so nothing here trusts the layout further +/// than the call's own return value confirms it: a `uint16_t` count of CPU +/// performance levels and six bytes of padding, then for each level five +/// `uint64_t` — instructions, cycles, user time, system time, and the +/// thread's CPU energy in nanojoules. On an M5 Max, macOS 27.0.1: two levels, +/// 88 bytes. +/// +/// The decoding is pure and compiled everywhere, so its tests run on any host, +/// on a fixed byte layout. +#[cfg_attr(not(target_os = "macos"), allow(dead_code))] +mod thread_counts { + /// `PROC_PIDTHREADCOUNTS`. + pub(crate) const FLAVOR: i32 = 34; + /// The bytes before the first level's record. + pub(crate) const HEADER: usize = 8; + /// The bytes of one level's record: five `uint64_t`. + pub(crate) const LEVEL: usize = 40; + /// Where a level's record keeps its energy: its fifth `uint64_t`. + pub(crate) const ENERGY_NJ: usize = 32; + /// The most performance levels a read leaves room for. + pub(crate) const MAX_LEVELS: usize = 12; + /// The buffer a read hands the kernel. + pub(crate) const SIZE: usize = HEADER + MAX_LEVELS * LEVEL; + + /// The thread's CPU energy in nJ, summed over the performance levels, + /// from the `wrote` bytes the call says it wrote into `counts`. + /// + /// `None` unless that is exactly the header and one record for each + /// level the header names, at least one and no more than the buffer + /// holds. A failed call (`wrote` ≤ 0) and any other size — a layout this + /// crate does not know — are no count, never a field read from the wrong + /// place. + pub(crate) fn energy_nj(counts: &[u8; SIZE], wrote: i32) -> Option { + let levels = usize::from(u16::from_ne_bytes([counts[0], counts[1]])); + if !(1..=MAX_LEVELS).contains(&levels) || usize::try_from(wrote).ok() != Some(HEADER + levels * LEVEL) { + return None; + } + let energy = (0..levels).map(|level| { + let at = HEADER + level * LEVEL + ENERGY_NJ; + let mut word = [0u8; 8]; + word.copy_from_slice(&counts[at..at + 8]); + u64::from_ne_bytes(word) + }); + Some(energy.fold(0, u64::saturating_add)) + } +} + +/// When a process may read its own energy count: once the reading thread has +/// been SEEN to leave its core. +/// +/// The kernel adds a thread's CPU energy to its process's count only when +/// the thread leaves a core (a context switch, or the end of its quantum, +/// about 10 ms of its CPU), and a process's read of its own count does not +/// take the reading thread off its core: its CPU time is current at the +/// read, its energy is not. A span read that way holds, at its start, up to +/// a quantum of what the thread spent BEFORE the span, and lacks, at its +/// end, what the thread spent since it last left a core. Measured on an +/// idle M3 Ultra, macOS 27.0.1, against the tests' own reader that sleeps +/// before each of its reads, 40 spans of each kind a run over six runs: of +/// the spans over 1 ms of the metering thread's CPU, all 40 showed no rise +/// and were the default-power estimate, every run; of the spans over a 2 ms +/// sleep taken straight after 8 ms of that thread's CPU, 39 or 40 were +/// graded `HwShunt` on the burn before them, about 41 mJ for a sleep. (On a +/// loaded host other work takes the thread off its core more often, and the +/// same spans read a part of the work, or of the burn, instead.) With the +/// check below, on that host, idle and under 40 busy loops (110 runs): every +/// span of both kinds was read, the work at 84% or more of the tests' own +/// window around it and the sleep at 6% or less of the window that held the +/// burn. +/// +/// A sleep takes the thread off its core — but not always: when the sleep's +/// timer fires before the thread has blocked, it goes on without leaving. +/// So the thread sleeps and CHECKS: its own energy count +/// (`thread_counts`) is moved by the kernel only when it adds the thread's +/// energy to the process's, so a rise across a sleep is the thread having +/// left its core after all it did before the sleep. The process's +/// context-switch count is no such check: any other thread's switch moves +/// it. The sleeps grow ([`SLEEPS`]), so one that did not block is followed +/// by one that much more surely does. +/// +/// The rule is pure and compiled everywhere, so its tests run on any host. +#[cfg_attr(not(target_os = "macos"), allow(dead_code))] +mod off_core { + use std::time::Duration; + + /// The sleeps the reading thread takes, in turn, until one is seen to + /// take it off its core: 6.25 ms in all on a read that never is. + pub(crate) const SLEEPS: [Duration; 4] = + [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1), Duration::from_millis(5)]; + + /// Whether the reading thread was seen to leave its core: its own energy + /// count (`count`) rose across one of `sleeps`, taken in turn through + /// `sleep`. A count that cannot be read ends the wait at once; one that + /// held across every sleep, or fell, is no evidence. `false` either way, + /// and the caller does not read the process's count. + pub(crate) fn seen(sleeps: &[Duration], mut count: impl FnMut() -> Option, mut sleep: impl FnMut(Duration)) -> bool { + for &pause in sleeps { + let Some(before) = count() else { return false }; + sleep(pause); + let Some(after) = count() else { return false }; + if after > before { + return true; + } + } + false + } +} + /// The kernel's count of this process's own CPU energy, read through /// `proc_pid_rusage(getpid(), RUSAGE_INFO_V6, ...)` from libproc: public API, /// no entitlement, no privilege. `ri_energy_nj` is the cumulative CPU energy @@ -1134,6 +1259,27 @@ mod rusage_v6 { /// Measured on an M5 Max, macOS 27.0.1: 0.002 J/s idle, 2.4 J/s with one /// thread burning, 5.3 J/s with two, changing about every 0.5 ms while /// polled. +/// +/// A span's two reads of the count are each taken only once the metering +/// thread is seen to have left its core (`off_core`), so the count holds +/// all that thread spent before the read; a read not so checked is no read +/// ([`ProcessEnergy::read`]). That covers the thread that reads. Another +/// thread of the process that is on a core at a read is short by what it +/// spent since it last left one, so its share of a span can be off by up to +/// a quantum at each end: work on the thread that opens and closes the span +/// is read whole, and the figure holds what the other threads spent as the +/// kernel had counted it. Each read costs the sleep and the wait for a core +/// after it: on an idle M3 Ultra 79 to 81 µs at the median, 113 µs at most; +/// under 40 busy loops there, 169 µs at the median over 110 runs, 0.6 ms at +/// the median of the worst run, and up to 27 ms for one read (200 reads a +/// run; under 1 µs with no sleep). A read that fails costs all four sleeps +/// (6.25 ms) and their waits. A span also holds its closing read's own +/// wake-up, a few tens of microjoules (59 µJ for a span over a 200 ms sleep, +/// on the M3 Ultra): most of the figure for a span over much less than a +/// millisecond of work, which is then a reading of what the process spent +/// between its two reads, over that work and not under it. The liveness +/// probe samples the count with no sleep: it asks only whether the count +/// keeps advancing under a burn, which it does at every quantum. #[cfg(target_os = "macos")] #[allow(unsafe_code)] mod process_energy { @@ -1141,10 +1287,14 @@ mod process_energy { use crate::liveness; use crate::rusage_v6::{self, ProcessEnergyReading}; + use crate::{off_core, thread_counts}; unsafe extern "C" { fn proc_pid_rusage(pid: c_int, flavor: c_int, buffer: *mut c_void) -> c_int; fn proc_listchildpids(ppid: c_int, buffer: *mut c_void, buffersize: c_int) -> c_int; + fn proc_pidinfo(pid: c_int, flavor: c_int, arg: u64, buffer: *mut c_void, buffersize: c_int) -> c_int; + fn pthread_self() -> *mut c_void; + fn pthread_threadid_np(thread: *mut c_void, thread_id: *mut u64) -> c_int; fn getpid() -> c_int; } @@ -1168,38 +1318,93 @@ mod process_energy { #[repr(C, align(8))] struct Info([u8; rusage_v6::SIZE]); - /// This process's energy counts, now. `None` if the call fails (a kernel - /// without the V6 flavor). + /// This process's energy counts as the kernel holds them now, read with + /// no sleep before the call: short of what the calling thread spent + /// since it last left a core. `None` if the call fails (a kernel without + /// the V6 flavor). No span is made of this read alone: a span's ends are + /// [`read_off_core`]. pub(crate) fn read() -> Option { let mut info = Info([0; rusage_v6::SIZE]); let rc = unsafe { proc_pid_rusage(getpid(), rusage_v6::FLAVOR, info.0.as_mut_ptr().cast()) }; (rc == 0).then(|| rusage_v6::decode(&info.0)) } - /// The per-process CPU energy counter of this process. Holds nothing: each - /// read asks the kernel about the calling process. + /// A `proc_threadcounts`-sized buffer, aligned as the struct is. + #[repr(C, align(8))] + struct Counts([u8; thread_counts::SIZE]); + + /// The calling thread's own CPU energy count, in nJ: what `off_core` + /// watches. `None` if the thread's id or its counts cannot be read, or + /// the counts come back in a layout `thread_counts` does not know. + pub(crate) fn thread_energy_nj() -> Option { + let mut thread = 0u64; + if unsafe { pthread_threadid_np(pthread_self(), &mut thread) } != 0 { + return None; + } + let mut counts = Counts([0; thread_counts::SIZE]); + let bytes = c_int::try_from(thread_counts::SIZE).ok()?; + let wrote = unsafe { proc_pidinfo(getpid(), thread_counts::FLAVOR, thread, counts.0.as_mut_ptr().cast(), bytes) }; + thread_counts::energy_nj(&counts.0, wrote) + } + + /// One end of a span: this process's energy counts, read once the + /// calling thread is seen to have left its core (`off_core::seen` on + /// `thread_count`, sleeping `off_core::SLEEPS`), so they hold all that + /// thread spent before the read. `None` if the thread was not seen to + /// leave — the process's count is then not read at all — or the read + /// itself fails. + fn read_off_core(thread_count: fn() -> Option) -> Option { + off_core::seen(&off_core::SLEEPS, thread_count, std::thread::sleep).then(read).flatten() + } + + /// The per-process CPU energy counter of this process. Each read asks + /// the kernel about the calling process and the calling thread. #[derive(Debug)] pub struct ProcessEnergy { - _opened: (), + /// The reading thread's own energy count, which each read of a span + /// is checked against: [`thread_energy_nj`], but for a test of a + /// thread that is never seen to leave its core. + thread_count: fn() -> Option, } impl ProcessEnergy { - /// `Some` when the kernel answers for this process. Opening is not - /// selection: [`crate::Meter::detect`] selects the rung only while + /// `Some` when the kernel answers for this process, and for the + /// calling thread's own count: every read of a span is checked + /// against that count, and a counter whose reads could never be + /// checked would only ever estimate. Opening is not selection: + /// [`crate::Meter::detect`] selects the rung only while /// [`crate::process_energy_status`] is Live. pub(crate) fn open() -> Option { - read().map(|_| ProcessEnergy { _opened: () }) + read()?; + thread_energy_nj()?; + Some(ProcessEnergy { thread_count: thread_energy_nj }) } - /// `ri_energy_nj` now, in nJ. + /// A counter whose reading thread is never seen to leave its core: + /// its own count reads, and never moves. + #[cfg(test)] + pub(crate) fn never_off_core() -> Self { + ProcessEnergy { thread_count: || Some(7) } + } + + /// `ri_energy_nj` now, in nJ, with no sleep before the read: the + /// liveness probe's sample. pub(crate) fn read_nj(&self) -> Option { read().map(|r| r.energy_nj) } /// What a span reads at each end: the energy count and the reaped - /// children's CPU time, from one call. + /// children's CPU time, from one call, taken once the calling thread + /// is seen to have left its core. `None` where it was not: that end + /// has no reading, and the span is the default-power estimate + /// (`process_span`). pub(crate) fn read(&self) -> Option { - read() + read_off_core(self.thread_count) + } + + /// [`Self::read`]'s energy count alone, in nJ. + pub(crate) fn read_energy_nj(&self) -> Option { + self.read().map(|r| r.energy_nj) } /// One liveness sample: `ri_energy_nj` as the counter's one rail. @@ -5214,7 +5419,10 @@ pub enum Meter { /// handed to the GPU is not detected. [`Meter::detect`] selects it only /// while the counter is live /// ([`process_energy_status`]), and a span over which it did not advance is - /// the default-power estimate (`process_span`). + /// the default-power estimate (`process_span`). So is a span either of + /// whose two reads the metering thread was not seen to leave its core + /// before: the kernel counts a thread's energy into its process's only + /// when the thread leaves a core, so each read sleeps first and checks. #[cfg(target_os = "macos")] ProcessEnergy(process_energy::ProcessEnergy), /// Apple Silicon IOReport Energy Model energy → `Provenance::HwShunt`, the @@ -5479,6 +5687,10 @@ impl Meter { } #[cfg(target_os = "macos")] Meter::ProcessEnergy(p) => { + // Each read sleeps first, and is taken only once this thread + // is seen to have left its core. The sleeps are outside the + // work's wall time, which the estimate for a span with no + // reading scales by. let before = p.read(); let started = Instant::now(); let out = work(); @@ -5486,7 +5698,9 @@ impl Meter { // The children first, then the count: a child reaped between // the two is then listed, or in the reaped children's time. let children = process_energy::child_count(); - (out, process_span(before, p.read(), children, elapsed.as_nanos())) + // No reading at the start is no span: the end is not read. + let after = before.and_then(|_| p.read()); + (out, process_span(before, after, children, elapsed.as_nanos())) } #[cfg(target_os = "macos")] Meter::IoReport(io) => { @@ -5625,6 +5839,10 @@ pub struct FabricEnergy { pub struct FabricMeter { #[cfg(target_os = "macos")] ioreport: Option, + /// This process's CPU energy count, where the kernel answers for it and + /// for the reading thread's own count its reads are checked against. + #[cfg(target_os = "macos")] + process: Option, } impl FabricMeter { @@ -5632,7 +5850,7 @@ impl FabricMeter { pub fn detect() -> Self { #[cfg(target_os = "macos")] { - FabricMeter { ioreport: ioreport::IoReport::open() } + FabricMeter { ioreport: ioreport::IoReport::open(), process: process_energy::ProcessEnergy::open() } } #[cfg(not(target_os = "macos"))] { @@ -5645,7 +5863,7 @@ impl FabricMeter { let mut out = Vec::new(); #[cfg(target_os = "macos")] { - if process_energy::read().is_some() { + if self.process.is_some() { out.push((Fabric::Cpu, Attribution::Process)); } if self.ioreport.is_some() { @@ -5666,10 +5884,16 @@ impl FabricMeter { /// only for a counter that is live: the Neural Engine is reported only /// once [`npu_rail_liveness`] has proved its rail live, because on macOS /// 27.0.1 an unprivileged reader's `ANE0` holds through real ANE work. + /// + /// The CPU figure is this process's own count, read at each end only + /// once the calling thread is seen to have left its core (the kernel + /// counts a thread's energy into its process's only then). A span with + /// an end not so read has no CPU figure: it is omitted, not reported + /// short or with what the thread spent before the span. pub fn measure(&self, work: impl FnOnce() -> T) -> (T, Vec) { - let started = std::time::Instant::now(); #[cfg(target_os = "macos")] - let cpu_before = process_energy::read().map(|r| r.energy_nj); + let cpu_before = self.process.as_ref().and_then(|p| p.read_energy_nj()); + let started = std::time::Instant::now(); #[cfg(target_os = "macos")] let io_before = self.ioreport.as_ref().and_then(|m| m.read()); @@ -5679,7 +5903,8 @@ impl FabricMeter { let mut readings = Vec::new(); #[cfg(target_os = "macos")] { - if let (Some(b), Some(a)) = (cpu_before, process_energy::read().map(|r| r.energy_nj)) { + let cpu_after = cpu_before.and_then(|_| self.process.as_ref()?.read_energy_nj()); + if let (Some(b), Some(a)) = (cpu_before, cpu_after) { readings.push(FabricEnergy { fabric: Fabric::Cpu, uj: a.saturating_sub(b) / 1_000, @@ -6276,11 +6501,13 @@ fn nvml_span(before_uj: Option, after_uj: Option, elapsed_ns: u128) -> /// /// A reading, `HwShunt`, only when `ri_energy_nj` advanced across the span: /// then it is the rise, in µJ rounded **up**, so a span that spent energy never -/// reads as zero and the work is never under-debited by the rounding. The -/// count changes about every 0.5 ms on a busy thread, so a shorter span can see -/// no rise though the work ran; that span, a count that fell, and a failed read -/// are the time×power figure at the default power, `Estimator`, as IOReport's -/// held spans are ([`ioreport_span`]). Never `HwShunt` on a figure no counter +/// reads as zero and the work is never under-debited by the rounding. Each +/// read is taken once the metering thread is seen to have left its core, so +/// the count holds what that thread spent up to the read; an end where it was +/// not seen to leave has no read (`None`). That span, a span over which the +/// count did not rise, a count that fell, and a failed read are the +/// time×power figure at the default power, `Estimator`, as IOReport's held +/// spans are ([`ioreport_span`]). Never `HwShunt` on a figure no counter /// read. /// /// The reading covers the whole span only when no child process can have @@ -7951,6 +8178,303 @@ mod tests { }); } + /// One `proc_threadcounts` as the kernel writes it into a read's buffer: + /// `levels` in its first two bytes, six bytes of padding, then for each + /// of `energy_nj` a record of five `uint64_t` whose fifth is that level's + /// energy and whose first four are other counts. + fn thread_counts_bytes(levels: u16, energy_nj: &[u64]) -> [u8; thread_counts::SIZE] { + let mut counts = [0u8; thread_counts::SIZE]; + counts[..2].copy_from_slice(&levels.to_ne_bytes()); + for (level, nj) in energy_nj.iter().enumerate() { + let record = thread_counts::HEADER + level * thread_counts::LEVEL; + for (field, word) in [1_111u64, 2_222, 3_333, 4_444, *nj].into_iter().enumerate() { + counts[record + field * 8..record + field * 8 + 8].copy_from_slice(&word.to_ne_bytes()); + } + } + counts + } + + /// The layout constants are the kernel header's: flavor 34, an 8-byte + /// header, 40 bytes a level, the energy 32 bytes into a level. The + /// decoding reads each level's energy and nothing else, and reads no + /// count at all from a result of any size but the header and one record + /// for each level it names: a failed call, a short or long result, no + /// level, more levels than the buffer holds. + #[test] + fn thread_counts_decoding_reads_each_levels_energy_in_the_one_layout_it_knows() { + assert_eq!( + (thread_counts::FLAVOR, thread_counts::HEADER, thread_counts::LEVEL, thread_counts::ENERGY_NJ), + (34, 8, 40, 32) + ); + // Two levels, 88 bytes: what an M5 Max and an M3 Ultra write. + assert_eq!(thread_counts::energy_nj(&thread_counts_bytes(2, &[3_000_000, 250]), 88), Some(3_000_250)); + assert_eq!(thread_counts::energy_nj(&thread_counts_bytes(1, &[77]), 48), Some(77)); + assert_eq!(thread_counts::energy_nj(&thread_counts_bytes(3, &[1, 2, 4]), 128), Some(7)); + assert_eq!(thread_counts::energy_nj(&thread_counts_bytes(2, &[u64::MAX, 5]), 88), Some(u64::MAX), "saturates"); + let two = thread_counts_bytes(2, &[3_000_000, 250]); + for (wrote, why) in [(-1, "the call failed"), (0, "nothing written"), (48, "one record for two levels"), (80, "short"), (96, "long")] + { + assert_eq!(thread_counts::energy_nj(&two, wrote), None, "{why}"); + } + assert_eq!(thread_counts::energy_nj(&thread_counts_bytes(0, &[]), 8), None, "no performance level"); + let too_many = u16::try_from(thread_counts::MAX_LEVELS + 1).unwrap(); + assert_eq!( + thread_counts::energy_nj(&thread_counts_bytes(too_many, &[]), 8 + 40 * i32::from(too_many)), + None, + "more levels than the buffer holds" + ); + } + + /// The rule for reading one's own process: the reading thread is seen + /// off its core only when its own energy count rose across a sleep. The + /// sleeps are taken in turn until one does; a count that held across + /// them all, or fell, is not a thread seen to leave, and a count that + /// cannot be read ends the wait at once. + #[test] + fn a_thread_is_seen_off_its_core_only_by_its_own_count_rising_across_a_sleep() { + use std::cell::RefCell; + let sleeps = [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1)]; + // The thread's count at each read in turn; the sleeps taken. + let seen = |counts: &[Option]| { + let mut counts = counts.iter().copied(); + let slept = RefCell::new(Vec::new()); + let seen = off_core::seen(&sleeps, || counts.next().flatten(), |pause| slept.borrow_mut().push(pause)); + (seen, slept.into_inner()) + }; + assert_eq!(seen(&[Some(10), Some(11)]), (true, vec![sleeps[0]]), "rose across the first sleep"); + assert_eq!( + seen(&[Some(10), Some(10), Some(10), Some(10), Some(10), Some(4_000)]), + (true, sleeps.to_vec()), + "held across two sleeps, rose across the third" + ); + assert_eq!(seen(&[Some(10); 6]), (false, sleeps.to_vec()), "held across every sleep"); + assert_eq!(seen(&[Some(10), Some(9), Some(9), Some(8), Some(8), Some(7)]), (false, sleeps.to_vec()), "fell"); + assert_eq!(seen(&[None]), (false, vec![]), "unreadable before any sleep"); + assert_eq!(seen(&[Some(10), None]), (false, vec![sleeps[0]]), "unreadable after a sleep"); + assert!(!off_core::seen(&[], || Some(1), |_| panic!("slept")), "no sleep, nothing seen"); + assert_eq!( + off_core::SLEEPS, + [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1), Duration::from_millis(5)] + ); + } + + /// On this host the metering thread's own count reads, in the layout + /// `thread_counts` knows: between two reads of the tests' own per-thread + /// oracle (their own FFI declaration and decoding), the meter's read of + /// it sits between theirs. And a span's read sees the thread leave its + /// core: the path every figure of the rung takes. + /// + /// A thread that has not left a core since it started has a count of + /// zero (seen on an idle M3 Ultra), which would make the comparison one + /// of zeros. So the thread first burns and sleeps until the oracle's + /// count is above zero. + #[cfg(target_os = "macos")] + #[test] + fn the_metering_threads_own_count_reads_here_and_a_span_read_sees_it_leave_its_core() { + for ms in [1, 2, 4, 8] { + burn_thread_cpu(Duration::from_millis(1)); + std::thread::sleep(Duration::from_millis(ms)); + if oracle_this_thread_energy_nj() > 0 { + break; + } + } + let before = oracle_this_thread_energy_nj(); + let mine = process_energy::thread_energy_nj().expect("the meter cannot read this thread's own count"); + let after = oracle_this_thread_energy_nj(); + eprintln!("process energy: this thread's own count: oracle {before} <= meter {mine} <= oracle {after} nJ"); + assert!(before > 0, "this thread's own count is still zero after four burns and sleeps"); + assert!(before <= mine && mine <= after, "the meter's count {mine} nJ is not this thread's ({before} .. {after})"); + let counter = process_energy::ProcessEnergy::open().expect("the per-process counter does not open"); + assert!(counter.read().is_some(), "this thread was not seen to leave its core within {:?}", off_core::SLEEPS); + } + + /// A span whose metering thread is never seen to leave its core is not a + /// reading: the rung's figure for it is the default-power estimate, + /// `Estimator`, with no measured figure — never a zero, and never a + /// figure graded `HwShunt` on a count that may lack what the thread + /// spent. The work still runs, once, and the read gives up only after + /// every sleep. The per-fabric meter reports no CPU figure for such a + /// span, while it still lists the CPU as a fabric it reads. + #[cfg(target_os = "macos")] + #[test] + fn a_span_whose_thread_is_never_seen_off_its_core_is_an_estimate() { + let meter = Meter::ProcessEnergy(process_energy::ProcessEnergy::never_off_core()); + let mut runs = 0; + let started = std::time::Instant::now(); + let ((), e) = meter.measure(|| runs += 1); + let took = started.elapsed(); + assert_eq!(runs, 1, "the work ran {runs} times"); + assert_eq!((e.provenance, e.measured_uj), (Provenance::Estimator, None), "{e:?}"); + e.check_provenance().unwrap(); + let every_sleep: Duration = off_core::SLEEPS.iter().sum(); + assert!(took >= every_sleep, "the read gave up after {took:?}, before all of {:?}", off_core::SLEEPS); + + let fabrics = FabricMeter { ioreport: None, process: Some(process_energy::ProcessEnergy::never_off_core()) }; + assert_eq!(fabrics.readable(), vec![(Fabric::Cpu, Attribution::Process)]); + let ((), readings) = fabrics.measure(|| ()); + assert!(readings.is_empty(), "a CPU figure for a span no end of which was read: {readings:?}"); + } + + /// `proc_pidinfo` flavor 4, `PROC_PIDTASKINFO` in ``: a + /// process's task counts, 96 bytes — six `uint64_t` (sizes and CPU + /// times), then twelve `int32_t`, the ninth of them `pti_csw`, how many + /// times the process's threads have been switched off a core. + #[cfg(target_os = "macos")] + const TESTS_PIDTASKINFO: std::os::raw::c_int = 4; + + /// The tests' own count of this process's context switches (`pti_csw`, + /// the `int32_t` at byte 80 of `proc_taskinfo`), through their own FFI + /// declaration. + #[cfg(target_os = "macos")] + #[allow(unsafe_code)] + fn oracle_context_switches() -> i32 { + let mut info = [0i32; 24]; + let bytes = std::mem::size_of_val(&info) as std::os::raw::c_int; + let me = std::process::id() as std::os::raw::c_int; + let wrote = unsafe { proc_pidinfo(me, TESTS_PIDTASKINFO, 0, info.as_mut_ptr().cast(), bytes) }; + assert_eq!(wrote, bytes, "the tests' proc_pidinfo(PROC_PIDTASKINFO) wrote {wrote} of {bytes} bytes"); + info[80 / 4] + } + + /// The tests' own read of this process's `ri_energy_nj`, taken once the + /// calling thread has left its core by the tests' own rule: a sleep of + /// 1 ms, then 2, 4 and 8, until the process's context-switch count rose + /// across one. In a fresh process running one test on one thread, a rise + /// is this thread's switch. The kernel adds a thread's energy to its + /// process's count when the thread leaves a core, so this read holds all + /// the thread spent before it. The meter's own check shares nothing with + /// it: another call, another count, sleeps a twentieth as long. + #[cfg(target_os = "macos")] + fn oracle_energy_nj_off_core() -> u64 { + let left = [1, 2, 4, 8].into_iter().any(|ms| { + let before = oracle_context_switches(); + std::thread::sleep(Duration::from_millis(ms)); + oracle_context_switches() > before + }); + assert!(left, "the tests' oracle never saw this thread leave its core across sleeps of 1, 2, 4 and 8 ms"); + oracle_energy_nj(std::process::id()).expect("the oracle cannot read this process").0 + } + + /// A span of a millisecond of the metering thread's CPU is that work's + /// reading, and a sleep metered straight after a burn is not given the + /// burn. Each `HwShunt` figure is held against the tests' own window + /// around its span, whose two ends are read once this thread has left + /// its core by the tests' own rule. + /// + /// - 1 ms of this thread's CPU, 40 times: a `HwShunt` figure is no more + /// than the oracle's window (which holds the span and both readers' + /// own reads and wake-ups) and at least two thirds of it. Those reads + /// do not shrink with the burn's cost: under 2% of the window on an + /// idle M3 Ultra, up to 16% under 40 busy loops (the lowest of 4,400 + /// spans). A span the meter could not read is the default-power + /// estimate, which claims no reading. At most a tenth of the spans + /// may be that or fall short of the band; none may be over the + /// oracle's window. + /// - a 2 ms sleep straight after 8 ms of this thread's CPU that the span + /// does not cover, 40 times: the oracle's window is the burn and the + /// sleep, and a `HwShunt` figure for the sleep is under a quarter of + /// it (it was under 1% idle, and at most 6% under the busy loops), in + /// at least nine spans of ten. + /// + /// No joule figure and no timing is asserted: what a millisecond of CPU + /// costs follows the core that ran it. A meter that reads its own + /// process's count from a thread still on its core fails both: the count + /// lacks what that thread spent since it last left one, so the first + /// kind of span reads nothing or part of the burn, and the second reads + /// the burn before it as the sleep's energy. + #[cfg(target_os = "macos")] + #[test] + fn a_short_span_is_its_own_reading_by_an_oracle_that_leaves_its_core_its_own_way() { + in_a_fresh_process("tests::a_short_span_is_its_own_reading_by_an_oracle_that_leaves_its_core_its_own_way", || { + const TRIES: usize = 40; + let meter = process_meter(); + + // (try, the figure in µJ, the oracle's window in nJ) of each + // HwShunt figure that is short of its span's, and of each that is + // over the oracle's window, which no read of this process's + // count can be. + let (mut agreed, mut estimated, mut wrong, mut over) = (Vec::new(), 0usize, Vec::new(), Vec::new()); + for i in 0..TRIES { + let before = oracle_energy_nj_off_core(); + let (_, e) = meter.measure(|| burn_thread_cpu(Duration::from_millis(1))); + let oracle_nj = oracle_energy_nj_off_core() - before; + let nj = e.uj().saturating_mul(1_000); + match e.provenance { + // The meter rounds a rise up to the next whole µJ. + Provenance::HwShunt if nj >= oracle_nj + 1_000 => over.push((i, e.uj(), oracle_nj)), + Provenance::HwShunt if nj * 3 >= oracle_nj * 2 => agreed.push(nj * 1_000 / oracle_nj.max(1)), + Provenance::HwShunt => wrong.push((i, e.uj(), oracle_nj)), + Provenance::ModelBased | Provenance::Estimator => estimated += 1, + } + } + eprintln!( + "process energy: 1 ms of this thread's CPU x {TRIES}: {} HwShunt within the oracle's window (at least \ + {}/1000 of it), {estimated} estimated, {} HwShunt and short of the span's {wrong:?}, {} HwShunt and \ + over the oracle's window {over:?} (try, µJ, oracle nJ)", + agreed.len(), + agreed.iter().min().copied().unwrap_or(0), + wrong.len(), + over.len() + ); + + let (mut small, mut slept_estimated, mut leaked) = (Vec::new(), 0usize, Vec::new()); + for i in 0..TRIES { + let before = oracle_energy_nj_off_core(); + burn_thread_cpu(Duration::from_millis(8)); + let ((), e) = meter.measure(|| std::thread::sleep(Duration::from_millis(2))); + let oracle_nj = oracle_energy_nj_off_core() - before; + let nj = e.uj().saturating_mul(1_000); + match e.provenance { + Provenance::HwShunt if nj * 4 < oracle_nj => small.push(nj * 1_000 / oracle_nj.max(1)), + Provenance::HwShunt => leaked.push((i, e.uj(), oracle_nj)), + Provenance::ModelBased | Provenance::Estimator => slept_estimated += 1, + } + } + eprintln!( + "process energy: a 2 ms sleep after an 8 ms burn x {TRIES}: {} HwShunt under a quarter of the oracle's \ + window (at most {}/1000 of it), {slept_estimated} estimated, {} HwShunt with the burn before the span \ + in them {leaked:?} (try, µJ, oracle nJ)", + small.len(), + small.iter().max().copied().unwrap_or(0), + leaked.len() + ); + + // What a read of the count costs: reported, not asserted. + let counter = process_energy::ProcessEnergy::open().expect("the per-process counter does not open"); + let mut micros: Vec = (0..200) + .map(|_| { + let started = std::time::Instant::now(); + let _ = counter.read(); + started.elapsed().as_micros() + }) + .collect(); + micros.sort_unstable(); + eprintln!( + "process energy: one read of the count for a span costs {} µs at the median, {} µs at the 95th \ + percentile, {} µs at most (200 reads)", + micros[100], micros[190], micros[199] + ); + + assert!(over.is_empty(), "a span was graded HwShunt on more than the process spent around it: {over:?}"); + // A tenth of the spans may miss the band. On a loaded host the + // oracle's own reads can land on a costlier core than the burn + // did, which shrinks a correct figure's share of the oracle's + // window; and a span the meter could not read is an estimate by + // design. A meter that does not take the metering thread off + // its core misses on every span of an idle host. + assert!( + (estimated + wrong.len()) * 10 <= TRIES, + "{estimated} of {TRIES} 1 ms spans were not read and {} were graded HwShunt short of the work: {wrong:?}", + wrong.len() + ); + assert!( + leaked.len() * 10 <= TRIES, + "{} of {TRIES} sleeps were graded HwShunt on the energy of the burn before them: {leaked:?}", + leaked.len() + ); + }); + } + /// Two threads burning 200 ms of CPU each meter more than one: every /// thread of the process is in the count. Each thread's 200 ms are of its /// own CPU clock (see [`burn_thread_cpu`]). Both burn in one span, and the -- 2.54.0 (Apple Git-157) From 0f6a9a3bb3b570a18901afba1f3dd0bc5eb50491 Mon Sep 17 00:00:00 2001 From: Transaction Science Date: Mon, 12 Oct 2026 20:15:01 -0400 Subject: [PATCH 3/5] eoc-meter: the process counter reads its own count only once the reading thread has left its core The kernel adds a thread's CPU energy to its process's count (proc_pid_rusage ri_energy_nj) only when the thread leaves a core, and a process's read of its own count does not take the reading thread off its core. MacosProcessEnergyCounter read the count as it stood, so a span bracketed by two reads held up to a scheduling quantum of what the thread spent before the span and lacked the span's own tail, and every consumer here tags a positive delta of the counter Measured. Measured on an M3 Ultra (macOS 27.0.1, load average about 14) against the tests' own reader, which sleeps before each read until the process's context-switch count rose; three runs of 40 spans of each kind: - 1 ms of the reading thread's CPU between two reads: 39, 40 and 40 spans read nothing or under two thirds of the work; - a 2 ms sleep between two reads, straight after 8 ms of CPU: 40, 40 and 37 spans read the burn before them, about 41 mJ for a sleep. read_microjoules now sleeps (50 us, then 200 us, 1 ms, 5 ms) until the reading thread's own energy count (proc_pidinfo PROC_PIDTHREADCOUNTS, read only in the one layout known: 88 bytes, two performance levels here) rose across a sleep, and only then reads the process. A read whose thread was not seen to leave is an error, not a short count: eoc-cascade, eoc-agent and eoc-local all take a failed read as no span and keep their estimate. process_energy_status is Unavailable, with no probe run, where the thread's count does not read, and the liveness probe still samples with no sleep. The rule and the layout decoding are pure and compiled on every platform. With it, on that host, quiet and under 40 busy loops (110 runs): every 1 ms span read 79% or more of the tests' window around it (98% when quiet) and no sleep read more than 3% of the window that held the burn. A read costs 83 us at the median on the quiet host and 226 us under the busy loops, against under 1 us; detect_in_process's docs say so, and that a batch of short operations is bracketed by one span, not one each. tests/process_energy_short_span.rs is the test that fails without it. Co-Authored-By: Claude Opus 5.5 --- eoc/eoc-rs/crates/eoc-meter/src/lib.rs | 337 +++++++++++++++++- .../tests/process_energy_short_span.rs | 199 +++++++++++ 2 files changed, 528 insertions(+), 8 deletions(-) create mode 100644 eoc/eoc-rs/crates/eoc-meter/tests/process_energy_short_span.rs diff --git a/eoc/eoc-rs/crates/eoc-meter/src/lib.rs b/eoc/eoc-rs/crates/eoc-meter/src/lib.rs index b5005189e..e1e2a3d9b 100644 --- a/eoc/eoc-rs/crates/eoc-meter/src/lib.rs +++ b/eoc/eoc-rs/crates/eoc-meter/src/lib.rs @@ -48,7 +48,12 @@ //! process's own threads' CPU energy, from `proc_pid_rusage`, live for an //! unprivileged reader. **Never selected by [`detect`]** — it does not see //! a child process's work, or the GPU's — only by [`detect_in_process`], -//! for callers whose metered work runs on the CPU in this process. +//! for callers whose metered work runs on the CPU in this process. The +//! kernel adds a thread's energy to the process's count only when the +//! thread leaves a core, so **each read is taken only once the reading +//! thread is seen to have left its core** (it sleeps at least 50 µs +//! first, and checks); a read whose thread was not seen to leave fails, +//! and its span is no reading: the caller keeps its estimate. //! - macOS `powermetrics`: detected when the binary is on the PATH, but the //! reference wrapper does not parse it, so every read returns //! `Err(NoCounter)`: no figure, and callers keep their own estimate. @@ -70,7 +75,9 @@ // IOReport module (`macos_ioreport`) — the on-die energy counters are // unreachable without the `unsafe extern "C"` IOReport calls — `clocks`, whose // one call is `clock_gettime` for the probing thread's CPU clock, and -// `macos_process_energy`, whose calls are `getpid` and `proc_pid_rusage`. +// `macos_process_energy`, whose calls are `getpid`, `proc_pid_rusage`, and, +// for the reading thread's own energy count, `pthread_self`, +// `pthread_threadid_np` and `proc_pidinfo`. // Everything else stays unsafe-free. #![deny(unsafe_code)] @@ -4480,6 +4487,172 @@ mod macos_powermetrics { #[cfg(target_os = "macos")] pub use macos_powermetrics::MacosPowermetricsCounter; +// When a process may read its own energy count, kept apart from the FFI so +// the rule and the one byte layout it depends on run under test on every +// platform, with scripted counts and scripted sleeps. +// +// The kernel adds a thread's CPU energy to its process's count +// (`ri_energy_nj`) only when the thread leaves a core: a context switch, or +// the end of its quantum, about 10 ms of its CPU. A process's read of its own +// count does not take the reading thread off its core — its CPU time is +// current at the read, its energy is not. So the count read from a thread +// that has been running lacks what that thread spent since it last left a +// core. Bracket a span with two such reads and the first puts up to a +// quantum of energy from BEFORE the span inside it, and the second leaves +// the span's tail out. Measured on an M3 Ultra, macOS 27.0.1 (load average +// about 14, three runs of 40 spans each, against the tests' own reader that +// sleeps before each of its reads): of spans over 1 ms of the reading +// thread's CPU, 39, 40 and 40 read nothing or under two thirds of the work; +// of spans over a 2 ms sleep opened straight after 8 ms of that thread's +// CPU, 40, 40 and 37 read the burn before them as the sleep's energy, about +// 41 mJ for a sleep. +// +// A thread that sleeps leaves its core — unless the sleep's timer fires +// before the thread has blocked, and then it goes on without leaving. So the +// reading thread sleeps and CHECKS: its own energy count +// (`proc_pidinfo`'s `PROC_PIDTHREADCOUNTS`) is moved by the kernel only when +// it adds the thread's energy to the process's, so a rise across a sleep is +// the thread having left its core after everything it did before the sleep. +// The process's context-switch count is no such check, since any other +// thread's switch moves it. The sleeps grow, so one that did not block is +// followed by one that much more surely does. +#[cfg_attr(not(target_os = "macos"), allow(dead_code))] +mod reading_thread { + use std::time::Duration; + + /// The sleeps the reading thread takes, in turn, until one is seen to + /// take it off its core: 6.25 ms in all on a read that never is. + pub(crate) const SLEEPS: [Duration; 4] = + [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1), Duration::from_millis(5)]; + + /// Whether the reading thread was seen to leave its core: its own energy + /// count, read by `count`, rose across one of `sleeps`, taken in turn + /// through `sleep`. A count that held across every sleep, or fell, is no + /// evidence that it left, and a count that cannot be read ends the wait + /// at once: `false`, and the process's count is not read on it. + pub(crate) fn left_its_core( + sleeps: &[Duration], + mut count: impl FnMut() -> Option, + mut sleep: impl FnMut(Duration), + ) -> bool { + for &pause in sleeps { + let Some(before) = count() else { return false }; + sleep(pause); + match count() { + Some(after) if after > before => return true, + Some(_) => {} + None => return false, + } + } + false + } + + /// `PROC_PIDTHREADCOUNTS`: the `proc_pidinfo` flavor that returns one + /// thread's counts, asked by its 64-bit thread id. It is in the kernel's + /// `` (macOS 13 and later), not the SDK's + /// public header, so [`energy_nj`] reads its result in one layout only. + pub(crate) const THREAD_COUNTS_FLAVOR: i32 = 34; + + /// The size of the buffer a read of the thread's counts hands the + /// kernel: room for the header and twelve performance levels. + pub(crate) const THREAD_COUNTS_SIZE: usize = 8 + 12 * 40; + + /// The thread's CPU energy in nanojoules, summed over the CPU performance + /// levels, from the `wrote` bytes the call says it wrote into `counts`. + /// The kernel writes a `uint16_t` count of performance levels and six + /// bytes of padding, then for each level five `uint64_t`: instructions, + /// cycles, user time, system time, energy (nJ). + /// + /// `None` unless the call wrote exactly that: the 8-byte header and one + /// 40-byte record for each level the header names, at least one. A + /// failed call and a result of any other size — a layout this crate does + /// not know — are no count, never a field read from the wrong place. + /// Seen on an M5 Max and an M3 Ultra (macOS 27.0.1): 88 bytes, two + /// levels. + pub(crate) fn energy_nj(counts: &[u8], wrote: i32) -> Option { + let levels = usize::from(u16::from_ne_bytes([*counts.first()?, *counts.get(1)?])); + let size = 8 + levels * 40; + if levels == 0 || size > counts.len() || usize::try_from(wrote).ok() != Some(size) { + return None; + } + let mut nj = 0u64; + for level in 0..levels { + let at = 8 + level * 40 + 32; + let mut energy = [0u8; 8]; + energy.copy_from_slice(&counts[at..at + 8]); + nj = nj.saturating_add(u64::from_ne_bytes(energy)); + } + Some(nj) + } + + #[cfg(test)] + mod tests { + use super::*; + use std::cell::RefCell; + + /// The thread is seen to leave its core only when its own count + /// rose across a sleep: the sleeps are taken in turn until one does. + /// A count that held, fell or could not be read is not a thread + /// seen to leave, and an unreadable count takes no further sleep. + #[test] + fn a_thread_is_seen_to_leave_its_core_only_by_its_own_count_rising() { + let sleeps = [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1)]; + let seen = |counts: &[Option]| { + let mut counts = counts.iter().copied(); + let slept = RefCell::new(Vec::new()); + let left = left_its_core(&sleeps, || counts.next().flatten(), |pause| slept.borrow_mut().push(pause)); + (left, slept.into_inner()) + }; + assert_eq!(seen(&[Some(300), Some(301)]), (true, vec![sleeps[0]]), "rose across the first sleep"); + assert_eq!( + seen(&[Some(300), Some(300), Some(300), Some(300), Some(300), Some(9_000)]), + (true, sleeps.to_vec()), + "held across two sleeps, rose across the third" + ); + assert_eq!(seen(&[Some(300); 6]), (false, sleeps.to_vec()), "held across every sleep"); + assert_eq!(seen(&[Some(300), Some(200), Some(200), Some(100), Some(100), Some(50)]), (false, sleeps.to_vec()), "fell"); + assert_eq!(seen(&[None]), (false, vec![]), "unreadable before any sleep"); + assert_eq!(seen(&[Some(300), None]), (false, vec![sleeps[0]]), "unreadable after a sleep"); + assert!(!left_its_core(&[], || Some(1), |_| panic!("slept")), "no sleep, nothing seen"); + assert_eq!(SLEEPS.iter().sum::(), Duration::from_micros(6_250)); + assert!(SLEEPS.windows(2).all(|w| w[0] < w[1]) && SLEEPS[0] >= Duration::from_micros(50), "{SLEEPS:?}"); + } + + /// A thread's counts as the kernel writes them: `levels` in the + /// first two bytes, six of padding, then five u64 a level, the fifth + /// its energy. + fn counts(levels: u16, energy_nj: &[u64]) -> Vec { + let mut bytes = vec![0u8; THREAD_COUNTS_SIZE]; + bytes[..2].copy_from_slice(&levels.to_ne_bytes()); + for (level, nj) in energy_nj.iter().enumerate() { + for (field, word) in [9_001u64, 9_002, 9_003, 9_004, *nj].into_iter().enumerate() { + let at = 8 + level * 40 + field * 8; + bytes[at..at + 8].copy_from_slice(&word.to_ne_bytes()); + } + } + bytes + } + + /// The energy is each level's fifth u64, summed; and a result of any + /// size but the header and one record per level named is no count. + #[test] + fn the_threads_energy_is_read_only_from_the_layout_known() { + assert_eq!(energy_nj(&counts(2, &[4_000_000, 600]), 88), Some(4_000_600), "two levels, 88 bytes"); + assert_eq!(energy_nj(&counts(1, &[42]), 48), Some(42)); + assert_eq!(energy_nj(&counts(3, &[1, 10, 100]), 128), Some(111)); + assert_eq!(energy_nj(&counts(2, &[u64::MAX, 1]), 88), Some(u64::MAX), "the sum saturates"); + let two = counts(2, &[4_000_000, 600]); + for (wrote, why) in [(-1, "the call failed"), (0, "nothing written"), (48, "one record"), (87, "short"), (128, "long")] { + assert_eq!(energy_nj(&two, wrote), None, "{why}"); + } + assert_eq!(energy_nj(&counts(0, &[]), 8), None, "no performance level"); + assert_eq!(energy_nj(&counts(13, &[]), 8 + 13 * 40), None, "more levels than the buffer holds"); + assert_eq!(energy_nj(&[2], 88), None, "no header"); + assert_eq!(THREAD_COUNTS_FLAVOR, 34); + } + } +} + /// This process's own CPU energy on macOS, as the kernel attributes it to /// this process's threads: `ri_energy_nj` of `proc_pid_rusage(getpid(), /// RUSAGE_INFO_V6)` (libproc; public, no privilege, no entitlement). @@ -4499,11 +4672,48 @@ pub use macos_powermetrics::MacosPowermetricsCounter; /// measured. A caller whose metered work runs on the CPU in this process /// opts in with [`crate::detect_in_process`] or /// [`MacosProcessEnergyCounter::try_new`]. +/// +/// **Each read is taken only once the reading thread is seen to have left +/// its core** (`reading_thread`): the kernel counts a thread's energy into +/// the process's only then, so a read from a thread still on its core lacks +/// what that thread spent since it last left one, and a span bracketed by +/// two such reads holds what the thread spent before the span and lacks its +/// own tail. The read sleeps 50 µs, then 200 µs, 1 ms and 5 ms, until the +/// reading thread's own energy count rose across a sleep, and only then +/// reads the process. A read whose thread was not seen to leave is an +/// error, not a short count: every consumer here takes a failed read as no +/// span, and keeps its estimate. With it, the same spans on the same host, +/// quiet and under 40 busy loops (110 runs of 40 spans of each kind): every +/// 1 ms span read 79% or more of the tests' own window around it (98% on +/// the quiet host), and no sleep read more than 3% of the window that held +/// the burn before it. +/// +/// What that costs, the sleep and the wait for a core after it: 83 µs a +/// read at the median on the quiet host and 113 µs at most; under 40 busy +/// loops (load average up to 105 on 32 cores), 226 µs at the median over +/// the runs, 1.5 ms at the median of the worst run, and up to 38 ms for one +/// read; against under 1 µs for the read alone. A read that fails costs all +/// four sleeps (6.25 ms) and their waits. A span also holds its closing +/// read's own wake-up, a few tens of microjoules (31 µJ for a span over a +/// 500 ms sleep), which is most of the figure for a span over much less +/// than a millisecond of work: such a span is a true reading of what this +/// process spent between its two reads, over that work and not under it. A +/// caller with many short pieces of work brackets the lot with one span, +/// not each with its own. +/// +/// Only the reading thread is seen to leave. Another thread of the process +/// that is on a core at a read is short by what it spent since it last left +/// one, up to a quantum: work on the thread that takes both reads is read +/// whole, and work on other threads (a thread pool, or a task an async +/// runtime moved to another thread between the two reads) to within a +/// quantum for each such thread at each end. The liveness probe samples the +/// count with no sleep: it asks only whether the count keeps advancing under +/// a burn, which it does at every quantum. #[cfg(target_os = "macos")] #[allow(unsafe_code)] mod macos_process_energy { use super::*; - use crate::rail_liveness; + use crate::{rail_liveness, reading_thread}; use std::os::raw::{c_int, c_void}; /// `RUSAGE_INFO_V6` in ``. @@ -4576,6 +4786,9 @@ mod macos_process_energy { unsafe extern "C" { fn proc_pid_rusage(pid: c_int, flavor: c_int, buffer: *mut c_void) -> c_int; + fn proc_pidinfo(pid: c_int, flavor: c_int, arg: u64, buffer: *mut c_void, buffersize: c_int) -> c_int; + fn pthread_self() -> *mut c_void; + fn pthread_threadid_np(thread: *mut c_void, thread_id: *mut u64) -> c_int; fn getpid() -> c_int; } @@ -4584,6 +4797,29 @@ mod macos_process_energy { unsafe { getpid() } } + /// The calling thread's own cumulative CPU energy, in nanojoules: the + /// count a read watches to see the thread leave its core. `None` if the + /// thread's id or its counts cannot be read, or the counts come back in + /// a layout [`reading_thread::energy_nj`] does not know. + pub(crate) fn this_thread_energy_nj() -> Option { + let mut thread = 0u64; + if unsafe { pthread_threadid_np(pthread_self(), &mut thread) } != 0 { + return None; + } + let mut counts = [0u8; reading_thread::THREAD_COUNTS_SIZE]; + let size = c_int::try_from(counts.len()).ok()?; + let wrote = unsafe { + proc_pidinfo(this_pid(), reading_thread::THREAD_COUNTS_FLAVOR, thread, counts.as_mut_ptr() as *mut c_void, size) + }; + reading_thread::energy_nj(&counts, wrote) + } + + /// What a read of this process's own count says when the reading thread + /// was not seen to leave its core before it. + const NOT_SEEN_OFF_CORE: &str = "the reading thread was not seen to leave its core before a read of its own \ + process's energy: the count could lack what the thread spent since it last \ + did, so it was not read"; + /// The cumulative CPU energy, in nanojoules, the kernel attributes to the /// threads of process `pid`; `None` when `proc_pid_rusage` fails (no such /// process, or one this user may not inspect). @@ -4600,6 +4836,10 @@ mod macos_process_energy { #[derive(Debug)] pub struct MacosProcessEnergyCounter { pid: i32, + /// The reading thread's own energy count, which every read is + /// checked against: [`this_thread_energy_nj`], but for a test of a + /// thread that is never seen to leave its core. + thread_count: fn() -> Option, } impl MacosProcessEnergyCounter { @@ -4615,7 +4855,7 @@ mod macos_process_energy { /// every status the gate does not admit declines. pub(crate) fn try_new_given(status: CounterStatus) -> Result { if rail_liveness::admits_vendor_counter(status) { - Ok(Self { pid: this_pid() }) + Ok(Self { pid: this_pid(), thread_count: this_thread_energy_nj }) } else { Err(Error::NoCounter) } @@ -4624,8 +4864,16 @@ mod macos_process_energy { impl JouleCounter for MacosProcessEnergyCounter { /// This process's cumulative CPU energy since it started, in µJ - /// (`ri_energy_nj` / 1000). + /// (`ri_energy_nj` / 1000), read once the calling thread is seen to + /// have left its core, so the count holds all that thread spent + /// before the read. `Err` where it was not seen to leave within + /// [`reading_thread::SLEEPS`]: the process's count is then not read, + /// and a caller that brackets a span with this read has no reading + /// of the span, never a short one. Sleeps at least 50 µs. fn read_microjoules(&self) -> Result { + if !reading_thread::left_its_core(&reading_thread::SLEEPS, self.thread_count, std::thread::sleep) { + return Err(Error::Backend(NOT_SEEN_OFF_CORE.to_string())); + } energy_nj(self.pid) .map(|nj| nj / 1_000) .ok_or_else(|| Error::Backend("proc_pid_rusage(RUSAGE_INFO_V6) failed".to_string())) @@ -4666,10 +4914,28 @@ mod macos_process_energy { /// The real probe: this process's counter, the CPU-burning tick (this /// thread's burn is this process's work, so a live counter advances in /// every interval) and the monotonic clock. Cached by - /// [`crate::process_energy_status`], its only caller. + /// [`crate::process_energy_status`], its only caller. The probe samples + /// the count with no sleep before a sample. + /// + /// `Unavailable`, the probe not run, where the calling thread's own + /// energy count does not read: every read the counter takes is checked + /// against that count, so a counter there could never read. pub(crate) fn host_status() -> CounterStatus { let pid = this_pid(); - status_with(|| energy_nj(pid), crate::clocks::cpu_burn_tick, crate::clocks::wall_now) + status_where(this_thread_energy_nj().is_some(), || { + status_with(|| energy_nj(pid), crate::clocks::cpu_burn_tick, crate::clocks::wall_now) + }) + } + + /// The counter's status on a host where the reading thread's own energy + /// count reads, or does not: what `probe` finds where it does, and + /// `Unavailable`, with no probe run, where it does not. + pub(crate) fn status_where(thread_count_reads: bool, probe: impl FnOnce() -> CounterStatus) -> CounterStatus { + if thread_count_reads { + probe() + } else { + CounterStatus::Unavailable + } } #[cfg(test)] @@ -4721,7 +4987,54 @@ mod macos_process_energy { #[test] fn no_process_no_reading() { assert_eq!(energy_nj(-1), None); - assert!(MacosProcessEnergyCounter { pid: -1 }.read_microjoules().is_err()); + assert!(MacosProcessEnergyCounter { pid: -1, thread_count: this_thread_energy_nj }.read_microjoules().is_err()); + } + + /// A read whose thread is never seen to leave its core is no read: + /// an error after every sleep, never the count as it stands — which + /// could lack what the thread spent — and an error at once when the + /// thread's own count cannot be read. A consumer takes either as no + /// span and keeps its estimate. + #[test] + fn a_read_whose_thread_is_never_seen_off_its_core_fails() { + let held = MacosProcessEnergyCounter { pid: this_pid(), thread_count: || Some(7) }; + let started = std::time::Instant::now(); + let read = held.read_microjoules(); + let took = started.elapsed(); + assert!(matches!(&read, Err(Error::Backend(why)) if why.contains("not seen to leave its core")), "{read:?}"); + let every_sleep: Duration = reading_thread::SLEEPS.iter().sum(); + assert!(took >= every_sleep, "gave up after {took:?}, before all of {:?}", reading_thread::SLEEPS); + + let unreadable = MacosProcessEnergyCounter { pid: this_pid(), thread_count: || None }; + let read = unreadable.read_microjoules(); + assert!(matches!(&read, Err(Error::Backend(why)) if why.contains("not seen to leave its core")), "{read:?}"); + } + + /// On this host the calling thread's own count reads, in the layout + /// known, and a read of the counter sees the thread leave its core: + /// the path every reading takes. Two reads are in order, and the + /// first is this process's count: no more than the count as it + /// stands just after it. + #[test] + fn on_this_host_a_read_sees_the_reading_thread_leave_its_core() { + let thread = this_thread_energy_nj(); + eprintln!("process-energy: this thread's own energy count: {thread:?} nJ"); + assert!(thread.is_some(), "this thread's own energy count does not read here"); + let c = MacosProcessEnergyCounter::try_new_given(CounterStatus::Live).expect("Live constructs"); + let first = c.read_microjoules().expect("the reading thread was not seen to leave its core"); + let now = energy_nj(this_pid()).expect("this process's count") / 1_000; + let second = c.read_microjoules().expect("the reading thread was not seen to leave its core"); + assert!(first <= now && now <= second, "{first} µJ, then {now} µJ as it stands, then {second} µJ"); + } + + /// A host on which the reading thread's own count does not read has + /// no process counter: `Unavailable`, and the probe is not run. + #[test] + fn a_host_without_the_threads_count_has_no_process_counter() { + assert_eq!(status_where(false, || panic!("probed a counter no read could be checked on")), CounterStatus::Unavailable); + for status in [CounterStatus::Live, CounterStatus::Frozen, CounterStatus::Unavailable] { + assert_eq!(status_where(true, || status), status); + } } } } @@ -4757,6 +5070,14 @@ pub fn process_energy_status() -> CounterStatus { /// span over work done anywhere else reads only this process's share of it. /// That is why [`detect`] never selects it, and why only a caller that knows /// its work stays in-process should ask for it. +/// +/// Each read of the process counter sleeps at least 50 µs before it reads — +/// about 80 µs a read on a quiet host, a few hundred on a loaded one — +/// because it is taken only once the reading thread is seen to have left its +/// core ([`MacosProcessEnergyCounter`]). A span bracketed by two reads +/// therefore costs two such sleeps and holds its closing read's own wake-up +/// (tens of microjoules): bracket a batch of short operations with one span, +/// not each operation with its own. pub fn detect_in_process() -> Box { detect_in_process_with(process_energy_status, detect) } diff --git a/eoc/eoc-rs/crates/eoc-meter/tests/process_energy_short_span.rs b/eoc/eoc-rs/crates/eoc-meter/tests/process_energy_short_span.rs new file mode 100644 index 000000000..9439d7691 --- /dev/null +++ b/eoc/eoc-rs/crates/eoc-meter/tests/process_energy_short_span.rs @@ -0,0 +1,199 @@ +//! Short spans on this process's own CPU energy counter, against an oracle +//! that takes the reading thread off its core by a rule of its own. +//! +//! The kernel adds a thread's CPU energy to its process's count only when the +//! thread leaves its core. A process that reads its own count from a thread +//! still on its core reads a count that lacks what that thread spent since it +//! last left one: a span of a millisecond of work then reads nothing, and a +//! span opened straight after other work reads that work as its own. This +//! file brackets exactly such spans with two reads of the counter, as every +//! consumer of a [`JouleCounter`] does, and holds each delta against the +//! tests' own window around it. +//! +//! One test binary with one test: the counter's domain is every thread of the +//! process, and the oracle's check is the process's context-switch count, so +//! nothing else may run here. No joule figure, joules per CPU-second or +//! timing is asserted: what a millisecond of CPU costs follows the core that +//! ran it, and a loaded host stretches everything's wall time. + +#![cfg(target_os = "macos")] + +use std::os::raw::{c_int, c_void}; +use std::time::{Duration, Instant}; + +use eoc_meter::{CounterStatus, JouleCounter, MacosProcessEnergyCounter}; + +unsafe extern "C" { + fn proc_pid_rusage(pid: c_int, flavor: c_int, buffer: *mut c_void) -> c_int; + fn proc_pidinfo(pid: c_int, flavor: c_int, arg: u64, buffer: *mut c_void, buffersize: c_int) -> c_int; + fn clock_gettime_nsec_np(clock_id: u32) -> u64; +} + +/// `CLOCK_THREAD_CPUTIME_ID` in macOS ``. +const CLOCK_THREAD_CPUTIME_ID: u32 = 16; + +/// This thread's CPU time. +fn thread_cpu() -> Duration { + Duration::from_nanos(unsafe { clock_gettime_nsec_np(CLOCK_THREAD_CPUTIME_ID) }) +} + +/// Spin this thread until it has used `d` of its own CPU time (or 20 s of +/// wall time have passed), however loaded the host is. +fn burn(d: Duration) { + let (started, wall) = (thread_cpu(), Instant::now()); + let mut acc: u64 = 0; + while thread_cpu() - started < d && wall.elapsed() < Duration::from_secs(20) { + for _ in 0..1_000 { + acc = std::hint::black_box(acc.wrapping_add(1)); + } + } +} + +fn me() -> c_int { + std::process::id() as c_int +} + +/// The oracle's read of this process's `ri_energy_nj`: `proc_pid_rusage(pid, +/// RUSAGE_INFO_V6)` into 464 raw bytes, the count at byte 336. +fn oracle_energy_nj() -> u64 { + let mut words = [0u64; 464 / 8]; + let rc = unsafe { proc_pid_rusage(me(), 6, words.as_mut_ptr() as *mut c_void) }; + assert_eq!(rc, 0, "the oracle's proc_pid_rusage"); + words[336 / 8] +} + +/// How many times this process's threads have been switched off a core: +/// `pti_csw`, the `int32_t` at byte 80 of the 96-byte `proc_taskinfo` that +/// `proc_pidinfo(pid, PROC_PIDTASKINFO = 4)` fills. +fn oracle_context_switches() -> i32 { + let mut info = [0i32; 96 / 4]; + let wrote = unsafe { proc_pidinfo(me(), 4, 0, info.as_mut_ptr() as *mut c_void, 96) }; + assert_eq!(wrote, 96, "the oracle's proc_pidinfo(PROC_PIDTASKINFO)"); + info[80 / 4] +} + +/// The oracle's read of this process's energy, taken once this thread has +/// left its core by the oracle's own rule: a sleep of 1 ms, then 2, 4 and 8, +/// until the process's context-switch count rose across one. Only this +/// test's thread runs in this process, so a rise is this thread's switch, +/// and the read after it holds all the thread spent before it. The counter +/// under test shares neither call nor number with this. +fn oracle_energy_nj_off_core() -> u64 { + let left = [1, 2, 4, 8].into_iter().any(|ms| { + let before = oracle_context_switches(); + std::thread::sleep(Duration::from_millis(ms)); + oracle_context_switches() > before + }); + assert!(left, "the oracle never saw this thread leave its core across sleeps of 1, 2, 4 and 8 ms"); + oracle_energy_nj() +} + +/// What a span is to a consumer of the counter: the delta of its two reads, +/// only when both succeeded and the counter advanced between them. Anything +/// else measured nothing, and the consumer keeps its own estimate. +fn span_reading(start: eoc_core::Result, end: eoc_core::Result) -> Option { + match (start, end) { + (Ok(s), Ok(e)) if e > s => Some(e - s), + _ => None, + } +} + +#[test] +fn a_short_span_reads_what_an_oracle_that_leaves_its_core_its_own_way_reads() { + const TRIES: usize = 40; + let status = eoc_meter::process_energy_status(); + eprintln!("process-energy short span: status={status:?}"); + assert_eq!(status, CounterStatus::Live, "this process's CPU energy counter is not live here"); + let c = MacosProcessEnergyCounter::try_new().expect("the process counter is live here"); + + // 1. A millisecond of this thread's CPU between two reads of the counter. + // The oracle's window opens before the first read and closes after the + // second, each end read once this thread has left its core, so it + // holds the burn and both readers' own reads and wake-ups. A reading + // is the span's when it is no more than that window (and the µJ the + // two reads round away) and at least two thirds of it: the readers' + // own cost does not shrink with the burn's, and was up to 21% of the + // window on an M3 Ultra under 40 busy loops (2% when quiet). A reading + // above the window is not this process's count at all. + let (mut shares, mut none, mut short, mut over) = (Vec::new(), 0usize, Vec::new(), Vec::new()); + for i in 0..TRIES { + let before = oracle_energy_nj_off_core(); + let start = c.read_microjoules(); + burn(Duration::from_millis(1)); + let end = c.read_microjoules(); + let oracle_nj = oracle_energy_nj_off_core() - before; + match span_reading(start, end).map(|uj| uj * 1_000) { + None => none += 1, + Some(nj) if nj > oracle_nj + 1_000 => over.push((i, nj / 1_000, oracle_nj)), + Some(nj) if nj * 3 < oracle_nj * 2 => short.push((i, nj / 1_000, oracle_nj)), + Some(nj) => shares.push(nj * 1_000 / oracle_nj.max(1)), + } + } + eprintln!( + "process-energy short span: 1 ms burn x {TRIES}: {} read within the oracle's window (at least {}/1000 of it), \ + {none} not read, {} read short {short:?}, {} read over {over:?} (try, µJ, oracle nJ)", + shares.len(), + shares.iter().min().copied().unwrap_or(0), + short.len(), + over.len() + ); + + // 2. A 2 ms sleep between two reads, straight after 8 ms of this thread's + // CPU that the span does not cover. The burn is still on the thread, + // not yet in the process's count, when the span opens; a counter whose + // first read does not take the thread off its core reads the burn as + // the sleep's energy. The oracle's window is the burn and the sleep: a + // reading for the sleep is under a quarter of it (it was under 1% on + // a quiet host and at most 3% under 40 busy loops), or no reading at + // all. + let (mut slept, mut slept_none, mut leaked) = (Vec::new(), 0usize, Vec::new()); + for i in 0..TRIES { + let before = oracle_energy_nj_off_core(); + burn(Duration::from_millis(8)); + let start = c.read_microjoules(); + std::thread::sleep(Duration::from_millis(2)); + let end = c.read_microjoules(); + let oracle_nj = oracle_energy_nj_off_core() - before; + match span_reading(start, end).map(|uj| uj * 1_000) { + None => slept_none += 1, + Some(nj) if nj * 4 >= oracle_nj => leaked.push((i, nj / 1_000, oracle_nj)), + Some(nj) => slept.push(nj * 1_000 / oracle_nj.max(1)), + } + } + eprintln!( + "process-energy short span: 2 ms sleep after an 8 ms burn x {TRIES}: {} read under a quarter of the oracle's \ + window (at most {}/1000 of it), {slept_none} not read, {} read the burn before the span {leaked:?} (try, µJ, \ + oracle nJ)", + slept.len(), + slept.iter().max().copied().unwrap_or(0), + leaked.len() + ); + + // 3. What one read costs, in wall time: reported, never asserted. + let mut micros: Vec = (0..200) + .map(|_| { + let t = Instant::now(); + let _ = c.read_microjoules(); + t.elapsed().as_micros() + }) + .collect(); + micros.sort_unstable(); + eprintln!( + "process-energy short span: one read of the counter costs {} µs at the median, {} µs at the 95th percentile, \ + {} µs at most (200 reads)", + micros[100], micros[190], micros[199] + ); + + assert!(over.is_empty(), "a span read more than this process spent around it: {over:?}"); + // A tenth of the spans may miss the band: on a loaded host the oracle's + // own reads can land on a costlier core than the burn did, and a read + // whose thread was not seen to leave its core is no reading by design. + // A counter that does not take the reading thread off its core misses on + // most spans (all 40, on an idle host). + assert!( + (none + short.len()) * 10 <= TRIES, + "{none} of {TRIES} 1 ms spans were not read and {} were read short: {short:?}", + short.len() + ); + assert!(leaked.len() * 10 <= TRIES, "{} of {TRIES} sleeps read the burn before them: {leaked:?}", leaked.len()); +} -- 2.54.0 (Apple Git-157) From 60bcca7594a96d2868a13474f3d77c9a6b2e9dd7 Mon Sep 17 00:00:00 2001 From: Transaction Science Date: Mon, 12 Oct 2026 20:23:14 -0400 Subject: [PATCH 4/5] proof-cascade: the meter reads its own process only once the measuring thread has left its core measure_marginal's process-counter rung brackets its window with two reads of this process's CPU energy (proc_pid_rusage ri_energy_nj). The kernel adds a thread's energy to that count only when the thread leaves a core, and a process's read of its own count does not take the reading thread off its core. So the first read left up to a scheduling quantum of what the measuring thread spent before the window (the liveness probe's burn, the caller's own work) to land inside it, and the figure is sealed HwShunt. Measured on an M3 Ultra (macOS 27.0.1) with the meter's own read at each end of a window on the reading thread, against the tests' own reader, which sleeps before each read until the process's context-switch count rose; three runs of 40 windows of each kind: - 1 ms of the reading thread's CPU: all 40 read no advance, every run; - a 2 ms sleep straight after 8 ms of CPU: all 40 read the burn before them, every run, 40 to 48 mJ for a sleep. Each of the measurement's two reads now sleeps (50 us, then 200 us, 1 ms, 5 ms) until the measuring thread's own energy count (proc_pidinfo PROC_PIDTHREADCOUNTS, read only in the one layout known: 88 bytes, two performance levels here) rose across a sleep, and only then reads the process. A read whose thread was not seen to leave gives the measurement no figure, by the path an unreadable counter already takes: the work does not run, measure_marginal returns None and the caller keeps its estimate. The process counter is Unavailable where the thread's count does not read (proof --measure says so), and the liveness probe still samples with no sleep. The rule and the layout decoding are pure and compiled on every platform. The measurement was already one window around a batch: a second of calls on every spare core, two reads in all. Its workers have exited and been joined before the closing read, and a thread's exit puts its last time on a core into the count before the join returns (measured: a 5 ms burn read the same at the join whether or not the thread slept first), so only the measuring thread needed taking off its core. With it, on that host: quiet, every window read 98% or more of the tests' window and no sleep more than 1% of the window that held the burn; under 40 busy loops (110 runs), 82% or more and 4% or less. A read costs about 80 us quiet and 190 us at the median under the busy loops, against under 1 us. process_window_read_nj is a doc-hidden hook, like the crate's other test hooks: tests/process_energy_short_span.rs, the test that fails without the check, needs a process of its own. The published conformance vectors are unchanged (gen-vectors into a scratch directory is byte-identical to conformance/v1). Co-Authored-By: Claude Opus 5.5 --- .../crates/proof-cascade/src/meter.rs | 395 +++++++++++++++++- .../tests/process_energy_short_span.rs | 188 +++++++++ proof/proof-rs/crates/proof-cli/src/main.rs | 3 +- 3 files changed, 571 insertions(+), 15 deletions(-) create mode 100644 proof/proof-rs/crates/proof-cascade/tests/process_energy_short_span.rs diff --git a/proof/proof-rs/crates/proof-cascade/src/meter.rs b/proof/proof-rs/crates/proof-cascade/src/meter.rs index f8f377885..25f61049c 100644 --- a/proof/proof-rs/crates/proof-cascade/src/meter.rs +++ b/proof/proof-rs/crates/proof-cascade/src/meter.rs @@ -11,7 +11,8 @@ //! this process's threads burn meanwhile, which in a quiet caller is the //! workers' start-up and the sleeping caller, a few microjoules — while //! other processes are excluded by construction: no idle baseline to -//! subtract. +//! subtract. Each of the two reads is taken only once the calling thread +//! is seen to have left its core (below). //! 2. **IOReport's Energy Model** (Apple Silicon, read directly via its C API — //! no `macmon`, no sudo): SoC power bracketed busy against idle. //! 3. **RAPL** `energy_uj` (Linux): package power bracketed busy against idle. @@ -53,6 +54,52 @@ //! about every 0.5–0.7 ms under load, holds near 1–2 mJ/s idle, and keeps the //! energy of threads that have exited. //! +//! **A read of this process's own counter is taken only once the reading +//! thread is seen to have left its core.** The kernel adds a thread's energy +//! to its process's count only when the thread leaves a core — a context +//! switch, or the end of its quantum, about 10 ms of its CPU — and a +//! process's read of its own count does not take the reading thread off its +//! core: its CPU time is current at the read, its energy is not. So a window +//! bracketed by two plain reads holds, at its start, up to a quantum of what +//! the reading thread spent BEFORE the window (the liveness probe's burn, +//! say, or the caller's own work), and lacks, at its end, what that thread +//! spent since it last left a core. Measured on an M3 Ultra (macOS 27.0.1, +//! three runs of 40 windows of each kind, against the tests' own reader that +//! sleeps before each of its reads): a window over 1 ms of the reading +//! thread's CPU read no advance in all 40, every run; a window over a 2 ms +//! sleep opened straight after 8 ms of that thread's CPU read the burn +//! before it in all 40, every run, 40 to 48 mJ for a sleep. +//! +//! So before each read of its window the measuring thread sleeps (50 µs, +//! then 200 µs, 1 ms, 5 ms) until its own energy count +//! (`proc_pidinfo`'s `PROC_PIDTHREADCOUNTS`, by its thread id) rose across a +//! sleep — which it does only when the kernel adds that thread's energy to +//! the process's — and only then reads the process. A sleep alone is no +//! proof: one whose timer fires before the thread has blocked returns with +//! the thread still on its core; and the process's context-switch count is +//! none either, since any other thread's switch moves it. A read whose +//! thread was not seen to leave is no read: the measurement returns `None`, +//! and the caller keeps its estimate — never a figure short of the window's +//! tail, or holding what was spent before it, graded `HwShunt`. With it, the +//! same windows on the same host: quiet, all 40 of the 1 ms windows read 98% +//! or more of the tests' own window around them, and all 40 of the sleeps +//! under 1% of the window that held the burn before them; under 40 busy +//! loops (110 runs), every window read 82% or more, and no sleep more than +//! 4%. A read costs about 80 µs on the quiet host (the sleep and the wait +//! for a core after it) and 190 µs at the median under the busy loops (0.9 ms +//! at the median of the worst run, 50 ms the worst single read), against +//! under 1 µs for the read alone, and all four sleeps (6.25 ms) and their +//! waits when it fails. The measurement takes two, around a window of a +//! second over every spare core: one window around the whole batch of +//! calls, not one around each call. The workers have exited and been joined +//! before the closing read, and a thread's exit puts its last time on a core +//! into the count before the join returns (measured: a 5 ms burn read the +//! same at the join whether or not the thread slept before it exited), so +//! the window holds every call it counts. The counter is used only where the +//! measuring thread's own count reads, in the one layout known, and the +//! liveness probe samples with no sleep: it asks only whether the count +//! keeps advancing under a burn, which it does at every quantum. +//! //! **IOReport counts as reachable only while every CPU energy rail is live** //! ([`ioreport_status`](crate::meter::ioreport_status)). A subscription can //! open while no CPU rail tracks the work: measured on macOS 27.0.1 for an @@ -485,7 +532,9 @@ pub enum CounterStatus { /// permission to read it (RAPL's `energy_uj` is root-only on current /// kernels), or never two consecutive reads within the probe's five /// budgets. Never used. (The process counter is never `Absent`: it is one - /// counter, read or not.) + /// counter, read or not. It is `Unavailable` too where the measuring + /// thread's own energy count does not read: each read of a window is + /// checked against that count, so without it no window could be read.) Unavailable, /// The interface was read, but holds no counter for the domain a figure /// would claim (RAPL: zones, but no `package-` zone). Never used. @@ -742,13 +791,29 @@ static REAL_PROCESS_PROBE_RUNS: std::sync::atomic::AtomicUsize = std::sync::atom #[cfg(target_os = "macos")] fn process_host_status() -> CounterStatus { REAL_PROCESS_PROBE_RUNS.fetch_add(1, Ordering::SeqCst); - counter_status_of(&process_probe_with( - macos_process::energy_nj, - probe_clock::spin_tick, - probe_clock::wall_clock, - probe_clock::thread_cpu_time, - PROCESS_LIVENESS_BUDGET, - )) + process_status_where(macos_process::thread_energy_nj().is_some(), || { + counter_status_of(&process_probe_with( + macos_process::energy_nj, + probe_clock::spin_tick, + probe_clock::wall_clock, + probe_clock::thread_cpu_time, + PROCESS_LIVENESS_BUDGET, + )) + }) +} + +/// The process counter's status on a host where the measuring thread's own +/// energy count reads, or does not: what `probe` finds where it does, and +/// `Unavailable`, with no probe run, where it does not — every read of a +/// window is checked against that count ([`own_read`]), so a counter there +/// could never meter. +#[cfg_attr(not(target_os = "macos"), allow(dead_code))] +fn process_status_where(thread_count_reads: bool, probe: impl FnOnce() -> CounterStatus) -> CounterStatus { + if thread_count_reads { + probe() + } else { + CounterStatus::Unavailable + } } /// This host's process-counter status, probed once per process and cached: @@ -785,6 +850,27 @@ pub fn simulate_frozen_process_energy() { macos_process::FROZEN.store(true, Ordering::SeqCst); } +/// The read [`measure_marginal`] takes of this process's CPU energy counter at +/// each end of its window, in nanojoules, where that counter is live: `None` +/// off macOS, where it is not live, and where the calling thread was not seen +/// to leave its core before the read ([`own_read`]). Exposed for the +/// short-span test, which brackets work of its own with two of these reads in +/// a process of its own; not part of the meter's interface. +#[doc(hidden)] +pub fn process_window_read_nj() -> Option { + #[cfg(target_os = "macos")] + { + if !admits_counter(process_energy_status()) { + return None; + } + macos_process::window_read_nj() + } + #[cfg(not(target_os = "macos"))] + { + None + } +} + /// The process-counter rung: `work` on every spare core, metered by this /// process's CPU energy counter — only while it is live (its own gate, on the /// cached status). `None` off macOS. @@ -797,7 +883,7 @@ where if !admits_counter(process_energy_status()) { return None; } - process_marginal_with(work, macos_process::energy_nj, PROCESS_WINDOW) + process_marginal_with(work, macos_process::window_read_nj, PROCESS_WINDOW) } #[cfg(not(target_os = "macos"))] { @@ -818,10 +904,11 @@ fn spare_cores() -> usize { /// rounded to the nearest: the counter's advance ÷ every call that completed. /// Reading after the join puts the energy of every counted call, and only /// those calls' window, in the figure; a call still running when `window` -/// ends finishes and is counted. `None` if either read fails (the work never -/// runs when the first one does), if the counter went down, or if no call -/// completed. Generic over the counter, so the tests drive it on a scripted -/// counter. +/// ends finishes and is counted. `None` if either read gives nothing (the +/// work never runs when the first one does) — the call failed, or, in +/// production, the calling thread was not seen to leave its core before the +/// read ([`own_read`]) — if the counter went down, or if no call completed. +/// Generic over the counter, so the tests drive it on a scripted counter. #[cfg_attr(not(target_os = "macos"), allow(dead_code))] fn process_marginal_with(work: F, counter: impl Fn() -> Option, window: std::time::Duration) -> Option where @@ -2422,6 +2509,194 @@ mod probe_clock { } } +// --------------------------------------------------------------------------- +// A process's read of its own energy counter: when it may be taken, and the +// one byte layout that check depends on. Kept apart from the FFI so both are +// pure, tested code on every platform; the macOS module only supplies the +// thread's own count, the sleep and the read. Why the check exists is in the +// module doc ("A read of this process's own counter…"). +// --------------------------------------------------------------------------- +#[cfg_attr(not(target_os = "macos"), allow(dead_code))] +mod own_read { + use std::time::Duration; + + /// The sleeps the measuring thread takes, in turn, before a read of its + /// own process, until one is seen to take it off its core. They grow, so + /// a sleep that returned without blocking is followed by one that much + /// more surely blocks; 6.25 ms in all on a read that is never seen to. + pub(super) const SLEEPS: [Duration; 4] = + [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1), Duration::from_millis(5)]; + + /// Whether the measuring thread was seen to leave its core: its own + /// energy count (`count`) rose across one of `sleeps`, each taken in turn + /// through `sleep`. The kernel moves that count only when it adds the + /// thread's energy to its process's, so a rise across a sleep is the + /// thread having left its core after all it did before the sleep. A + /// count that held across every sleep, or went down, shows no such + /// thing, and one that cannot be read ends the wait at once. + pub(super) fn thread_left_its_core( + sleeps: &[Duration], + mut count: impl FnMut() -> Option, + mut sleep: impl FnMut(Duration), + ) -> bool { + for &pause in sleeps { + let Some(before) = count() else { return false }; + sleep(pause); + let Some(after) = count() else { return false }; + if after > before { + return true; + } + } + false + } + + /// One read at an end of the measurement's window: `counter`, this + /// process's cumulative CPU energy, read only once the measuring thread + /// was seen to leave its core ([`thread_left_its_core`] over [`SLEEPS`]). + /// `None` where it was not — the counter is then not read at all — or + /// the counter's own read gives nothing. + pub(super) fn window_read( + count: impl FnMut() -> Option, + sleep: impl FnMut(Duration), + counter: impl FnOnce() -> Option, + ) -> Option { + if thread_left_its_core(&SLEEPS, count, sleep) { + counter() + } else { + None + } + } + + /// `PROC_PIDTHREADCOUNTS`, the `proc_pidinfo` flavor that returns one + /// thread's counts, asked by its 64-bit thread id: in the kernel's + /// `` (macOS 13 and later), not the SDK's + /// public header, so its result is read in one layout only + /// ([`thread_energy_nj`]). + pub(super) const THREAD_COUNTS_FLAVOR: i32 = 34; + + /// The bytes a read of a thread's counts gives the kernel room for: the + /// header and twelve performance levels. + pub(super) const THREAD_COUNTS_BYTES: usize = 8 + 12 * 40; + + /// A thread's cumulative CPU energy in nanojoules, summed over the CPU + /// performance levels, from the `wrote` bytes the call says it wrote + /// into `counts`: a `uint16_t` count of levels and six bytes of padding, + /// then for each level five `uint64_t` — instructions, cycles, user + /// time, system time, energy (nJ). + /// + /// `None` unless the call wrote exactly the 8-byte header and one 40-byte + /// record for each level the header names, at least one. A failed call + /// and a result of any other size are a layout this code does not know: + /// no count, never a number read from the wrong place. An M5 Max and an + /// M3 Ultra (macOS 27.0.1) write 88 bytes, two levels. + pub(super) fn thread_energy_nj(counts: &[u8], wrote: i32) -> Option { + let levels = usize::from(u16::from_ne_bytes([*counts.first()?, *counts.get(1)?])); + let bytes = 8 + levels * 40; + if levels == 0 || bytes > counts.len() || usize::try_from(wrote).ok() != Some(bytes) { + return None; + } + let energy = (0..levels).map(|level| { + let at = 8 + level * 40 + 32; + let mut word = [0u8; 8]; + word.copy_from_slice(&counts[at..at + 8]); + u64::from_ne_bytes(word) + }); + Some(energy.fold(0, u64::saturating_add)) + } + + #[cfg(test)] + mod tests { + use super::*; + use std::cell::{Cell, RefCell}; + + /// The measuring thread is seen to leave its core only when its own + /// count rose across a sleep; the sleeps are taken in turn until one + /// does. A count that held, went down or could not be read is no + /// such sight, and an unreadable count takes no further sleep. + #[test] + fn the_thread_is_seen_to_leave_its_core_only_by_its_own_count_rising() { + let sleeps = [Duration::from_micros(50), Duration::from_micros(200), Duration::from_millis(1)]; + let seen = |counts: &[Option]| { + let mut counts = counts.iter().copied(); + let slept = RefCell::new(Vec::new()); + let left = thread_left_its_core(&sleeps, || counts.next().flatten(), |pause| slept.borrow_mut().push(pause)); + (left, slept.into_inner()) + }; + assert_eq!(seen(&[Some(70), Some(71)]), (true, vec![sleeps[0]]), "rose across the first sleep"); + assert_eq!( + seen(&[Some(70), Some(70), Some(70), Some(70), Some(70), Some(5_000)]), + (true, sleeps.to_vec()), + "held across two sleeps, rose across the third" + ); + assert_eq!(seen(&[Some(70); 6]), (false, sleeps.to_vec()), "held across every sleep"); + assert_eq!(seen(&[Some(70), Some(60), Some(60), Some(50), Some(50), Some(40)]), (false, sleeps.to_vec()), "went down"); + assert_eq!(seen(&[None]), (false, vec![]), "unreadable before any sleep"); + assert_eq!(seen(&[Some(70), None]), (false, vec![sleeps[0]]), "unreadable after a sleep"); + assert!(!thread_left_its_core(&[], || Some(1), |_| panic!("slept")), "no sleep, nothing seen"); + assert_eq!(SLEEPS.iter().sum::(), Duration::from_micros(6_250)); + } + + /// A window's read is the counter's only once the thread was seen to + /// leave its core. Where its count never rises the read is `None` + /// after every sleep, and the counter is not read at all; where its + /// count cannot be read, `None` at once. A counter that gives + /// nothing after a thread seen to leave is `None` too. + #[test] + fn a_window_read_whose_thread_is_not_seen_to_leave_its_core_is_no_read() { + let run = |counts: &[Option], counter: Option| { + let mut counts = counts.iter().copied().cycle(); + let slept = RefCell::new(Vec::new()); + let read = Cell::new(false); + let r = window_read( + || counts.next().flatten(), + |pause| slept.borrow_mut().push(pause), + || { + read.set(true); + counter + }, + ); + (r, slept.into_inner(), read.get()) + }; + assert_eq!(run(&[Some(3), Some(8)], Some(123_456)), (Some(123_456), vec![SLEEPS[0]], true)); + assert_eq!(run(&[Some(3)], Some(123_456)), (None, SLEEPS.to_vec(), false), "a count that never rose"); + assert_eq!(run(&[None], Some(123_456)), (None, vec![], false), "a count that cannot be read"); + assert_eq!(run(&[Some(3), Some(8)], None), (None, vec![SLEEPS[0]], true), "the counter gave nothing"); + } + + /// A thread's counts as the kernel writes them: `levels` in the first + /// two bytes, six of padding, five u64 a level, the fifth its energy. + fn counts(levels: u16, energy_nj: &[u64]) -> Vec { + let mut bytes = vec![0u8; THREAD_COUNTS_BYTES]; + bytes[..2].copy_from_slice(&levels.to_ne_bytes()); + for (level, nj) in energy_nj.iter().enumerate() { + for (field, word) in [71u64, 72, 73, 74, *nj].into_iter().enumerate() { + let at = 8 + level * 40 + field * 8; + bytes[at..at + 8].copy_from_slice(&word.to_ne_bytes()); + } + } + bytes + } + + /// The energy is each level's fifth u64, summed, and a result of any + /// size but the header and one record a level is no count. + #[test] + fn a_threads_energy_is_read_only_from_the_layout_known() { + assert_eq!(THREAD_COUNTS_FLAVOR, 34); + assert_eq!(thread_energy_nj(&counts(2, &[2_500_000, 40]), 88), Some(2_500_040), "two levels, 88 bytes"); + assert_eq!(thread_energy_nj(&counts(1, &[9]), 48), Some(9)); + assert_eq!(thread_energy_nj(&counts(3, &[1, 20, 300]), 128), Some(321)); + assert_eq!(thread_energy_nj(&counts(2, &[u64::MAX, 2]), 88), Some(u64::MAX), "the sum saturates"); + let two = counts(2, &[2_500_000, 40]); + for (wrote, why) in [(-1, "the call failed"), (0, "nothing written"), (48, "one record"), (80, "short"), (96, "long")] { + assert_eq!(thread_energy_nj(&two, wrote), None, "{why}"); + } + assert_eq!(thread_energy_nj(&counts(0, &[]), 8), None, "no performance level"); + assert_eq!(thread_energy_nj(&counts(13, &[]), 8 + 13 * 40), None, "more levels than the buffer holds"); + assert_eq!(thread_energy_nj(&[2], 88), None, "no header"); + } + } +} + // --------------------------------------------------------------------------- // macOS — this process's CPU energy counter: `proc_pid_rusage(getpid(), // RUSAGE_INFO_V6)`, public libproc API, readable by an unprivileged process. @@ -2429,6 +2704,7 @@ mod probe_clock { #[cfg(target_os = "macos")] #[allow(unsafe_code)] mod macos_process { + use super::own_read; use std::os::raw::{c_int, c_void}; use std::sync::atomic::{AtomicBool, Ordering}; @@ -2503,6 +2779,14 @@ mod macos_process { /// ``: `int proc_pid_rusage(int pid, int flavor, /// rusage_info_t *buffer)`; 0 on success. fn proc_pid_rusage(pid: c_int, flavor: c_int, buffer: *mut c_void) -> c_int; + /// ``: `int proc_pidinfo(int pid, int flavor, uint64_t arg, + /// void *buffer, int buffersize)`; the bytes written, or 0 or less. + fn proc_pidinfo(pid: c_int, flavor: c_int, arg: u64, buffer: *mut c_void, buffersize: c_int) -> c_int; + /// ``: the calling thread. + fn pthread_self() -> *mut c_void; + /// ``: `int pthread_threadid_np(pthread_t thread, + /// uint64_t *thread_id)`; 0 on success. + fn pthread_threadid_np(thread: *mut c_void, thread_id: *mut u64) -> c_int; } /// Set by [`super::simulate_frozen_process_energy`]. @@ -2530,6 +2814,34 @@ mod macos_process { (rc == 0).then(|| unsafe { info.assume_init() }.ri_energy_nj) } + /// The calling thread's own cumulative CPU energy in nanojoules: the + /// count a window's read watches to see the thread leave its core. + /// `None` if the thread's id or its counts cannot be read, or the counts + /// come back in a layout [`own_read::thread_energy_nj`] does not know. + pub(super) fn thread_energy_nj() -> Option { + let pid = c_int::try_from(std::process::id()).ok()?; + let mut thread = 0u64; + // SAFETY: `thread` is a writable u64, and `pthread_self` is the + // calling thread, alive for the call. + if unsafe { pthread_threadid_np(pthread_self(), &mut thread) } != 0 { + return None; + } + let mut counts = [0u8; own_read::THREAD_COUNTS_BYTES]; + let size = c_int::try_from(counts.len()).ok()?; + // SAFETY: `counts` is writable for `size` bytes, which the call is + // given; the kernel writes plain integers and no more than that. + let wrote = unsafe { proc_pidinfo(pid, own_read::THREAD_COUNTS_FLAVOR, thread, counts.as_mut_ptr().cast(), size) }; + own_read::thread_energy_nj(&counts, wrote) + } + + /// The read the measurement takes at each end of its window: this + /// process's counter ([`energy_nj`]), read only once the calling thread + /// was seen to leave its core ([`own_read::window_read`]). `None` where + /// it was not, or the counter's read fails. + pub(super) fn window_read_nj() -> Option { + own_read::window_read(thread_energy_nj, std::thread::sleep, energy_nj) + } + #[cfg(test)] mod tests { use super::*; @@ -2595,6 +2907,21 @@ mod macos_process { } assert!(prod.windows(2).all(|w| w[1] > w[0]), "the production reads did not advance across 50 ms burns: {prod:?}"); } + + /// On this host the calling thread's own count reads, in the layout + /// known, and a window's read sees the thread leave its core: the + /// path both of the measurement's reads take. The read is this + /// process's counter, between two of the tests' own reads of it. + #[test] + fn a_window_read_sees_the_measuring_thread_leave_its_core_here() { + let thread = thread_energy_nj(); + eprintln!("process window read: this thread's own energy count: {thread:?} nJ"); + assert!(thread.is_some(), "this thread's own energy count does not read here"); + let lo = oracle_energy_nj(); + let v = window_read_nj().expect("the measuring thread was not seen to leave its core"); + let hi = oracle_energy_nj(); + assert!(lo <= v && v <= hi, "the window's read {v} is outside the oracle's [{lo}, {hi}]"); + } } } @@ -5148,6 +5475,46 @@ mod tests { assert_eq!(process_marginal_with(half_up, || Some(NJ3.load(Ordering::SeqCst)), Duration::from_millis(50)), Some(8)); } + /// A host on which the measuring thread's own energy count does not read + /// has no process counter: `Unavailable`, which never meters, and the + /// liveness probe is not run. Where the count reads, the status is the + /// probe's. + #[test] + fn process_no_counter_where_the_threads_own_count_does_not_read() { + let status = process_status_where(false, || panic!("probed a counter no window could be read on")); + assert_eq!(status, CounterStatus::Unavailable); + assert!(!admits_counter(status)); + for probed in [CounterStatus::Live, CounterStatus::Frozen, CounterStatus::Unavailable] { + assert_eq!(process_status_where(true, || probed), probed); + } + } + + /// The production window read on a thread never seen to leave its core + /// gives the measurement no figure, and the work never runs: the same + /// `None` an unreadable counter gives, never a window read from a count + /// that may lack what the thread spent. + #[test] + fn process_a_window_whose_thread_is_not_seen_to_leave_its_core_gives_no_figure() { + static CALLS: AtomicU64 = AtomicU64::new(0); + fn counted() { + CALLS.fetch_add(1, Ordering::SeqCst); + } + let read = Cell::new(0u32); + // The thread's count reads, and never moves; the counter would read. + let never_seen = || { + own_read::window_read( + || Some(7), + |_| {}, + || { + read.set(read.get() + 1); + Some(1_000_000) + }, + ) + }; + assert_eq!(process_marginal_with(counted, never_seen, Duration::from_millis(50)), None); + assert_eq!((CALLS.load(Ordering::SeqCst), read.get()), (0, 0), "the work ran, or the counter was read"); + } + /// No figure — never an invented one — from a counter that cannot be read /// (and then the work never runs) or that went down. #[test] diff --git a/proof/proof-rs/crates/proof-cascade/tests/process_energy_short_span.rs b/proof/proof-rs/crates/proof-cascade/tests/process_energy_short_span.rs new file mode 100644 index 000000000..f9cbf3087 --- /dev/null +++ b/proof/proof-rs/crates/proof-cascade/tests/process_energy_short_span.rs @@ -0,0 +1,188 @@ +//! Short spans on this process's CPU energy counter, bracketed by the read +//! the meter takes at each end of its window, against an oracle that takes +//! the reading thread off its core by a rule of its own. +//! +//! The kernel adds a thread's CPU energy to its process's count only when the +//! thread leaves its core. A process that reads its own count from a thread +//! still on its core reads a count that lacks what that thread spent since it +//! last left one: a window of a millisecond of the reading thread's work then +//! reads nothing, and a window opened straight after other work reads that +//! work as its own. +//! +//! One test binary with one test: the counter counts every thread of the +//! process, and the oracle's check is the process's context-switch count, so +//! nothing else may run here. No joule figure, joules per CPU-second or +//! timing is asserted: what a millisecond of CPU costs follows the core that +//! ran it, and a loaded host stretches everything's wall time. + +#![cfg(target_os = "macos")] + +use proof_cascade::meter::{meter_source, process_energy_status, process_window_read_nj, CounterStatus, MeterSource}; +use std::os::raw::{c_int, c_void}; +use std::time::{Duration, Instant}; + +unsafe extern "C" { + fn proc_pid_rusage(pid: c_int, flavor: c_int, buffer: *mut [u64; 58]) -> c_int; + fn proc_pidinfo(pid: c_int, flavor: c_int, arg: u64, buffer: *mut c_void, buffersize: c_int) -> c_int; + fn getpid() -> c_int; + fn clock_gettime_nsec_np(clock_id: u32) -> u64; +} + +/// This thread's CPU time (`CLOCK_THREAD_CPUTIME_ID` is 16 in ``). +fn thread_cpu() -> Duration { + // SAFETY: the call takes a clock id and returns a number. + Duration::from_nanos(unsafe { clock_gettime_nsec_np(16) }) +} + +/// Spin until this thread has used `d` of its own CPU time (or 20 s of wall +/// time have passed), however loaded the host is. +fn burn(d: Duration) { + let (started, wall) = (thread_cpu(), Instant::now()); + let mut acc = 0u64; + while thread_cpu() - started < d && wall.elapsed() < Duration::from_secs(20) { + for _ in 0..1_000 { + acc = std::hint::black_box(acc.wrapping_add(1)); + } + } +} + +/// The oracle's read of `ri_energy_nj`: `proc_pid_rusage(getpid(), 6)` into a +/// raw 464-byte buffer, the count at byte 336 (its 43rd `uint64_t`). +fn oracle_energy_nj() -> u64 { + let mut buf = [0u64; 58]; + // SAFETY: buf is 464 writable bytes, the size of rusage_info_v6. + let rc = unsafe { proc_pid_rusage(getpid(), 6, &mut buf) }; + assert_eq!(rc, 0, "the oracle's proc_pid_rusage(getpid(), 6) failed"); + buf[42] +} + +/// How many times this process's threads have been switched off a core: +/// `pti_csw`, the `int32_t` at byte 80 of the 96-byte `proc_taskinfo` that +/// `proc_pidinfo(getpid(), PROC_PIDTASKINFO = 4)` fills. +fn oracle_context_switches() -> i32 { + let mut info = [0i32; 24]; + // SAFETY: info is 96 writable bytes, the size the call is given. + let wrote = unsafe { proc_pidinfo(getpid(), 4, 0, info.as_mut_ptr().cast(), 96) }; + assert_eq!(wrote, 96, "the oracle's proc_pidinfo(PROC_PIDTASKINFO) wrote {wrote} bytes"); + info[20] +} + +/// The oracle's read of this process's energy once this thread has left its +/// core, by the oracle's own rule: a sleep of 1 ms, then 2, 4 and 8, until +/// the process's context-switch count rose across one. This test's thread is +/// the only one that runs here, so a rise is its own switch, and the read +/// after it holds all the thread spent before. The meter's read shares +/// neither call nor number with this. +fn oracle_energy_nj_off_core() -> u64 { + let left = [1, 2, 4, 8].into_iter().any(|ms| { + let before = oracle_context_switches(); + std::thread::sleep(Duration::from_millis(ms)); + oracle_context_switches() > before + }); + assert!(left, "the oracle never saw this thread leave its core across sleeps of 1, 2, 4 and 8 ms"); + oracle_energy_nj() +} + +/// The meter's window over what ran between its two reads: the counter's +/// advance in nJ, or `None` where a read gave nothing or the counter did not +/// advance — no reading, as the meter itself takes it. +fn window_nj(before: Option, after: Option) -> Option { + after?.checked_sub(before?).filter(|nj| *nj > 0) +} + +#[test] +fn a_short_window_reads_what_an_oracle_that_leaves_its_core_its_own_way_reads() { + const TRIES: usize = 40; + let (status, source) = (process_energy_status(), meter_source()); + eprintln!("process short window: status={status:?} source={source:?}"); + assert_eq!(status, CounterStatus::Live, "this process's CPU energy counter is not live here"); + assert_eq!(source, Some(MeterSource::ProcessEnergy), "a live process counter was not selected"); + + // 1. A millisecond of this thread's CPU between the meter's two reads. + // The oracle's window opens before the first and closes after the + // second, each end read once this thread has left its core, so it + // holds the burn and both readers' own reads and wake-ups. A window + // is the burn's when it is no more than the oracle's and at least two + // thirds of it: the readers' own cost does not shrink with the + // burn's. A reading above the oracle's is not this process's count. + let (mut shares, mut none, mut short, mut over) = (Vec::new(), 0usize, Vec::new(), Vec::new()); + for i in 0..TRIES { + let oracle_before = oracle_energy_nj_off_core(); + let before = process_window_read_nj(); + burn(Duration::from_millis(1)); + let after = process_window_read_nj(); + let oracle_nj = oracle_energy_nj_off_core() - oracle_before; + match window_nj(before, after) { + None => none += 1, + Some(nj) if nj > oracle_nj => over.push((i, nj, oracle_nj)), + Some(nj) if nj * 3 < oracle_nj * 2 => short.push((i, nj, oracle_nj)), + Some(nj) => shares.push(nj * 1_000 / oracle_nj.max(1)), + } + } + eprintln!( + "process short window: 1 ms burn x {TRIES}: {} read within the oracle's window (at least {}/1000 of it), \ + {none} not read, {} read short {short:?}, {} read over {over:?} (try, nJ, oracle nJ)", + shares.len(), + shares.iter().min().copied().unwrap_or(0), + short.len(), + over.len() + ); + + // 2. A 2 ms sleep between the two reads, straight after 8 ms of this + // thread's CPU that the window does not cover. The burn is still on + // the thread, not yet in the process's count, when the window opens; + // a first read that does not take the thread off its core leaves the + // burn to land inside the window. The oracle's window is the burn and + // the sleep: a reading for the sleep is under a quarter of it, or no + // reading at all. + let (mut slept, mut slept_none, mut leaked) = (Vec::new(), 0usize, Vec::new()); + for i in 0..TRIES { + let oracle_before = oracle_energy_nj_off_core(); + burn(Duration::from_millis(8)); + let before = process_window_read_nj(); + std::thread::sleep(Duration::from_millis(2)); + let after = process_window_read_nj(); + let oracle_nj = oracle_energy_nj_off_core() - oracle_before; + match window_nj(before, after) { + None => slept_none += 1, + Some(nj) if nj * 4 >= oracle_nj => leaked.push((i, nj, oracle_nj)), + Some(nj) => slept.push(nj * 1_000 / oracle_nj.max(1)), + } + } + eprintln!( + "process short window: 2 ms sleep after an 8 ms burn x {TRIES}: {} read under a quarter of the oracle's \ + window (at most {}/1000 of it), {slept_none} not read, {} read the burn before the window {leaked:?} (try, \ + nJ, oracle nJ)", + slept.len(), + slept.iter().max().copied().unwrap_or(0), + leaked.len() + ); + + // 3. What one read costs, in wall time: reported, never asserted. + let mut micros: Vec = (0..200) + .map(|_| { + let t = Instant::now(); + let _ = process_window_read_nj(); + t.elapsed().as_micros() + }) + .collect(); + micros.sort_unstable(); + eprintln!( + "process short window: one read costs {} us at the median, {} us at the 95th percentile, {} us at most (200 \ + reads)", + micros[100], micros[190], micros[199] + ); + + assert!(over.is_empty(), "a window read more than this process spent around it: {over:?}"); + // A tenth of the windows may miss the band: on a loaded host the + // oracle's own reads can land on a costlier core than the burn did, and + // a read whose thread was not seen to leave its core is no reading by + // design. A read that does not take the reading thread off its core + // misses on most windows (all 40, on a quiet host). + assert!( + (none + short.len()) * 10 <= TRIES, + "{none} of {TRIES} 1 ms windows were not read and {} were read short: {short:?}", + short.len() + ); + assert!(leaked.len() * 10 <= TRIES, "{} of {TRIES} sleeps read the burn before them: {leaked:?}", leaked.len()); +} diff --git a/proof/proof-rs/crates/proof-cli/src/main.rs b/proof/proof-rs/crates/proof-cli/src/main.rs index 1e7fe0347..fcf469202 100644 --- a/proof/proof-rs/crates/proof-cli/src/main.rs +++ b/proof/proof-rs/crates/proof-cli/src/main.rs @@ -287,7 +287,8 @@ fn process_reason() -> &'static str { use proof_cascade::meter::{process_energy_status, CounterStatus}; match process_energy_status() { CounterStatus::Unavailable => { - "this process's CPU energy counter (proc_pid_rusage, ri_energy_nj) could not be read" + "this process's CPU energy counter (proc_pid_rusage, ri_energy_nj) could not be read, or the measuring \ + thread's own energy count, which each of its reads is checked against, could not" } CounterStatus::Absent => "this process's CPU energy counter is absent", CounterStatus::Frozen => { -- 2.54.0 (Apple Git-157) From ac93d9e56e74ad9b7a862e3a295f05787635249c Mon Sep 17 00:00:00 2001 From: Transaction Science Date: Tue, 13 Oct 2026 00:54:51 -0400 Subject: [PATCH 5/5] eoc annex: the per-process counter's lumps are the kernel's fold, and a checked read is exact The annex reported that the macOS per-process energy counter "accrues in lumps" under sub-millisecond sampling, and left it there. The mechanism is now established: a thread's energy is added to its process's count when the thread leaves its core, so a reader on a running thread sees nothing until its quantum ends. A reader that first leaves its core and checks its own thread's count moved reads 1 ms spans to within a few percent of an independent read, where unchecked it read none of them on an idle host. Say so beside the measured figures, which stand. Co-Authored-By: Claude Opus 5.5 --- eoc/standards/sci-for-ai-energy-provenance-annex.md | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/eoc/standards/sci-for-ai-energy-provenance-annex.md b/eoc/standards/sci-for-ai-energy-provenance-annex.md index 62470e7e6..2191c07aa 100644 --- a/eoc/standards/sci-for-ai-energy-provenance-annex.md +++ b/eoc/standards/sci-for-ai-energy-provenance-annex.md @@ -74,6 +74,14 @@ at all, the median step was ~20 mJ, two orders above the 1 ms step. It accrues in lumps. A sampler reading it every 500 µs would see nothing most of the time and a 20 mJ jump occasionally, and would report both as measurements. +The lumps are the kernel's bookkeeping, not the hardware's. A thread's energy is +added to its process's count when the thread leaves its core, so a reader on a +running thread sees nothing until that thread's scheduling quantum ends, and then +sees all of it at once. A reader that first leaves its core, and checks that its +own thread's count moved across that pause, reads the same 1 ms spans to within a +few percent of an independent read; unchecked, on an idle host, it read none of +them. The counter is exact; an unchecked read of it is not. + ## c. Proposed requirements An `E` figure claiming to be **measured** MUST carry: -- 2.54.0 (Apple Git-157)