//! This process's own GPU energy counter on real hardware, asserted in a process //! of its own against oracles the test reads itself. //! //! The oracles take independent paths to the counter's two sources: the GPU //! rail through this file's own IOReport calls, and every client's GPU time //! through `ioreg -r -c IOAccelerator -l` (another process, parsing its text). //! A third is the test's own Metal command buffers' GPU start and end times. //! The GPU is shared with whatever else the host runs, which opens, closes and //! resets GPU clients at any moment, so every assertion holds under contention //! and that churn. Each span of this process's GPU work that the test checks //! against the oracle or through the span meter (steps 2, 4b, 4c and 6) has the //! registry listed before it, around its work and after it, and every client of //! the counter's two snapshots is sorted against those listings ([`classify`]). //! A client two reads list is in every read between, under one pid. A refusal //! is corroborated by the independent read: the client the counter saw vanish //! is one the registry listed under the same pid (gone), or whose fall it shows //! inside the span (gone back), and the refusal names the one the meter's rule //! picks. The counter agrees with the oracle's reads inside its span, over the //! clients present at both ends: on this process's GPU time exactly, and on the //! others' to within what the GPU can accrue in the gap between them. A reading //! of this process's own client that the registry contradicts fails the test at //! once. A span the registry cannot vouch for (a vanished client it never //! listed, a reading of another process's client out of its order that no fall //! it saw explains) is taken again later, and none in 90 s is INCONCLUSIVE, //! which fails the test as any other assertion does. //! //! One test function, its checks in sequence on one thread; it also serves as //! the GPU-burning child process the contention and vanished-client checks //! spawn (run with `JOULECLAW_GPU_BURN_CHILD` set, it burns and returns). Off //! macOS, or without `ioreport`, it is not compiled; the crate's unit tests //! assert that the counter is unavailable there. #![cfg(all(target_os = "macos", feature = "ioreport"))] use std::collections::{BTreeMap, BTreeSet}; use std::ffi::{c_char, c_long, c_void}; use std::io::{BufRead, BufReader}; use std::process::{Child, Command, Stdio}; use std::ptr::NonNull; use std::time::{Duration, Instant}; use jouleclaw_energy::process_gpu::{ gpu_rail_liveness_cached, probe_gpu_liveness_uncached, GpuClient, GpuShare, GpuSnapshot, ProcessGpuCounter, }; use jouleclaw_energy::span::{ProcessSpanMeter, SpanEnergy, SpanSource, SpanUses}; use jouleclaw_energy::{CounterLiveness, Coverage, EnergyDomain, EnergyError, Provenance}; use objc2::rc::Retained; use objc2::runtime::ProtocolObject; use objc2_foundation::NSString; use objc2_metal::{ MTLBuffer, MTLCommandBuffer, MTLCommandEncoder, MTLCommandQueue, MTLComputeCommandEncoder, MTLComputePipelineState, MTLCreateSystemDefaultDevice, MTLDevice, MTLLibrary, MTLResourceOptions, MTLSize, }; const CHILD_ENV: &str = "JOULECLAW_GPU_BURN_CHILD"; const READY: &str = "GPU-BURN-CHILD-READY"; /// How long a check takes spans again while the registry cannot vouch for /// them, before it gives up INCONCLUSIVE. const BUDGET: Duration = Duration::from_secs(90); // ── The GPU load: the test's own Metal ────────────────────────────────────── const BURN_MSL: &str = "#include \nusing namespace metal;\n\ kernel void burn(device float *b [[buffer(0)]], constant uint &n [[buffer(1)]], uint i [[thread_position_in_grid]]) {\n\ float x = b[i]; for (uint k = 0; k < n; k++) { x = fma(x, 1.0000001f, 0.0000001f); } b[i] = x; }\n"; const THREADS: usize = 1 << 20; /// A compute kernel that keeps the GPU busy, one command buffer at a time. struct Burner { queue: Retained>, pso: Retained>, buf: Retained>, iters: u32, } impl Burner { /// Compile the kernel, then size one command buffer to about 8 ms of GPU /// time. fn new() -> Self { let device = MTLCreateSystemDefaultDevice().expect("a Metal device"); let lib = device.newLibraryWithSource_options_error(&NSString::from_str(BURN_MSL), None).expect("compile"); let f = lib.newFunctionWithName(&NSString::from_str("burn")).expect("the kernel"); let pso = device.newComputePipelineStateWithFunction_error(&f).expect("a pipeline"); let buf = device.newBufferWithLength_options(THREADS * 4, MTLResourceOptions::StorageModeShared).expect("a buffer"); let queue = device.newCommandQueue().expect("a queue"); let mut b = Self { queue, pso, buf, iters: 64 }; let t = (0..3).map(|_| b.dispatch()).fold(f64::MAX, f64::min).max(1e-5); b.iters = ((64.0 * 0.008 / t) as u32).clamp(64, 1 << 20); b } /// One command buffer, committed and waited on: its GPU time (end minus /// start on the GPU's clock), in seconds. fn dispatch(&self) -> f64 { let cb = self.queue.commandBuffer().expect("a command buffer"); let enc = cb.computeCommandEncoder().expect("an encoder"); enc.setComputePipelineState(&self.pso); // SAFETY: buffer 0 is THREADS floats, buffer 1 one u32, as the kernel // declares; `iters` outlives the call, which copies it. unsafe { enc.setBuffer_offset_atIndex(Some(&self.buf), 0, 0); enc.setBytes_length_atIndex(NonNull::from(&self.iters).cast(), 4, 1); } let tg = self.pso.maxTotalThreadsPerThreadgroup().min(THREADS); enc.dispatchThreads_threadsPerThreadgroup( MTLSize { width: THREADS, height: 1, depth: 1 }, MTLSize { width: tg, height: 1, depth: 1 }, ); enc.endEncoding(); cb.commit(); cb.waitUntilCompleted(); cb.GPUEndTime() - cb.GPUStartTime() } /// Dispatch until `gpu` of command-buffer GPU time has run, or `wall` has /// passed: the GPU time run, in seconds. fn burn(&self, gpu: Duration, wall: Duration) -> f64 { self.burn_counted(gpu, wall).0 } /// [`Self::burn`], and how many command buffers it took. fn burn_counted(&self, gpu: Duration, wall: Duration) -> (f64, u32) { let t = Instant::now(); let (mut ran, mut n) = (0.0, 0); while ran < gpu.as_secs_f64() && t.elapsed() < wall { ran += self.dispatch(); n += 1; } (ran, n) } } /// The liveness probe's load: about 25 ms of this process's GPU time. fn gpu_tick(b: &Burner) { b.burn(Duration::from_millis(25), Duration::from_millis(500)); } /// A CPU load of about 25 ms of this thread's CPU time. fn cpu_tick() { let t = Instant::now(); let mut x = 1u64; while t.elapsed() < Duration::from_millis(25) { for _ in 0..10_000 { x = std::hint::black_box(x.wrapping_mul(6_364_136_223_846_793_005).wrapping_add(1)); } } } // ── Oracle 1: the GPU rail, through this file's own IOReport calls ───────── type CFRef = *const c_void; unsafe extern "C" { fn IOReportCopyChannelsInGroup(g: CFRef, sg: CFRef, a: u64, b: u64, c: u64) -> *mut c_void; fn IOReportCreateSubscription(a: CFRef, ch: *mut c_void, out: *mut *mut c_void, id: u64, o: CFRef) -> CFRef; fn IOReportCreateSamples(sub: CFRef, ch: *mut c_void, o: CFRef) -> CFRef; fn IOReportChannelGetChannelName(item: CFRef) -> CFRef; fn IOReportChannelGetUnitLabel(item: CFRef) -> CFRef; fn IOReportSimpleGetIntegerValue(item: CFRef, i: i32) -> i64; fn CFStringCreateWithCString(a: *mut c_void, s: *const c_char, enc: u32) -> CFRef; fn CFStringGetCString(s: CFRef, buf: *mut c_char, n: c_long, enc: u32) -> bool; fn CFDictionaryGetValue(d: CFRef, k: CFRef) -> CFRef; fn CFArrayGetCount(a: CFRef) -> c_long; fn CFArrayGetValueAtIndex(a: CFRef, i: c_long) -> CFRef; fn CFRelease(r: CFRef); } #[link(name = "IOReport", kind = "dylib")] #[link(name = "CoreFoundation", kind = "framework")] unsafe extern "C" {} fn cf_text(s: CFRef) -> String { let mut buf = [0 as c_char; 256]; // SAFETY: `s` is a live CFString or null (then nothing is read). if s.is_null() || !unsafe { CFStringGetCString(s, buf.as_mut_ptr(), 256, 0x0800_0100) } { return String::new(); } // SAFETY: on success the buffer holds a NUL-terminated string. unsafe { std::ffi::CStr::from_ptr(buf.as_ptr()) }.to_string_lossy().into_owned() } /// The test's own subscription to the `Energy Model` group. struct OracleRail { sub: CFRef, channels: *mut c_void, } impl OracleRail { fn open() -> Self { // SAFETY: the IOReport calls `ioreg`/`powermetrics` make; every object // is kept for the test's life or released. unsafe { let group = CFStringCreateWithCString(std::ptr::null_mut(), c"Energy Model".as_ptr(), 0x0800_0100); let wanted = IOReportCopyChannelsInGroup(group, std::ptr::null(), 0, 0, 0); let mut channels: *mut c_void = std::ptr::null_mut(); let sub = IOReportCreateSubscription(std::ptr::null(), wanted, &mut channels, 0, std::ptr::null()); assert!(!sub.is_null() && !channels.is_null(), "the oracle's Energy Model subscription"); Self { sub, channels } } } /// The `GPU Energy` channel's absolute value, in nJ (it is the only unit it /// has been seen in; anything else fails the test). fn gpu_nj(&self) -> u64 { // SAFETY: a live subscription; the sample is released. unsafe { let s = IOReportCreateSamples(self.sub, self.channels, std::ptr::null()); assert!(!s.is_null(), "the oracle's sample"); let key = CFStringCreateWithCString(std::ptr::null_mut(), c"IOReportChannels".as_ptr(), 0x0800_0100); let arr = CFDictionaryGetValue(s, key); CFRelease(key); let mut found = None; for i in 0..CFArrayGetCount(arr) { let ch = CFArrayGetValueAtIndex(arr, i); if cf_text(IOReportChannelGetChannelName(ch)) == "GPU Energy" { assert_eq!(cf_text(IOReportChannelGetUnitLabel(ch)), "nJ", "the GPU rail's unit"); found = Some(IOReportSimpleGetIntegerValue(ch, 0) as u64); } } CFRelease(s); found.expect("a GPU Energy channel") } } } // ── Oracle 2: every client's GPU time, from `ioreg`'s text ───────────────── /// Every GPU client `ioreg` lists: registry id → (pid, summed /// `accumulatedGPUTime` ns). fn ioreg_clients() -> BTreeMap { let out = Command::new("/usr/sbin/ioreg").args(["-r", "-c", "IOAccelerator", "-l", "-w0"]).output().expect("ioreg"); assert!(out.status.success(), "ioreg failed"); let text = String::from_utf8_lossy(&out.stdout); let mut clients = BTreeMap::new(); for block in text.split("+-o ").skip(1) { let Some(creator) = block.split("\"IOUserClientCreator\" = \"pid ").nth(1) else { continue }; let pid: i32 = creator.split(',').next().unwrap().trim().parse().expect("a pid"); let id_hex = block.split(", id 0x").nth(1).and_then(|s| s.split(',').next()).expect("an entry id"); let id = u64::from_str_radix(id_hex, 16).expect("a hex id"); let ns: u64 = block .lines() .find(|l| l.contains("\"AppUsage\" = ")) .map(|l| { l.split("\"accumulatedGPUTime\"=").skip(1).map(|s| { s.chars().take_while(char::is_ascii_digit).collect::().parse::().expect("a time") }).sum() }) .unwrap_or(0); clients.insert(id, (pid, ns)); } assert!(!clients.is_empty(), "ioreg listed no GPU client"); clients } /// One `ioreg` listing of every GPU client, with when `ioreg` was started and /// when it had finished: its readings lie between. #[derive(Debug, Clone)] struct Listing { clients: BTreeMap, from: Instant, to: Instant, } fn listing() -> Listing { let from = Instant::now(); let clients = ioreg_clients(); Listing { clients, from, to: Instant::now() } } /// One oracle reading: the rail, then every client. struct Oracle { rail_nj: u64, /// When the rail was read: on its first change after the oracle began /// watching it, so the reading is current (the rail can hold for hundreds /// of milliseconds and then catch up in one step). rail_at: Instant, list: Listing, } fn oracle(rail: &OracleRail) -> Oracle { // The rail on its next change; or, if it holds while `ioreg` shows no // client accruing GPU time between two of its listings, as it stands (an // idle GPU has next to nothing to publish). let first = rail.gpu_nj(); let waited = Instant::now(); let mut listed: Option<(Instant, u64)> = None; let rail_nj = loop { std::thread::sleep(Duration::from_millis(1)); let now = rail.gpu_nj(); if now != first { break now; } if waited.elapsed() >= Duration::from_millis(150) { let total: u64 = ioreg_clients().values().map(|c| c.1).sum(); match listed { Some((at, before)) if at.elapsed() >= Duration::from_millis(100) && before == total => break rail.gpu_nj(), Some((at, _)) if at.elapsed() < Duration::from_millis(100) => {} _ => listed = Some((Instant::now(), total)), } } assert!(waited.elapsed() < Duration::from_secs(3), "the oracle's GPU rail held for 3 s while the GPU was busy"); }; let rail_at = Instant::now(); Oracle { rail_nj, rail_at, list: listing() } } /// The GPU time `pid`'s own clients ran between two listings, and nothing /// else: a client in both its advance, one new in the second its whole time. /// Another process's client being destroyed, or going back, says nothing /// about this pid's clients and does not take the figure away; only one of /// this pid's own going back makes it unavailable. fn oracle_pid_time(a: &Listing, b: &Listing, pid: i32) -> Option { let mut me = 0u64; for (id, (p, ns)) in &b.clients { if *p != pid { continue; } me += ns.checked_sub(a.clients.get(id).map_or(0, |c| c.1))?; } Some(me) } // ── Sorting a span's clients against the registry ────────────────────────── /// A span's six reads of the GPU clients, in the order they are taken. const READ: [&str; 6] = [ "ioreg before the span", "the counter's start snapshot", "ioreg as the work started", "ioreg as the work ended", "the counter's end snapshot", "ioreg after the span", ]; /// The counter's two reads among [`READ`]; the other four are `ioreg`'s. const START: usize = 1; const END: usize = 4; const IOREG: [usize; 4] = [0, 2, 3, 5]; /// A span's clients sorted against the registry's own listings ([`classify`]). #[derive(Debug, Default, PartialEq, Eq)] struct Sorted { /// The start snapshot's clients the counter saw vanish (gone from its end /// snapshot, or their time gone back there), each one the registry /// corroborates. Any one refuses a span this process used the GPU in; the /// view takes them out of both snapshots. vanished: BTreeSet, /// The clients whose time went down nowhere from the counter's start to /// its end, there at both ends or new at the end. clean: BTreeSet, /// GPU time inside the span that the counter's two snapshots cannot hold, /// ns, a lower bound: each client only the oracle listed (made and /// destroyed inside the span: the most it listed), and each fall only the /// registry listed inside the span, of a client the counter saw advance /// (a queue of it closed, and its whole time went with it, of which the /// fall is a part). hidden_ns: u64, /// What `hidden_ns` holds, for the log. hidden: Vec, } /// Why the registry cannot vouch for a span: it is taken again later. #[derive(Debug, PartialEq, Eq)] struct Void { kind: &'static str, detail: String, } impl std::fmt::Display for Void { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { write!(f, "{}: {}", self.kind, self.detail) } } const OWN_NOT_CLEAN: &str = "a client of this process's vanished, went back or was hidden"; const UNCORROBORATED: &str = "a vanished client the registry never listed"; const OUT_OF_ORDER: &str = "a counter reading out of the registry's order"; /// Sort every client of a span against the registry's own listings. The reads /// are in the order taken ([`READ`]): `ioreg` `before`, the counter's start /// `s`, `ioreg` `o0` and `o1` around the work, the counter's end `e`, `ioreg` /// `after`. Pure. `Err` is a contradiction, which fails the test; `Ok(Err)` a /// span the registry cannot vouch for, which is taken again. /// /// A registry entry once destroyed never comes back and its ID is not reused, /// so a client is listed by one unbroken stretch of the reads: one that two /// reads list is in every read between them, under one pid. Its instances: a /// client `ioreg` lists before the counter's start and after it is in the /// start snapshot; one `ioreg` lists after the counter's end and before it is /// in the end snapshot; one in both snapshots is in both of `ioreg`'s listings /// around the work; one gone between those is not in the end snapshot. /// /// A client's time never goes down, but where a queue of it closed; then the /// registry's own listings show the fall, if it fell past what accrued between /// them. So each counter reading lies between the `ioreg` listings either side /// of it, or on one side of a fall they show across it, which tells whether /// the fall came before the reading or after it. Anything else is a reading the /// registry does not explain: under-read, over-read, or two falls in one gap. /// For another process's client that voids the span (a queue of it can close /// and the client accrue again within one gap, which looks the same). This /// process does no GPU work between the counter's reads and the listings either /// side of them, so a correct read of one of its own clients equals those /// listings, or one side of a fall of it they show: a reading of its own that /// they do not explain, where they show no fall across it, is a contradiction. /// /// The classes, over the counter's span: clean, its time down nowhere from the /// start to the end; vanished, in the start and gone from the end (vouched for /// if `ioreg` listed it before the span or inside it), or lower at the end /// than at the start (vouched for by the fall the registry shows inside the /// span); hidden, a fall the registry shows inside the span where the counter /// saw an advance, or a client only `ioreg` listed inside the span. Any class /// but clean for one of this process's own clients is void: its own GPU time /// is what the test checks exactly. fn classify( before: &Listing, s: &GpuSnapshot, o0: &Listing, o1: &Listing, e: &GpuSnapshot, after: &Listing, me: i32, ) -> Result, String> { let by_id = |snap: &GpuSnapshot| -> BTreeMap { snap.clients.iter().map(|c| (c.id, (c.pid, c.gpu_ns))).collect() }; let (sm, em) = (by_id(s), by_id(e)); let reads: [&BTreeMap; 6] = [&before.clients, &sm, &o0.clients, &o1.clients, &em, &after.clients]; let ids: BTreeSet = reads.iter().flat_map(|r| r.keys().copied()).collect(); let mut sorted = Sorted::default(); let mut voids = Vec::new(); for id in ids { let at: [Option<(i32, u64)>; 6] = std::array::from_fn(|k| reads[k].get(&id).copied()); let listed: Vec = (0..6).filter(|&k| at[k].is_some()).collect(); let (first, last) = (listed[0], listed[listed.len() - 1]); let pid = at[first].map_or(0, |c| c.0); if let Some(k) = listed.iter().copied().find(|&k| at[k].is_some_and(|c| c.0 != pid)) { return Err(format!("client {id:#x} is pid {pid} in {} and pid {} in {}", READ[first], at[k].map_or(0, |c| c.0), READ[k])); } if let Some(k) = (first..=last).find(|&k| at[k].is_none()) { return Err(format!( "client {id:#x} of pid {pid} is in {} and in {}, but not in {} between them: an entry once destroyed never comes back, so that read left out a client that was there", READ[first], READ[last], READ[k] )); } let ns = |k: usize| at[k].map(|c| c.1); let near = |k: usize, earlier: bool| -> Option { let listed = |i: &usize| at[*i].is_some(); let i = if earlier { IOREG.iter().copied().filter(|&i| i < k).rev().find(listed) } else { IOREG.iter().copied().filter(|&i| i > k).find(listed) }; i.and_then(ns) }; // Each counter reading against the `ioreg` listings either side of it. // Where those show a fall across it, whether the fall came after it. let mine = pid == me; let mut misfit = None; let mut fall_after = [false; 6]; for k in [START, END] { let Some(c) = ns(k) else { continue }; let (p, n) = (near(k, true), near(k, false)); let (fits, fell) = match (p, n) { (Some(p), Some(n)) if n < p => { fall_after[k] = c >= p; (c >= p || c <= n, true) } (p, n) => (p.is_none_or(|p| p <= c) && n.is_none_or(|n| c <= n), false), }; if fits { continue; } if mine && !fell { return Err(format!( "client {id:#x} of this process: {} read {c} ns, the registry {p:?} ns before it and {n:?} ns after it: the counter misread this process's GPU time", READ[k] )); } misfit = Some(format!("client {id:#x} of pid {pid}: {} read {c} ns, the registry {p:?} ns before it and {n:?} ns after it", READ[k])); } if let Some(detail) = misfit { voids.push(Void { kind: if mine { OWN_NOT_CLEAN } else { OUT_OF_ORDER }, detail }); continue; } // The falls the registry shows inside the counter's span: across the // start snapshot when after it, between the listings around the work, // across the end snapshot when before it. let fall = |i: usize, j: usize| match (ns(i), ns(j)) { (Some(a), Some(b)) if b < a => a - b, _ => 0, }; let across_start = if fall_after[START] { fall(0, 2) } else { 0 }; let across_end = if at[END].is_some() && !fall_after[END] { fall(3, 5) } else { 0 }; let inside = across_start + fall(2, 3) + across_end; let own = |what: &str| Void { kind: OWN_NOT_CLEAN, detail: format!("client {id:#x} of pid {pid} {what}") }; match (ns(START), ns(END)) { (Some(a), Some(b)) if b < a => { if mine { voids.push(own(&format!("went back from {a} to {b} ns"))); } else if inside == 0 { voids.push(Void { kind: OUT_OF_ORDER, detail: format!("client {id:#x} of pid {pid} went back from {a} to {b} ns, and the registry shows no fall inside the span") }); } else { sorted.vanished.insert(id); } } (Some(_), None) => { if mine { voids.push(own("is gone")); } else if [0, 2, 3].iter().any(|&k| at[k].is_some()) { sorted.vanished.insert(id); } else { voids.push(Void { kind: UNCORROBORATED, detail: format!("client {id:#x} of pid {pid}, gone from the counter's end snapshot, is in no `ioreg` listing") }); } } (_, Some(_)) => { if inside == 0 { sorted.clean.insert(id); } else if mine { voids.push(own(&format!("fell {inside} ns inside the span"))); } else { sorted.hidden_ns += inside; sorted.hidden.push(format!("{id:#x} of pid {pid}: a fall of {inside} ns the counter saw an advance across")); } } (None, None) => { // Only `ioreg` listed it inside the span (a client listed // before the span or after it and nowhere else lies outside // it): made and destroyed there, and hidden from both // snapshots. if let Some(t) = ns(2).max(ns(3)) { if mine { voids.push(own("was made and destroyed inside the span")); } else { sorted.hidden_ns += t; sorted.hidden.push(format!("{id:#x} of pid {pid}: made and destroyed inside the span, {t} ns as listed")); } } } } } Ok(match voids.into_iter().next() { Some(void) => Err(void), None => Ok(sorted), }) } /// Whether a client in a span's start snapshot vanished by its end `e`: gone /// from it, or its time went back there. fn vanished(c: &GpuClient, e: &GpuSnapshot) -> bool { e.clients.iter().find(|x| x.id == c.id).is_none_or(|x| x.gpu_ns < c.gpu_ns) } /// The vanished client a refusal over `s` and `e` names, by the meter's rule: /// this process's own first, else the oldest (the least registry ID). fn expected_refusal(s: &GpuSnapshot, e: &GpuSnapshot, me: i32) -> Option<(i32, u64)> { let by_age = |mine: bool| { let mut v: Vec<&GpuClient> = s.clients.iter().filter(|c| (c.pid == me) == mine).collect(); v.sort_unstable_by_key(|c| c.id); v }; by_age(true).into_iter().chain(by_age(false)).find(|c| vanished(c, e)).map(|c| (c.pid, c.id)) } /// Whether a refusal's named client really vanished over the span: it is in /// the start snapshot under the named pid, and gone from the end or gone back /// there. fn names_a_vanished_client(s: &GpuSnapshot, e: &GpuSnapshot, pid: i32, client: u64) -> Result<(), String> { let named = s.clients.iter().find(|c| c.id == client && c.pid == pid).ok_or("it named a client not at the start")?; if !vanished(named, e) { return Err("it named a client still there and not reset".to_string()); } Ok(()) } /// [`names_a_vanished_client`], failing the test with `what` if not. fn assert_names_a_vanished_client(what: &str, s: &GpuSnapshot, e: &GpuSnapshot, pid: i32, client: u64) { if let Err(x) = names_a_vanished_client(s, e, pid, client) { panic!("{what}: {x}"); } } /// Whether what the counter made of a span, for process `me`, is the /// registry's sorting of it: a refusal exactly when the registry vouches for a /// vanished client, naming the one the meter's rule picks. Every span checked /// here is one this process used the GPU in, where any vanished client refuses /// the figure. fn refusal_is_the_registrys(s: &GpuSnapshot, e: &GpuSnapshot, sorted: &Sorted, real: &Result, me: i32) -> Result<(), String> { if sorted.vanished.is_empty() { return match real { Err(EnergyError::GpuClientVanished { .. }) => Err(format!("refused, though no client vanished: {real:?}")), _ => Ok(()), }; } let ids: Vec = sorted.vanished.iter().map(|id| format!("{id:#x}")).collect(); match real { Err(EnergyError::GpuClientVanished { pid, client }) => { let rule = expected_refusal(s, e, me); if rule != Some((*pid, *client)) { return Err(format!( "it named client {client:#x} of pid {pid}: not the vanished client the meter's rule names, this process's own first, else the oldest, {rule:?}" )); } names_a_vanished_client(s, e, *pid, *client) } other => Err(format!("the registry vouches for {} vanished client(s) ({}), but the counter gave {other:?}", ids.len(), ids.join(", "))), } } /// A snapshot without the clients `ids`. fn without(snap: &GpuSnapshot, ids: &BTreeSet) -> GpuSnapshot { GpuSnapshot { clients: snap.clients.iter().filter(|c| !ids.contains(&c.id)).copied().collect(), ..snap.clone() } } /// Whether `self_ns` is a sole user's share — at least 99% — of every client's /// GPU time, the `all_ns` the counter saw and the `hidden_ns` it could not. fn sole_with_hidden(self_ns: u64, all_ns: u64, hidden_ns: u64) -> bool { u128::from(self_ns) * 100 >= (u128::from(all_ns) + u128::from(hidden_ns)) * 99 } /// Take spans with `attempt` until the registry vouches for one ([`classify`], /// which `attempt` runs over its reads): a void span is taken again after 0.5, /// 1, 2, 4, 8, 8, … s, for at most `budget`, and none by then is INCONCLUSIVE, /// which fails the test. A contradiction fails it at once. The span vouched for /// is logged with its attempt and the void spans before it, by kind, so a /// rising rate of voids shows in CI's logs. fn until_sorted(what: &str, budget: Duration, mut attempt: impl FnMut() -> (T, Result, String>)) -> (T, Sorted) { let t = Instant::now(); let mut kinds: BTreeMap<&'static str, u32> = BTreeMap::new(); let counts = |kinds: &BTreeMap<&'static str, u32>| kinds.iter().map(|(k, n)| format!("{k} ×{n}")).collect::>().join(", "); let mut wait = Duration::from_millis(500); let mut n = 0; loop { n += 1; let (took, sorted) = attempt(); let void = match sorted { Err(wrong) => panic!("{what}: {wrong}"), Ok(Ok(sorted)) => { println!("process-gpu: {what}: vouched on attempt {n}; voids: {}", if kinds.is_empty() { "none".to_string() } else { counts(&kinds) }); return (took, sorted); } Ok(Err(void)) => void, }; *kinds.entry(void.kind).or_default() += 1; let left = budget.saturating_sub(t.elapsed()); if left.is_zero() { panic!( "process-gpu INCONCLUSIVE: {what}: no span in {} s ({n} spans) could be checked against the oracle: {}; host GPU-client churn or uncorroborated refusals, not a verdict, and not a pass", t.elapsed().as_secs(), counts(&kinds) ); } let pause = wait.min(left); println!("process-gpu: {what}: attempt {n} at {:.1} s: void: {void}; again in {:.1} s", t.elapsed().as_secs_f64(), pause.as_secs_f64()); std::thread::sleep(pause); wait = (wait * 2).min(Duration::from_secs(8)); } } /// One line for what a span came to, and what its sorting set aside. fn verdict(what: &str, real: &Result, sorted: &Sorted) { let v = match real { Ok(_) => "figure".to_string(), Err(EnergyError::GpuShared { .. }) => "shared".to_string(), Err(EnergyError::GpuClientVanished { .. }) => format!("vanished({})", sorted.vanished.len()), Err(x) => format!("no figure ({x})"), }; let ids: Vec = sorted.vanished.iter().map(|id| format!("{id:#x}")).collect(); println!( "process-gpu: {what}: verdict {v}; excluded [{}]; hidden {:.3} ms{}{}", ids.join(", "), ms(sorted.hidden_ns), if sorted.hidden.is_empty() { "" } else { ": " }, sorted.hidden.join("; ") ); } // ── A GPU-burning child process ───────────────────────────────────────────── /// A burner child, killed and reaped when dropped: std's `Child` is neither, /// and a check that failed while one burned would otherwise leave it burning /// the shared host's GPU for the rest of its life. struct Burning(Child); impl Burning { fn pid(&self) -> i32 { self.0.id() as i32 } /// Fail INCONCLUSIVE if the child has exited: `what`'s span, taken to be /// contended, may not have been. fn assert_burning(&mut self, what: &str) { if let Some(status) = self.0.try_wait().expect("poll the child") { panic!("process-gpu INCONCLUSIVE: {what}: the contending child exited ({status}) while its spans were taken: not a verdict, and not a pass"); } } } impl Drop for Burning { fn drop(&mut self) { let _ = self.0.kill(); let _ = self.0.wait(); } } /// This test binary again, as a child that burns the GPU for `secs`, or until /// this process is gone, and says so once its first command buffer has run. fn spawn_burner(secs: u32) -> Burning { let mut child = Burning( Command::new(std::env::current_exe().expect("this test binary")) .args(["--exact", "a_gpu_span_is_a_sole_users_rail_or_an_exact_zero_or_no_figure", "--nocapture", "--test-threads=1"]) .env(CHILD_ENV, secs.to_string()) .stdout(Stdio::piped()) .stderr(Stdio::null()) .spawn() .expect("spawn the burner child"), ); let mut lines = BufReader::new(child.0.stdout.take().expect("its stdout")).lines(); loop { let line = lines.next().expect("the child exited before it was ready").expect("its stdout"); // libtest prints the test's name on the same line, before it. if line.contains(READY) { break; } } child } /// Kill and reap a child, then wait until `ioreg` no longer lists any client /// of its pid. fn kill_and_await_gone(mut child: Burning) { let pid = child.pid(); child.0.kill().expect("kill the child"); child.0.wait().expect("reap the child"); drop(child); let t = Instant::now(); while ioreg_clients().values().any(|(p, _)| *p == pid) { assert!(t.elapsed() < Duration::from_secs(5), "the dead child's GPU client is still listed"); std::thread::sleep(Duration::from_millis(50)); } } /// Wait, at most 3 s, until two `ioreg` listings 100 ms apart show the same /// set of this process's GPU clients, none lower than in the one before: the /// liveness askers' Metal objects are gone, and their clients with them. It /// never fails: a span over a client of this process's that is still going is /// void ([`classify`]) and taken again. fn settle_own_clients() { let me = std::process::id() as i32; let own = |l: &Listing| -> BTreeMap { l.clients.iter().filter(|(_, (p, _))| *p == me).map(|(id, (_, ns))| (*id, *ns)).collect() }; let t = Instant::now(); let mut prev = own(&listing()); loop { std::thread::sleep(Duration::from_millis(100)); let now = own(&listing()); if prev.keys().eq(now.keys()) && now.iter().all(|(id, ns)| prev.get(id).is_none_or(|p| ns >= p)) { return; } if t.elapsed() >= Duration::from_secs(3) { println!("process-gpu: this process's GPU clients did not settle in 3 s: {now:?}"); return; } prev = now; } } // ── The checks ────────────────────────────────────────────────────────────── /// The counter's span over `work`, bracketing the oracle's own readings: the /// counter's start snapshot, the oracle, the work, the oracle, the counter's /// end snapshot. fn bracketed(counter: &ProcessGpuCounter, rail: &OracleRail, work: impl FnOnce()) -> (GpuSnapshot, Oracle, Oracle, GpuSnapshot) { let s = counter.snapshot().expect("a start snapshot"); let o0 = oracle(rail); work(); let o1 = oracle(rail); let e = counter.snapshot().expect("an end snapshot"); (s, o0, o1, e) } /// A span of the counter's that the registry vouches for, the oracle's /// readings inside it, and what the counter made of it: `real` over its two /// snapshots as taken, `view` over them with the vanished clients taken out of /// both. struct Checked { s: GpuSnapshot, e: GpuSnapshot, o0: Oracle, o1: Oracle, sorted: Sorted, real: Result, view_s: GpuSnapshot, view_e: GpuSnapshot, view: Result, } /// The counter's span over `work` ([`bracketed`]), with `ioreg` listed before /// it and after it, taken until the registry vouches for one /// ([`until_sorted`]). Its refusal, or none, is the registry's /// ([`refusal_is_the_registrys`]). fn checkable_span(what: &str, counter: &ProcessGpuCounter, rail: &OracleRail, budget: Duration, mut work: impl FnMut()) -> Checked { let me = std::process::id() as i32; let ((s, o0, o1, e), sorted) = until_sorted(what, budget, || { let before = listing(); let (s, o0, o1, e) = bracketed(counter, rail, &mut work); let after = listing(); let sorted = classify(&before, &s, &o0.list, &o1.list, &e, &after, me); ((s, o0, o1, e), sorted) }); let real = counter.share(&s, &e); verdict(what, &real, &sorted); refusal_is_the_registrys(&s, &e, &sorted, &real, me).unwrap_or_else(|x| panic!("{what}: {x}")); let (view_s, view_e) = (without(&s, &sorted.vanished), without(&e, &sorted.vanished)); let view = counter.share(&view_s, &view_e); Checked { s, e, o0, o1, sorted, real, view_s, view_e, view } } /// A span of the span meter's, the registry's sorting of it, and what the GPU /// counter makes of the meter's own two snapshots with the vanished clients /// taken out of both (`view`). struct MeterChecked { span: SpanEnergy, sorted: Sorted, view: Result, } /// The span meter's span over `work`, its GPU snapshots sorted against `ioreg` /// listed before the span, around the work and after it, taken until the /// registry vouches for one ([`until_sorted`]). The span is what the GPU /// counter makes of the meter's own snapshots: its figure in the span, or the /// CPU alone with its reason; its refusal, or none, is the registry's; and a /// figure is a sole user's share of the time the counter saw and the time /// hidden from it. fn checkable_meter_span(what: &str, meter: &ProcessSpanMeter, uses: SpanUses, budget: Duration, mut work: impl FnMut()) -> MeterChecked { let me = std::process::id() as i32; let ((span, s, e), sorted) = until_sorted(what, budget, || { let before = listing(); let start = meter.start(); let i0 = listing(); work(); let i1 = listing(); let (span, shown) = meter.finish_showing_gpu(start, uses); let after = listing(); let span = span.unwrap_or_else(|x| panic!("{what}: no figure: {x}")); let (s, e) = shown.unwrap_or_else(|| panic!("{what}: a GPU snapshot of the span failed: {span:?}")); let sorted = classify(&before, &s, &i0, &i1, &e, &after, me); ((span, s, e), sorted) }); let gpu = meter.gpu().share(&s, &e); match &gpu { Ok(g) => assert!( matches!(&span.source, SpanSource::Process { gpu, .. } if gpu == g), "{what}: the span {span:?} does not hold the GPU counter's figure over the meter's own snapshots, {g:?}" ), Err(x) => assert!( matches!(&span.source, SpanSource::CpuOnly { why, .. } if *why == format!("process GPU: {x}")), "{what}: the span {span:?} is not the CPU alone with the GPU counter's reason over the meter's own snapshots, {x}" ), } verdict(what, &gpu, &sorted); refusal_is_the_registrys(&s, &e, &sorted, &gpu, me).unwrap_or_else(|x| panic!("{what}: {x}")); // A figure is a sole user's share of the time the counter saw and the time // the registry shows it could not, as on the counter's own spans. if let Ok(g) = &gpu && g.self_ns > 0 { let all = g.all_ns.expect("a non-zero figure reads every client"); assert!( sole_with_hidden(g.self_ns, all, sorted.hidden_ns), "{what}: a figure, though this process ran {} ms of the {} ms the counter saw and the {} ms it could not ({}): below 99%", ms(g.self_ns), ms(all), ms(sorted.hidden_ns), sorted.hidden.join("; ") ); } let view = meter.gpu().share(&without(&s, &sorted.vanished), &without(&e, &sorted.vanished)); if !sorted.vanished.is_empty() { assert!(matches!(view, Ok(_) | Err(EnergyError::GpuShared { .. })), "{what}: without its vanished clients the span gave {view:?}"); } MeterChecked { span, sorted, view } } fn ms(ns: u64) -> f64 { ns as f64 / 1e6 } fn line(what: &str, r: &Result) { match r { Ok(g) => println!( "process-gpu: {what}: {:.3} J; this process {:.1} ms of {} GPU time ({:.2}%), rail {}, {:?}", g.uj as f64 / 1e6, ms(g.self_ns), g.all_ns.map_or("(not read)".to_string(), |a| format!("{:.1} ms", ms(a))), g.share_ppm() as f64 / 1e4, g.rail_uj.map_or("(not read)".to_string(), |r| format!("{:.3} J", r as f64 / 1e6)), g.provenance() ), Err(e) => println!("process-gpu: {what}: no figure: {e}"), } } /// The counter's view of a span against the oracle's readings inside it, /// client by client, `self_ns` and `all_ns` being the view's. /// /// - This process's GPU time agrees exactly: it ran no GPU work in the gaps. /// - The clients whose time went down nowhere advanced at least as far as the /// oracle saw (their sorting holds each counter reading between the /// registry's listings either side of it), and at most that plus what the /// gaps can hold. /// - The meter's every-client time is the sum over the view's clients. /// - The rail, wherever both snapshots read it current, shared span or not, /// is at least the oracle's inner reading and at most that plus 120 W over /// the gap and a republish interval at each end; and a figure's rail is it. /// - A figure is a sole user's of every client's time: the time the counter /// saw, and the time the registry shows it could not see. fn agrees_with_oracle(what: &str, c: &Checked, self_ns: u64, all_ns: u64) { let me = std::process::id() as i32; let (o0, o1) = (&c.o0.list, &c.o1.list); let o_me = oracle_pid_time(o0, o1, me).expect("this process's own clients are clean in a span the registry vouches for"); let at = |snap: &GpuSnapshot, id: u64| snap.clients.iter().find(|x| x.id == id).map_or(0, |x| x.gpu_ns); let listed = |l: &Listing, id: u64| l.clients.get(&id).map_or(0, |x| x.1); let counter_clean: u64 = c.sorted.clean.iter().map(|&id| at(&c.e, id).checked_sub(at(&c.s, id)).expect("a clean client")).sum(); let oracle_clean: u64 = c.sorted.clean.iter().map(|&id| listed(o1, id).checked_sub(listed(o0, id)).expect("a clean client")).sum(); let view_sum: u64 = c .view_e .clients .iter() .map(|x| x.gpu_ns.checked_sub(at(&c.view_s, x.id)).expect("no client of the view went back")) .sum(); // How much longer the counter's window is than the oracle's, at most: the // counter read the clients within 20 ms before each snapshot's `at`. let outer = c.e.at - c.s.at + Duration::from_millis(20); let gap_ns = outer.saturating_sub(o1.from.saturating_duration_since(o0.to)).as_nanos() as u64; println!( "process-gpu: {what}: oracle: this process {:.1} ms; the {} clients down nowhere {:.1} ms (counter {:.1} ms); outer window {:.0} ms, gap {:.0} ms", ms(o_me), c.sorted.clean.len(), ms(oracle_clean), ms(counter_clean), (c.e.at - c.s.at).as_secs_f64() * 1e3, ms(gap_ns) ); assert_eq!(self_ns, o_me, "{what}: this process's GPU time, counter vs ioreg"); assert!( counter_clean <= oracle_clean + gap_ns + gap_ns / 10 + 5_000_000, "{what}: the GPU time of the clients down nowhere: counter {} ms, oracle {} ms, gap {} ms", ms(counter_clean), ms(oracle_clean), ms(gap_ns) ); assert_eq!(all_ns, view_sum, "{what}: the meter's every-client GPU time is not the sum over the view's clients"); // The snapshots' own rail advance, as the meter sums it: each rail matched // by name and ordinal. let mut raw_nj = (c.s.rails_nj.len() == c.e.rails_nj.len()).then_some(0u64); for ((n0, a), (n1, b)) in c.s.rails_nj.iter().zip(&c.e.rails_nj) { raw_nj = raw_nj.and_then(|r| if n0 == n1 { b.checked_sub(*a).map(|d| r + d) } else { None }); } match raw_nj { Some(raw_nj) if c.s.rail_current && c.e.rail_current => { let rail_uj = raw_nj / 1_000; let o_rail_uj = (c.o1.rail_nj - c.o0.rail_nj) / 1_000; let rail_gap_ns = (c.e.at - c.s.at + Duration::from_millis(20)).saturating_sub(c.o1.rail_at - c.o0.rail_at).as_nanos() as u64 + 100_000_000; println!( "process-gpu: {what}: rail {:.3} J, oracle's inner {:.3} J: {:.1} W over the {:.0} ms gap and republish allowance (bound 120 W)", rail_uj as f64 / 1e6, o_rail_uj as f64 / 1e6, rail_uj.saturating_sub(o_rail_uj) as f64 * 1e3 / rail_gap_ns as f64, ms(rail_gap_ns) ); // The 120 W cap, against what it bounds, measured on the build host // (2026-11-04): beside the child alone, 12-17 W; beside three more // burners of this kernel as well (five clients burning, the GPU // drawing about 49 W across the window), at most 19.2 W. A co-tenant // that takes it near the cap calls for a new measurement, and a // raise from that, not a silent one. assert!( rail_uj + 1 >= o_rail_uj && rail_uj <= o_rail_uj + rail_gap_ns * 120 / 1_000, "{what}: rail {rail_uj} µJ vs the oracle's {o_rail_uj} µJ, gap {} ms", ms(rail_gap_ns) ); for (which, r) in [("as taken", &c.real), ("without the vanished", &c.view)] { if let Ok(g) = r && g.self_ns > 0 { assert_eq!(g.rail_uj, Some(rail_uj), "{what}: the figure's rail, {which}, is not the snapshots' advance"); } } } _ => { // The meter gives no figure then (`NotCurrent`, the rails differing, // or one going back), so no figure leaves its rail unchecked. for (which, r) in [("as taken", &c.real), ("without the vanished", &c.view)] { assert!( !matches!(r, Ok(g) if g.self_ns > 0), "{what}: a figure, {which}, whose rail is not checked against the oracle (a snapshot's rail was not current, or the rails differ): {r:?}" ); } println!("process-gpu: {what}: rail not checked: a snapshot's rail was not current, or the rails differ"); } } if let Ok(g) = &c.real && g.self_ns > 0 { let all = g.all_ns.expect("a non-zero figure reads every client"); assert!( sole_with_hidden(g.self_ns, all, c.sorted.hidden_ns), "{what}: a figure, though this process ran {} ms of the {} ms the counter saw and the {} ms it could not ({}): below 99%", ms(g.self_ns), ms(all), ms(c.sorted.hidden_ns), c.sorted.hidden.join("; ") ); } } /// A GPU-free span: an exact zero, a hardware reading, with nothing else read. fn assert_exact_zero(what: &str, r: &Result) { line(what, r); let g = r.as_ref().unwrap_or_else(|e| panic!("{what}: no GPU work of this process's is an exact zero, not {e}")); assert_eq!((g.uj, g.self_ns, g.rail_uj, g.all_ns, g.provenance()), (0, 0, None, None, Provenance::HwShunt), "{what}"); } /// A client of some *other* process going back must not take this pid's own GPU /// figure away: [`oracle_pid_time`] totals this pid's clients and no others. /// Deterministic: it builds the two listings rather than waiting for a client /// to be destroyed on the host. #[test] fn another_process_client_going_back_leaves_this_pids_gpu_time_readable() { const ME: i32 = 4242; const OTHER: i32 = 99; let at = Instant::now(); let mk = |clients: &[(u64, i32, u64)]| Listing { clients: clients.iter().map(|(id, pid, ns)| (*id, (*pid, *ns))).collect(), from: at, to: at }; // This pid's client advances 5 ms; another process's client goes back. let a = mk(&[(1, ME, 1_000_000), (2, OTHER, 9_000_000)]); let b = mk(&[(1, ME, 6_000_000), (2, OTHER, 1_000_000)]); assert_eq!(oracle_pid_time(&a, &b, ME), Some(5_000_000), "this pid's own time is still readable"); // This pid's own client going back is still no figure. let c = mk(&[(1, ME, 500_000), (2, OTHER, 9_000_000)]); assert_eq!(oracle_pid_time(&a, &c, ME), None, "this pid's own client going back makes it unavailable"); // No client of this pid at all is zero, not unavailable. let d = mk(&[(2, OTHER, 9_000_000)]); assert_eq!(oracle_pid_time(&d, &d, ME), Some(0), "a pid with no clients ran no GPU time"); } /// Every class [`classify`] sorts a span's clients into, each built from six /// reads rather than waited for on the host; the refusal rule's order; and the /// gate on a figure. Client 1 is this process's, advancing over the work. #[test] fn the_span_classifier_sorts_every_client() { const ME: i32 = 4242; let at = Instant::now(); let list = |c: &[(u64, i32, u64)]| Listing { clients: c.iter().map(|&(id, pid, ns)| (id, (pid, ns))).collect(), from: at, to: at }; let snap = |c: &[(u64, i32, u64)]| GpuSnapshot { rails_nj: vec![("GPU Energy".to_string(), 0)], clients: c.iter().map(|&(id, pid, gpu_ns)| GpuClient { id, pid, gpu_ns }).collect(), rail_current: true, at, }; // Client 9 of `pid` read as `r` (None: not listed) by the six reads, beside // this process's own client 1. let sort = |pid: i32, r: [Option; 6]| { let own = [100, 100, 100, 600, 600, 600]; let read = |k: usize| -> Vec<(u64, i32, u64)> { let mut v = vec![(1, ME, own[k])]; v.extend(r[k].map(|ns| (9, pid, ns))); v }; classify(&list(&read(0)), &snap(&read(1)), &list(&read(2)), &list(&read(3)), &snap(&read(4)), &list(&read(5)), ME) }; let other = |r| sort(77, r); let ok = |r| other(r).expect("no contradiction").expect("vouched for"); let void = |r| other(r).expect("no contradiction").expect_err("void").kind; let set = |ids: &[u64]| ids.iter().copied().collect::>(); // Clean: down nowhere; this process's own client is clean too. let s = ok([Some(10), Some(20), Some(30), Some(40), Some(50), Some(60)]); assert_eq!((s.vanished.clone(), s.clean.clone(), s.hidden_ns), (set(&[]), set(&[1, 9]), 0), "{s:?}"); // A fall before the counter's start lies outside its span: still clean. let s = ok([Some(1_000), Some(250), Some(260), Some(270), Some(280), Some(290)]); assert_eq!((s.vanished.clone(), s.clean.clone(), s.hidden_ns), (set(&[]), set(&[1, 9]), 0), "{s:?}"); // New at the end: clean. assert_eq!(ok([None, None, None, Some(5), Some(9), Some(12)]).clean, set(&[1, 9])); // Gone, vouched for by `ioreg` inside the span, or before it alone. assert_eq!(ok([Some(10), Some(20), Some(30), None, None, None]).vanished, set(&[9])); assert_eq!(ok([Some(10), Some(20), None, None, None, None]).vanished, set(&[9])); // Gone, and in no listing: void, not a refusal the test accepts. assert_eq!(void([None, Some(20), None, None, None, None]), UNCORROBORATED); // Back, the registry's fall across the start snapshot lying after it. assert_eq!(ok([Some(100), Some(200), Some(50), Some(60), Some(150), Some(160)]).vanished, set(&[9])); // Back, the fall inside the work (27254's shape, the counter seeing it). assert_eq!(ok([Some(10), Some(200), Some(300), Some(5), Some(8), Some(9)]).vanished, set(&[9])); // Back, with the registry showing no fall: the start read over: void. assert_eq!(void([Some(100), Some(200), Some(120), Some(130), Some(150), Some(160)]), OUT_OF_ORDER); // Back, made after `ioreg`'s first listing: nothing shows the fall: void. assert_eq!(void([None, Some(200), Some(50), Some(60), Some(150), Some(160)]), OUT_OF_ORDER); // Made and destroyed inside the span (48857's shape): hidden, nothing fails. let s = ok([None, None, Some(5_000_000), Some(28_000_000), None, None]); assert_eq!((s.vanished.clone(), s.clean.clone(), s.hidden_ns), (set(&[]), set(&[1]), 28_000_000), "{s:?}"); // Going back inside the oracle's window where the counter saw an advance // (27254's shape): a hidden fall of 400 ns, no refusal. let s = ok([Some(10), Some(20), Some(500), Some(100), Some(150), Some(160)]); assert_eq!((s.vanished.clone(), s.clean.clone(), s.hidden_ns), (set(&[]), set(&[1]), 400), "{s:?}"); // A fall across the end snapshot, before it: hidden too. assert_eq!(ok([Some(10), Some(20), Some(30), Some(500), Some(40), Some(45)]).hidden_ns, 455); // The same fall after the end snapshot lies outside the span: clean. assert_eq!(ok([Some(10), Some(20), Some(30), Some(500), Some(510), Some(45)]).clean, set(&[1, 9])); // Under-read at the start (below the registry's listing before it), or // over-read at the end (above the one after it): void. assert_eq!(void([Some(1_000), Some(900), Some(1_001), Some(1_002), Some(1_003), Some(1_004)]), OUT_OF_ORDER); assert_eq!(void([Some(1_000), Some(1_000), Some(1_001), Some(1_002), Some(1_100), Some(1_004)]), OUT_OF_ORDER); // This process's own client going back, gone, or hidden: void. So is a // reading of its own between the two sides of a fall of it the registry // shows across that reading (two falls in one gap). let mine = |r| sort(ME, r).expect("no contradiction").expect_err("void").kind; assert_eq!(mine([Some(10), Some(20), Some(30), Some(40), Some(5), Some(6)]), OWN_NOT_CLEAN); assert_eq!(mine([Some(10), Some(20), Some(30), None, None, None]), OWN_NOT_CLEAN); assert_eq!(mine([None, None, Some(5), Some(9), None, None]), OWN_NOT_CLEAN); assert_eq!(mine([Some(1_000), Some(700), Some(500), Some(500), Some(500), Some(500)]), OWN_NOT_CLEAN); // A reading of its own the registry does not explain, with no fall of it // shown across the reading, is a misread: it fails at once, not void. // Under-read at the start, over-read at the end, each by 1 ns, and a 10% // under-read at the start. let misread = |r| sort(ME, r).expect_err("a contradiction"); assert!(misread([Some(1_000), Some(999), Some(1_000), Some(1_000), Some(1_000), Some(1_000)]).contains("the counter's start snapshot read 999 ns")); assert!(misread([Some(1_000), Some(1_000), Some(1_000), Some(1_000), Some(1_001), Some(1_000)]).contains("the counter's end snapshot read 1001 ns")); assert!(misread([Some(1_000), Some(900), Some(1_000), Some(6_000), Some(6_000), Some(6_000)]).contains("the counter misread this process's GPU time")); // Contradictions: a read leaving out a client the reads either side of it // list, at the start snapshot, the end snapshot, inside the work, and // after a client is gone; and one client under two pids. let wrong = |r: [Option; 6]| other(r).expect_err("a contradiction"); assert!(wrong([Some(10), None, Some(30), Some(40), Some(50), Some(60)]).contains("but not in the counter's start snapshot")); assert!(wrong([Some(10), Some(20), Some(30), Some(40), None, Some(60)]).contains("but not in the counter's end snapshot")); assert!(wrong([None, Some(20), None, Some(40), Some(50), None]).contains("but not in ioreg as the work started")); assert!(wrong([None, None, Some(30), None, Some(50), None]).contains("but not in ioreg as the work ended")); let s = snap(&[(1, ME, 100), (9, 77, 20)]); let e = snap(&[(1, ME, 600), (9, 78, 50)]); let l = |n| list(&[(1, ME, n)]); assert!(classify(&l(100), &s, &l(100), &l(600), &e, &l(600), ME).expect_err("a contradiction").contains("is pid 77 in the counter's start snapshot and pid 78 in the counter's end snapshot")); // The refusal's rule: this process's own vanished client first, else the // least registry ID, wherever the snapshot lists it. let s = snap(&[(20, 500, 5), (31, ME, 0), (11, 78, 5), (10, 77, 5), (30, ME, 0)]); assert_eq!(expected_refusal(&s, &snap(&[(11, 78, 9), (30, ME, 1_000_000)]), ME), Some((ME, 31))); assert_eq!(expected_refusal(&s, &snap(&[(11, 78, 9), (30, ME, 1_000_000), (31, ME, 7)]), ME), Some((77, 10))); assert_eq!(expected_refusal(&s, &snap(&[(10, 77, 4), (11, 78, 9), (20, 500, 5), (30, ME, 1), (31, ME, 7)]), ME), Some((77, 10))); assert_eq!(expected_refusal(&s, &snap(&[(10, 77, 5), (11, 78, 9), (20, 500, 5), (30, ME, 1), (31, ME, 7)]), ME), None); // The counter's verdict against the registry's sorting: with vanished // clients the registry vouches for (10 and 11, both gone), a refusal naming // the oldest, and nothing else; with none, anything but a refusal. let s = snap(&[(1, ME, 100), (10, 77, 5), (11, 78, 5)]); let e = snap(&[(1, ME, 600)]); let vouched = Sorted { vanished: set(&[10, 11]), clean: set(&[1]), ..Sorted::default() }; let figure: Result = Ok(GpuShare { uj: 7, self_ns: 500, rail_uj: Some(7), all_ns: Some(500) }); let refused = |pid: i32, client: u64| -> Result { Err(EnergyError::GpuClientVanished { pid, client }) }; let against = |sorted: &Sorted, real: &Result| refusal_is_the_registrys(&s, &e, sorted, real, ME); assert!(against(&vouched, &figure).expect_err("a figure").contains("but the counter gave Ok(")); let shared = Err(EnergyError::GpuShared { self_ns: 500, all_ns: 1_000 }); assert!(against(&vouched, &shared).expect_err("shared").contains("but the counter gave Err(GpuShared")); assert!(against(&vouched, &refused(78, 11)).expect_err("a younger client").contains("not the vanished client the meter's rule names")); assert!(against(&vouched, &refused(77, 12)).is_err(), "a client not at the start"); assert_eq!(against(&vouched, &refused(77, 10)), Ok(())); let kept = snap(&[(1, ME, 600), (10, 77, 5), (11, 78, 9)]); let none = Sorted { clean: set(&[1, 10, 11]), ..Sorted::default() }; assert!(refusal_is_the_registrys(&s, &kept, &none, &refused(77, 10), ME).expect_err("no vanish").contains("refused, though no client vanished")); assert_eq!(refusal_is_the_registrys(&s, &kept, &none, &figure, ME), Ok(())); assert_eq!(refusal_is_the_registrys(&s, &kept, &none, &shared, ME), Ok(())); // The gate: 99% of what the counter saw, and of what it could not. assert!(sole_with_hidden(990, 1_000, 0)); assert!(!sole_with_hidden(990, 1_000, 1), "time hidden from the counter takes a 99.0% share below 99%"); assert!(!sole_with_hidden(989, 1_000, 0)); } #[test] fn a_gpu_span_is_a_sole_users_rail_or_an_exact_zero_or_no_figure() { if let Ok(secs) = std::env::var(CHILD_ENV) { // The child: burn, say so after the first command buffer, and keep on // for `secs` of wall time, or until its parent is gone (one killed // outright drops no `Burning` to stop it). let b = Burner::new(); b.dispatch(); println!("{READY}"); let (life, parent, t) = (Duration::from_secs(secs.parse().expect("seconds")), std::os::unix::process::parent_id(), Instant::now()); while t.elapsed() < life && std::os::unix::process::parent_id() == parent { b.dispatch(); } return; } let rail = OracleRail::open(); let me = std::process::id() as i32; // 1. Live, probed once per process with the first caller's GPU load, // however many threads ask; a CPU load never makes it live. let askers: Vec<_> = (0..4) .map(|_| { std::thread::spawn(|| { let b = Burner::new(); let c = ProcessGpuCounter::new(|| gpu_tick(&b)); (c.liveness(), c.is_available()) }) }) .collect(); let seen: Vec<_> = askers.into_iter().map(|t| t.join().expect("an asker")).collect(); let runs = jouleclaw_energy::process_gpu_probe_runs(); let cpu_only = probe_gpu_liveness_uncached(cpu_tick); println!("process-gpu: liveness seen by 4 threads={seen:?}, probe runs={runs}; under a CPU load only: {cpu_only:?}"); assert_eq!(runs, 1, "the GPU liveness probe did not run exactly once"); assert!(seen.iter().all(|s| *s == (CounterLiveness::Live, true)), "{seen:?}"); assert_eq!(gpu_rail_liveness_cached(), Some(CounterLiveness::Live)); assert_eq!(cpu_only, CounterLiveness::Frozen, "a CPU burn made this process's GPU sources look live"); let burner = Burner::new(); let counter = ProcessGpuCounter::new(|| panic!("the cached liveness probed again")); assert!(counter.is_available()); let span_meter = ProcessSpanMeter::new(|| panic!("the cached liveness probed again")); assert!(span_meter.is_metered()); settle_own_clients(); // 2. A GPU burn of ~1.5 s, against both oracles: the rail, as the sole // user; `GpuShared`, with the shares the oracle sees, otherwise. A // client of the host's that vanished in the span, vouched for by the // registry, refuses it; the checks then run on the view without it. let (mut ran, mut buffers) = (0.0, 0u32); let c = checkable_span("1.5 s burn", &counter, &rail, BUDGET, || { (ran, buffers) = burner.burn_counted(Duration::from_millis(1500), Duration::from_secs(20)); }); line("1.5 s GPU burn", &c.real); if !c.sorted.vanished.is_empty() { line("1.5 s GPU burn, without its vanished clients", &c.view); } println!("process-gpu: 1.5 s GPU burn: {buffers} command buffers ran {:.1} ms on the GPU", ran * 1e3); let (self_ns, all_ns) = match &c.view { Ok(g) => (g.self_ns, g.all_ns.expect("a non-zero figure reads every client")), Err(EnergyError::GpuShared { self_ns, all_ns }) => (*self_ns, *all_ns), Err(other) => panic!("1.5 s burn: {other}"), }; agrees_with_oracle("1.5 s GPU burn", &c, self_ns, all_ns); // This process's GPU time runs a little past its command buffers' own GPU // spans (as the sole user, 1618.3 ms for 1500.9 ms of spans over ~190 // buffers: ~0.6 ms a buffer), so the ceiling allows 2 ms a buffer. Under // contention the spans hold other clients' time slices too (1.50 s of // spans for 164 ms of this process's time), so the floor is low. assert!(self_ns >= 20_000_000, "{} ms of GPU time for a 1.5 s burn", ms(self_ns)); assert!(self_ns as f64 <= ran * 1e9 + f64::from(buffers) * 2e6 + 5e6, "more GPU time than {buffers} command buffers ran"); let sole = u128::from(self_ns) * 100 >= u128::from(all_ns) * 99; match &c.view { Ok(g) => { assert!(sole, "a figure below 99% of the GPU time: {g:?}"); // The rail's bounds against the oracle's, and that it is the // snapshots' own advance, are checked in `agrees_with_oracle`, // this span's rail being current at both ends, as a figure's must // be. let rail_uj = g.rail_uj.expect("a non-zero figure reads the rail"); let expected = (u128::from(rail_uj) * u128::from(g.self_ns) / u128::from(all_ns)) as u64; assert!(g.uj.abs_diff(expected) <= 1 && g.uj > 0, "the figure {} µJ is not the rail times the share, {expected} µJ", g.uj); assert_eq!(g.domain(), EnergyDomain::ProcessGpu); } Err(_) => assert!(!sole, "GpuShared at or above 99% of the GPU time: {:?}", c.view), } println!( "process-gpu: oracle-checked: 1.5 s GPU burn: {} (excluded {} vanished)", if c.view.is_ok() { "figure" } else { "shared" }, c.sorted.vanished.len() ); // 3. A span with no GPU work of this process's is an exact zero — every // time, whatever else on the host uses the GPU or closes a client — // and `ioreg` saw none inside it. for k in 0..3 { let what = format!("300 ms idle #{k}"); let s = counter.snapshot().expect("a snapshot"); let l0 = listing(); std::thread::sleep(Duration::from_millis(300)); let l1 = listing(); let e = counter.snapshot().expect("a snapshot"); assert_eq!(oracle_pid_time(&l0, &l1, me), Some(0), "{what}: ioreg saw this process's GPU time move"); assert_exact_zero(&what, &counter.share(&s, &e)); } // 4. Contended: a child burns the GPU through this process's spans, for // longer than 4b and 4c can take between them, each taking spans again // for up to `BUDGET`; its exit inside them would be a vanished client, // and the spans no longer contended. let mut child = spawn_burner(2 * BUDGET.as_secs() as u32 + 60); let child_pid = child.pid(); // a. No GPU work here beside it: still an exact zero, while the oracle // sees the child's GPU time in the window, and none of this one's. let (s, o0, o1, e) = bracketed(&counter, &rail, || std::thread::sleep(Duration::from_millis(400))); let child_ns = oracle_pid_time(&o0.list, &o1.list, child_pid).expect("the child's own GPU time went back in the oracle's window"); assert_eq!(oracle_pid_time(&o0.list, &o1.list, me), Some(0), "400 ms idle beside a child: ioreg saw this process's GPU time move"); assert_exact_zero(&format!("400 ms idle beside a child that ran {:.1} ms on the GPU", ms(child_ns)), &counter.share(&s, &e)); assert!(child_ns >= 20_000_000, "the child did not contend: {} ms", ms(child_ns)); // b. GPU work here beside it: `GpuShared`, at the oracle's times. A // vanished client can only have added GPU time, so the view without // it is at least as shared as the span. let c = checkable_span("contended 1 s burn", &counter, &rail, BUDGET, || { burner.burn(Duration::from_millis(1000), Duration::from_secs(20)); }); child.assert_burning("contended 1 s burn"); line("1 s GPU burn beside a burning child", &c.real); let Err(EnergyError::GpuShared { self_ns, all_ns }) = &c.view else { panic!("a shared GPU gave {:?}", c.view) }; let (self_ns, all_ns) = (*self_ns, *all_ns); agrees_with_oracle("1 s GPU burn beside a burning child", &c, self_ns, all_ns); let child_ns = oracle_pid_time(&c.o0.list, &c.o1.list, child_pid).expect("the child's own GPU time went back in the oracle's window"); println!("process-gpu: oracle: the child ran {:.1} ms on the GPU in that window", ms(child_ns)); assert!(child_ns >= 20_000_000 && self_ns > 0, "the child did not contend: {} ms", ms(child_ns)); assert!(u128::from(self_ns) * 100 < u128::from(all_ns) * 99); // c. The span meter there: the CPU alone, `Partial`, saying why; and a // CPU-only span beside the child keeps its whole figure. let m = checkable_meter_span("span meter, GPU burn beside the child", &span_meter, SpanUses::CpuGpu, BUDGET, || { burner.burn(Duration::from_millis(500), Duration::from_secs(10)); }); child.assert_burning("span meter, GPU burn beside the child"); let shared = &m.span; println!("process-gpu: span meter, GPU burn beside the child: {shared:?}"); if !m.sorted.vanished.is_empty() { assert!(matches!(m.view, Err(EnergyError::GpuShared { .. })), "a span beside a burning child, without its vanished clients, gave {:?}", m.view); } match &shared.source { SpanSource::CpuOnly { cpu_uj, why } => { // A refusal the registry vouched for is the CPU alone as well, its // reason the GPU counter's (checked above). if m.sorted.vanished.is_empty() { assert!(why.contains("GPU was shared") && why.contains("ns of"), "{why}"); } assert_eq!((shared.uj, shared.provenance, shared.coverage), (*cpu_uj, Provenance::HwShunt, Coverage::Partial)); assert!(*cpu_uj > 0); } other => panic!("a span on a shared GPU was not the CPU alone: {other:?}"), } let start = span_meter.start(); let i0 = listing(); cpu_tick(); let i1 = listing(); let cpu_span = span_meter.finish(start, SpanUses::CpuGpu).expect("a figure"); println!("process-gpu: span meter, CPU-only work beside the child: {cpu_span:?}"); assert_eq!(oracle_pid_time(&i0, &i1, me), Some(0), "CPU-only work beside the child: ioreg saw this process's GPU time move"); let (cpu_uj, gpu) = cpu_span.parts().expect("a CPU-only span is metered whole"); assert_eq!((gpu.uj, gpu.self_ns, cpu_span.provenance, cpu_span.coverage), (0, 0, Provenance::HwShunt, Coverage::Whole)); assert!(cpu_uj > 0 && cpu_span.uj == cpu_uj); // 5. The child exits inside a span. With no GPU work here: an exact zero. // With GPU work here: no GPU figure (`GpuClientVanished`), and the span // meter gives the CPU alone, `Partial`, saying why. let second = spawn_burner(60); let second_pid = second.pid(); let s = counter.snapshot().expect("a snapshot"); assert!(s.clients.iter().any(|c| c.pid == child_pid), "the child's client is not in the start snapshot"); kill_and_await_gone(child); let e = counter.snapshot().expect("a snapshot"); assert!(!e.clients.iter().any(|c| c.pid == child_pid), "the dead child's client is in the end snapshot"); assert_exact_zero("idle across the child's exit", &counter.share(&s, &e)); let span = span_meter.start(); let s = counter.snapshot().expect("a snapshot"); assert!(s.clients.iter().any(|c| c.pid == second_pid), "the second child's client is not in the start snapshot"); burner.burn(Duration::from_millis(200), Duration::from_secs(10)); kill_and_await_gone(second); let e = counter.snapshot().expect("a snapshot"); let refused = counter.share(&s, &e); line("GPU burn across the second child's exit", &refused); // The child's exit refuses the span, but this host's other processes // open, close and reset GPU clients too, and one of theirs that vanished // in the same span refuses it just as truly. The meter names this // process's own vanished client first, else the oldest (the least // registry ID), so an older client of another process's is named before // the child's. So: the named client really vanished, it is the one that // rule picks, every client of the child's is gone, and with the host's // other vanished clients taken out of the start snapshot the child's // exit alone still refuses the span. let Err(EnergyError::GpuClientVanished { pid, client }) = refused else { panic!("a GPU span across the second child's exit gave {refused:?}") }; let what = "GPU burn across the second child's exit"; // Read independently of the counter, after its end snapshot: a client gone // from that snapshot is gone from the registry for good (an entry once // destroyed never comes back, and its ID is not reused), so one `ioreg` // still lists was left out of the counter's read, not closed. let after = ioreg_clients(); let gone_from_e: Vec<&GpuClient> = s.clients.iter().filter(|c| !e.clients.iter().any(|x| x.id == c.id)).collect(); let missed: Vec = gone_from_e.iter().filter(|c| after.contains_key(&c.id)).map(|c| format!("{:#x} of pid {}", c.id, c.pid)).collect(); assert!(missed.is_empty(), "{what}: clients the counter's end snapshot lacks, which the registry still lists after it: {missed:?}"); assert_names_a_vanished_client(what, &s, &e, pid, client); assert_eq!(expected_refusal(&s, &e, me), Some((pid, client)), "{what}: not the oldest vanished client, this process's own first"); assert!( s.clients.iter().filter(|c| c.pid == second_pid).all(|c| !e.clients.iter().any(|x| x.id == c.id)), "{what}: a client of the dead child's is in the end snapshot" ); let only_child = GpuSnapshot { clients: s.clients.iter().filter(|c| c.pid == second_pid || !vanished(c, &e)).copied().collect(), ..s.clone() }; let alone = counter.share(&only_child, &e); assert!(matches!(alone, Err(EnergyError::GpuClientVanished { pid, .. }) if pid == second_pid), "{what}: the child's exit alone gave {alone:?}"); if pid != second_pid { // Every client that vanished, for whoever reads a failure here: host churn // shows as other processes' clients gone, a fault in the read as one the // registry still lists (checked above). let all: Vec = s .clients .iter() .filter(|c| vanished(c, &e)) .map(|c| match e.clients.iter().find(|x| x.id == c.id) { Some(x) => format!("({}, {:#x}, {} ns, back to {} ns)", c.pid, c.id, c.gpu_ns, x.gpu_ns), None => format!("({}, {:#x}, {} ns, gone{})", c.pid, c.id, c.gpu_ns, if after.contains_key(&c.id) { ", but ioreg lists it" } else { "" }), }) .collect(); println!("process-gpu: {what}: it named client {client:#x} of pid {pid}, older than the child's; every client that vanished (pid, id, start, end): {}", all.join(", ")); } // The span meter across it: the CPU alone, saying why in the GPU // counter's own words over the meter's own snapshots. let (across, shown) = span_meter.finish_showing_gpu(span, SpanUses::CpuGpu); let across = across.expect("a figure"); let (s, e) = shown.expect("the span meter's GPU snapshots"); let g = span_meter.gpu().share(&s, &e); println!("process-gpu: span meter across it: {across:?}"); match &across.source { SpanSource::CpuOnly { why, .. } => { assert!(why.contains("process GPU") && why.contains("gone or reset"), "{why}"); let Err(x) = &g else { panic!("{what}: the span meter's own snapshots gave a GPU figure, {g:?}, but its span says {why}") }; assert_eq!(*why, format!("process GPU: {x}"), "{what}: the span meter's reason is not the GPU counter's over its snapshots"); } other => panic!("a span across a vanished client was not the CPU alone: {other:?}"), } assert_eq!((across.provenance, across.coverage), (Provenance::HwShunt, Coverage::Partial)); // 6. The span meter on a GPU burn with the children gone: CPU + GPU, // `Whole` (`Partial` when the caller says the work used the ANE), as the // sole user; the CPU alone, `Partial`, if the host's other GPU work // shared the GPU, or a client of its vanished as the registry vouches. for uses in [SpanUses::CpuGpu, SpanUses::CpuGpuAne] { let m = checkable_meter_span(&format!("span meter, {uses:?}"), &span_meter, uses, BUDGET, || { burner.burn(Duration::from_millis(500), Duration::from_secs(10)); }); let r = &m.span; match &r.source { SpanSource::Process { cpu_uj, gpu } => { println!( "process-gpu: span meter, {uses:?}: {:.3} J = CPU {:.3} J + GPU {:.3} J ({:.2}% of the GPU time), {:?}, {:?}", r.uj as f64 / 1e6, *cpu_uj as f64 / 1e6, gpu.uj as f64 / 1e6, gpu.share_ppm() as f64 / 1e4, r.provenance, r.coverage ); assert_eq!(r.uj, cpu_uj + gpu.uj); assert!(*cpu_uj > 0 && gpu.uj > 0 && gpu.share_ppm() >= 990_000, "{r:?}"); assert_eq!(r.provenance, Provenance::HwShunt); assert_eq!(r.coverage, if uses == SpanUses::CpuGpu { Coverage::Whole } else { Coverage::Partial }); } SpanSource::CpuOnly { cpu_uj, why } => { println!("process-gpu: span meter, {uses:?}: CPU alone {:.3} J, Partial: {why}", *cpu_uj as f64 / 1e6); if m.sorted.vanished.is_empty() { assert!(why.contains("GPU was shared"), "{why}"); } assert_eq!((r.uj, r.provenance, r.coverage), (*cpu_uj, Provenance::HwShunt, Coverage::Partial)); assert!(*cpu_uj > 0, "{r:?}"); } SpanSource::Fallback { .. } => panic!("the CPU counter is live, so no span falls back: {r:?}"), } } }