//! The per-process CPU energy probe on real hardware. Its counter covers //! every thread of THIS process, so these tests run in a process of their own //! (this file) and one at a time (a lock): a burn in a test running beside //! another would land in the other's span. Each asserts against an oracle of //! its own — `proc_pid_rusage` read into a raw buffer at the SDK's offset, //! sharing no code with the probe — and logs what it saw. #![cfg(all(target_os = "macos", target_arch = "aarch64"))] use sandbox_meter::probe::process_energy_probe_runs; use sandbox_meter::{process_energy_status, CounterStatus, Measurement, PowerMeter, Provenance}; use sandbox_schema::DeviceClass; use std::sync::{Mutex, MutexGuard}; use std::time::{Duration, Instant}; /// One test at a time: the counter is process-wide. static ONE_AT_A_TIME: Mutex<()> = Mutex::new(()); fn alone() -> MutexGuard<'static, ()> { ONE_AT_A_TIME.lock().unwrap_or_else(|e| e.into_inner()) } /// The oracle: `ri_energy_nj` of `pid`, read with `proc_pid_rusage(pid, /// RUSAGE_INFO_V6)` into a raw buffer and taken at byte 336, where the macOS /// SDK's `` puts it (a 16-byte uuid, then 40 `uint64_t`s). fn oracle_energy_nj(pid: libc::pid_t) -> Option { let mut buf = [0u64; 64]; // 512 bytes, more than the struct's 464 // SAFETY: `buf` is writable and larger than `rusage_info_v6`. let rc = unsafe { libc::proc_pid_rusage(pid, 6, buf.as_mut_ptr() as *mut libc::rusage_info_t) }; (rc == 0).then_some(buf[336 / 8]) } fn me() -> libc::pid_t { // SAFETY: no preconditions. unsafe { libc::getpid() } } /// This thread's CPU time. fn thread_cpu() -> Duration { let mut ts = libc::timespec { tv_sec: 0, tv_nsec: 0 }; // SAFETY: `ts` is writable. unsafe { libc::clock_gettime(libc::CLOCK_THREAD_CPUTIME_ID, &mut ts) }; Duration::new(ts.tv_sec as u64, ts.tv_nsec as u32) } /// Burn `cpu` of this thread's CPU time on this one thread — CPU time, not /// wall time, so a loaded machine that takes the core away makes the burn /// longer, never smaller — at the user-interactive QoS class, so the burn /// lands on the cores interactive work gets. fn burn_cpu(cpu: Duration) { // SAFETY: sets this thread's own QoS class; no preconditions. unsafe { libc::pthread_set_qos_class_self_np(libc::qos_class_t::QOS_CLASS_USER_INTERACTIVE, 0) }; let start = thread_cpu(); let mut x = 0u64; while thread_cpu() - start < cpu { for _ in 0..10_000 { x = x.wrapping_mul(6364136223846793005).wrapping_add(1442695040888963407); } } std::hint::black_box(x); } fn joules(uj: u64) -> f64 { uj as f64 / 1e6 } /// The span's one record, which must be a `Cpu` hardware reading. fn the_reading(m: &Measurement) -> u64 { assert_eq!(m.source, "process-energy", "{m:?}"); assert_eq!(m.devices.len(), 1, "{m:?}"); let d = m.devices[0]; assert_eq!((d.class, d.provenance), (DeviceClass::Cpu, Provenance::HwShunt), "{m:?}"); d.check_provenance().unwrap(); d.measured_uj.expect("a reading carries its measured figure") } /// The counter is live on this host, and the oracle agrees: over a second of /// burn sampled every ~25 ms of this thread's CPU, it advanced in at least /// nine intervals in ten. The probe ran once, however often it is asked. #[test] fn the_process_energy_probe_is_live() { let _one = alone(); let status = process_energy_status(); let (mut advanced, mut intervals) = (0, 0); let mut last = oracle_energy_nj(me()).expect("oracle read"); let t = Instant::now(); while t.elapsed() < Duration::from_secs(1) { burn_cpu(Duration::from_millis(25)); let now = oracle_energy_nj(me()).expect("oracle read"); intervals += 1; advanced += u32::from(now > last); last = now; } for _ in 0..8 { assert_eq!(process_energy_status(), status); let _ = PowerMeter::detect_in_process(); } let runs = process_energy_probe_runs(); eprintln!("process energy: status={status:?} oracle advanced in {advanced}/{intervals} intervals, probe runs={runs}"); assert_eq!(runs, 1, "the liveness probe runs once per process"); if advanced * 10 >= intervals * 9 { assert_eq!(status, CounterStatus::Live, "the oracle saw the counter keep advancing"); } if status == CounterStatus::Live { assert!(advanced * 5 >= intervals * 4, "Live, yet the oracle saw it advance in {advanced}/{intervals}"); } #[cfg(target_arch = "aarch64")] assert_eq!(status, CounterStatus::Live, "measured live on this Apple Silicon fleet (macOS 27.0.1)"); } /// 200 ms of one thread's CPU, burned in this process and metered through /// `detect_in_process`, is a `Cpu` hardware reading between 0.1 J and 20 J, /// and inside the oracle's reading of the same work (read around the span). /// /// The floor is 0.1 J, not 0.2: 200 ms of CPU costs a different amount /// depending on which core class ran it. On an M5 Max it read 0.18-1.24 J, /// and 0.171 J on a busy host where the burn took 1 s of wall time (the /// oracle read the same 0.171 J). 0.1 J is also the sleeping test's ceiling, /// so no counter that reads wall time at a fixed power passes both. #[test] fn an_in_process_burn_is_a_hardware_reading_of_its_energy() { let _one = alone(); let mut meter = PowerMeter::detect_in_process(); assert_eq!(meter.sources(), ["process-energy"], "status {:?}", process_energy_status()); let outer_before = oracle_energy_nj(me()).unwrap(); let ((), m) = meter.measure(|| burn_cpu(Duration::from_millis(200))); let outer = oracle_energy_nj(me()).unwrap() - outer_before; let uj = the_reading(&m); eprintln!("200 ms in-process burn: {:.4} J over {:?} wall (oracle around it: {:.4} J)", joules(uj), m.wall, outer as f64 / 1e9); assert!((100_000..=20_000_000).contains(&uj), "{uj} µJ for 200 ms of one thread"); assert!(uj <= outer / 1_000 + 1, "the span read more ({uj} µJ) than the oracle around it ({outer} nJ)"); } /// This process's context switches, every thread's: `getrusage`'s /// voluntary and involuntary counts. fn switches() -> libc::c_long { // SAFETY: an all-zero `rusage` is a valid out-parameter. let mut ru: libc::rusage = unsafe { std::mem::zeroed() }; // SAFETY: `ru` is writable for the call. assert_eq!(unsafe { libc::getrusage(libc::RUSAGE_SELF, &mut ru) }, 0); ru.ru_nvcsw + ru.ru_nivcsw } /// The oracle's own read of this process, after taking this thread off its /// core in a way that shares nothing with the meter's: a sleep of 1 ms or /// more, then 2, 4 and 8 ms, until this process's context-switch count moved /// across one. A sleep of a millisecond does not end before the thread has /// blocked (the timer would have to fire before the block, a millisecond /// after it was set), and the count moving says a switch happened; the /// meter instead watches its thread's own energy count after sleeps from /// 50 µs. A thread never seen to switch is the oracle's failure, said so. fn folded_oracle_nj() -> u64 { for ms in [1, 2, 4, 8] { let before = switches(); std::thread::sleep(Duration::from_millis(ms)); if switches() > before { return oracle_energy_nj(me()).expect("oracle read"); } } panic!("the oracle's thread was not seen to switch across sleeps of 1, 2, 4 and 8 ms"); } /// A short span is read whole on the thread that runs it. The kernel folds /// a thread's energy into the count only when the thread leaves a core, and /// a read of this process does not fold the thread reading (its CPU time is /// current, its energy is not), so the meter takes that thread off its core /// before each read and checks that it left. 1 ms of this thread's CPU, /// metered 20 times, is a `Cpu` hardware reading every time — never the /// estimator a count that held gives — and inside the oracle's reading /// around it, which folds on its own and by its own check /// ([`folded_oracle_nj`]), short of it by no more than a quarter: the /// meter's reads and wake-ups, a few tens of microjoules. #[test] fn a_short_in_process_span_is_read_whole_on_its_own_thread() { let _one = alone(); let mut meter = PowerMeter::detect_in_process(); for rep in 0..20 { let before = folded_oracle_nj(); let ((), m) = meter.measure(|| burn_cpu(Duration::from_millis(1))); let outer = folded_oracle_nj() - before; eprintln!("1 ms in-process burn rep {rep}: span {:?}, oracle around it {outer} nJ", m.devices); let uj = the_reading(&m); // The probe's µJ are its nJ floored at each end: within 1 µJ of the // nJ advance. assert!(uj * 1_000 <= outer + 1_000, "the span read more ({uj} µJ) than the oracle around it ({outer} nJ)"); assert!((uj + 1) * 1_000 * 4 >= outer * 3, "the span ({uj} µJ) is short of the oracle around it ({outer} nJ)"); } } /// A 200 ms sleep in this process is a reading under 0.1 J: the counter /// covers this process's threads, and they did next to nothing. #[test] fn an_in_process_sleep_reads_under_a_tenth_of_a_joule() { let _one = alone(); let mut meter = PowerMeter::detect_in_process(); let ((), m) = meter.measure(|| std::thread::sleep(Duration::from_millis(200))); let uj = the_reading(&m); eprintln!("200 ms in-process sleep: {uj} µJ"); assert!(uj < 100_000, "{uj} µJ for a 200 ms sleep"); } /// `detect()` never reads this process's counter, even where it is live: /// `detect` meters subprocesses, which that counter does not cover. #[test] fn detect_does_not_include_the_process_probe() { let _one = alone(); let status = process_energy_status(); let sources = PowerMeter::detect().sources(); eprintln!("detect(): {sources:?} (process energy {status:?})"); assert!(!sources.contains(&"process-energy"), "{sources:?}"); assert_eq!(status, CounterStatus::Live, "setup: the probe was available to include"); } /// Work in a child process is not attributed to the in-process probe. A child /// burns ~0.4 s of CPU while this process waits; the oracle reads the child's /// own energy from the exited child before it is reaped, and this process's /// energy around the wait. The in-process span over the wait is a fraction /// of the child's energy, and under 0.1 J — or, if this process's counter did /// not move at all while it waited, an estimate, never a reading. #[test] fn work_in_a_child_process_is_not_attributed_to_the_in_process_probe() { let _one = alone(); let mut meter = PowerMeter::detect_in_process(); let mine_before = oracle_energy_nj(me()).unwrap(); let span = meter.start(); let child = std::process::Command::new("awk") .arg("BEGIN { for (i = 0; i < 12000000; i++) x += i; print x }") .stdout(std::process::Stdio::null()) .spawn() .expect("spawn awk"); let pid = child.id() as libc::pid_t; // Wait for the exit without reaping, so the child is still readable. // SAFETY: an all-zero siginfo_t is a valid out-parameter; `pid` is ours. let mut info: libc::siginfo_t = unsafe { std::mem::zeroed() }; let rc = unsafe { libc::waitid(libc::P_PID, pid as libc::id_t, &mut info, libc::WEXITED | libc::WNOWAIT) }; assert_eq!(rc, 0, "waitid: {}", std::io::Error::last_os_error()); let m = span.stop(&mut meter); let mine = oracle_energy_nj(me()).unwrap() - mine_before; let childs = oracle_energy_nj(pid).expect("the exited, unreaped child reads"); let mut child = child; assert!(child.wait().expect("reap").success()); eprintln!( "child work: child {:.4} J, this process {:.6} J around the wait, span {:?}", childs as f64 / 1e9, mine as f64 / 1e9, m.devices ); assert!(childs >= 100_000_000, "setup: the child did real work ({childs} nJ)"); assert!(mine < 100_000_000 && mine * 10 < childs, "this process's counter took the child's work: {mine} nJ"); if m.reads_cpu() { let uj = the_reading(&m); assert!(uj < 100_000 && uj * 1_000 * 10 < childs, "the span read the child's work: {uj} µJ"); } else { assert_eq!(m.devices[0].provenance, Provenance::Estimator, "{m:?}"); } }