jcp-energy: IOReport only when its CPU rail keeps advancing, never on a batch refresh #110
Loading…
Reference in a new issue
No description provided.
Delete branch "jcp-energy/cpu-rail-liveness"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
jcp-energy's
detect()selected its IOReport rung the moment a subscription opened.measure()then took any rise in the summed rails as the task's energy. That contradicts this crate's own contract: "measured when the platform exposes it, estimated when it doesn't, and the provenance always says which … A reading never silently upgrades its own provenance."What was wrong: on main
macOS energy backend (jcp-energy)CI job flaked for the same reason. Its test asserted the summed total advanced during a CPU burn, which the GPU satisfies whenever something draws on screen. It passed by day and failed at night; this was the "healed" zero of 2026-09-19.What this does
detect()selects IOReport only whenioreport_status()isLive, under the rule below. Otherwise it falls back to TimePower (ModelBased), andioreport_status()says why.Verification of this PR (head
3fd35db5)host_status(). The old oracle is shown to vouch for a refresh:CpuRailMoved(true)on a two-step lump.status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false.CPU Energy. The hierarchy was confirmed from absolute values on both chips (CPU Energy=MCPU0+MCPU1+PCPU, to within 1–7 mJ).Later rounds on this branch (after the verification above)
340313d6: a live IOReport reading is graded HwShunt, the same as RAPL and NVML in this crate. A span is a reading only if the CPU rail itself advanced across it. intercept/1 carriescoverage: Partialfor a partial figure; the key is omitted when Whole, so old receipts are byte-identical (pinned against goldens). SPEC §5 has the liveness MUST and a coverage section.475680ab: RAPL and NVML are gated on the same liveness rule, through one shared module. An NVML figure ismeasured_partial. A span where no counter rose gets the time×power figure, never a hardware 0.4f9d90ca: a counter is live only if every rail it sums keeps advancing: each die for IOReport, each package for RAPL. A host with no rail is never Live.25bfdcd9: RAPL sums only thepackage-Nzones, never psys or dram. Each zone wraps at its own range; an unreadable range used to default tou64::MAXand seal a ~1.8×10¹⁹ µJ figure.Why: what IOReport actually does on macOS 27.0.1
Measured by reading channels directly on the M5 Max (dev) and the M3 Ultra (10.10.10.2), both on macOS 27.0.1:
CPU EnergyandDIE_<n>_CPU Energydo not move under load for seconds to minutes. On the M3 Ultra both dies held for at least 22 minutes, then jumped about 1.3 kJ each.+61,764,485 mJ, then+3,435 mJ64 ms later.A meter that sums rails therefore reports CPU work as GPU-only energy (M5 Max) or 0 (M3 Ultra), labelled as a reading. A liveness check that accepts one advance, or two, gives a false Live whenever its window holds a refresh. After that, each later ~1.3 kJ lump is booked whole to whichever span straddles it.
The rule: identical in all five backends (#110, #114, #115, #116, #117)
CPU Energy, or eachDIE_<n>_CPU Energy), keyed by name and ordinal:namereadspackage-N, on every socket, and each must be live. It never sumspsys, which already includes the packages, nordramor the sub-zones.max_energy_range_uj. A wrap whose range is unknown gives no figure; it never becomes a ~1.8×10¹⁹ µJ reading.Livedeclines the backend, so the crate's existing honest fallback runs. The reason is public:IoReportStatus,ioreport_status(),rapl_status(),nvml_status().admits(status)(Live only).How it was verified
Six rounds of implementation, each checked by independent adversarial verification.
Pure tests on scripted samples and a scripted clock. They cover:
Fault hooks inside the real IOReport opener and sampler. The tests drive the real production status through each script: opener fails, a single lump, a two-step lump, constant values, and a sustained advance. So a bypass written into the glue fails a test.
Hardware tests against an independent oracle. The oracle has its own subscription, reads absolute values, burns on a helper thread, and counts a rail as moving only on a sustained change. The tests check:
Mutation-tested. Each of the following was applied as a temporary edit and failed a test:
admits()that accepts CpuRailAbsent.The counts per crate are below.
Robustness. Each crate passes under artificial CPU load and while another process samples every IOReport channel in a tight loop. The latter is what made an earlier wall-clock pin flaky, so the job now runs on the shared CI host without that flake. Each also passes on the M3 Ultra.
CI: these tests are behind
cfg(target_os = "macos"), and this workspace runs on a linux runner. They reach CI through #102, which merges last. #102 runs every backend's lib and integration tests on macOS, and fails any step whose frozen-rail test did not printioreport liveness:.Merge order: #110, #114, #115, #116 and #117 are independent of each other. #102 goes after all of them.
Open questions, now decided and implemented (per "fix it all")
measured_ujthat carry estimates. Their grade now sits beside them in plaintext: jcp-gateway's_metagetsenergy_provenance, plusenergy_coveragewhen partial. The keys stay, for compatibility.Meterdefaults to Estimator, and the conformance fixture keeps HwShunt explicitly, so the vectors are byte-identical.Authorizer::chargecarries the figure's provenance.ri_energy_nj: unprivileged, live on both Macs, and attributed to the work. It is wired in as stacked PRs #120–#124, only where the work runs in-process. (Privilegedpowermetricsis live too, but machine-wide and root-only, so it is not used.)Still open
joule-ui-servegives it honest grades, and the per-process probe in #121 gives it real readings.🤖 Generated with Claude Code
This crate's contract, in its own module doc: "measured when the platform exposes it, estimated when it doesn't, and the provenance always says which ... A reading never silently upgrades its own provenance." The IOReport rung broke that on current macOS, and the CI job meant to catch it could not. What IOReport actually returns on macOS 27.0.1, measured by dumping the channels rather than re-running the test: - On an M5 Max, every CPU rail in the Energy Model group (`CPU Energy`, `PCPU`, `MCPU*`, `PACC_*`) holds the same cumulative value across 200 ms, 1 s, 3 s and ~4 minutes of full CPU load. `CPU Energy` read 73,176,481 mJ before and after. `GPU Energy` stays live. - On an M3 Ultra, the same OS: all 645 Energy Model rails are frozen, CPU, DRAM and display included. - Every channel is IOReport format 1 (Simple), so the accessor is right, and subscribing to the Energy Model group alone instead of all channels does not unfreeze anything. No channel in any group exposes live CPU energy to an unprivileged reader; "CPU Stats" residency moves, but that is activity. So `detect()` selected IOReport the moment a subscription opened, and `measure()` accepted any `a > b` on the summed rails as the task's energy. On the M5 Max the GPU rail makes `a > b` true: GPU energy was reported as the energy of CPU work, as a whole-task ModelBased figure. On the M3 Ultra nothing moves, so it fell to time×power under the same tag, indistinguishable from a reading. The CI job `macOS energy backend (jcp-energy)` flaked for the same reason. Its test asserted the summed total advanced across a 200 ms CPU burn — satisfied by the GPU, not the CPU. It passed when something happened to draw on screen and failed when nothing did, which is why it failed overnight and "healed" by day. That flake has been blocking unrelated PRs. The fix enforces the contract where the rung is chosen. `detect()` selects IOReport only when `ioreport_status()` is `Live`: the CPU rail itself — `CPU Energy`, or `DIE_<n>_CPU Energy` on multi-die parts — must advance while this thread burns CPU, polled every ~25 ms for up to one second, probed once per process and cached. Liveness is decided on the raw integer before unit conversion, and never on the summed total, because the live GPU rail is exactly what corrupts the total. Otherwise the rung is declined and the time×power model estimates, as the contract requires. `IoReportStatus` (`Unavailable`, `CpuRailAbsent`, `CpuRailFrozen`, `Live`) is exposed so a caller or receipt can say why an Apple Silicon host is being estimated. The change is additive: `mod ioreport` is private and nothing outside the crate matches on `Meter`. Tests. The flaky test is replaced by three that assert against an independent oracle: it reads the CPU rail's ABSOLUTE cumulative value with no delta samples, matches names with `ends_with("CPU Energy")` rather than the implementation's die-prefix stripping, and burns for three times the probe's budget. There is no early return that passes without asserting — a host with no IOReport must report `Unavailable`, one with no CPU rail `CpuRailAbsent`. - `the_ioreport_rung_is_never_selected_on_a_frozen_cpu_rail` — the property that matters. It logs what it observed so a CI log shows which branch was asserted. - `the_liveness_probe_never_reports_a_frozen_rail_as_live` — the dangerous direction, asserted on its own. - `a_selected_ioreport_meter_meters_cpu_work` — when the rung IS selected, a CPU burn meters as non-zero energy. Observed on both machines: `status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false`, 10/10 passing — on the M3 Ultra via the `DIE_0_`/`DIE_1_` rails, which confirms the multi-die path. The CI job becomes deterministic: green while the meter correctly declines a frozen rail, red if it ever selects one. Falsified: a probe that always says Live fails the test (the oracle saw the rail hold); reverting `detect()` to select IOReport whenever it opens — main's behaviour — fails it with "IOReport selected although its CPU rail did not move", so main fails this test today. jcp-cli, jcp-conformance and jcp-intercept (every dependant of this crate) pass, as does the conformance suite's C9 energy-honesty check; clippy is clean on jcp-energy. jcp-gateway fails on main as well and does not depend on this crate — it meters through sandbox-meter's probe, which reads the same frozen rail. Not done here, deliberately: - A per-span check for a rail that freezes after `detect()` needs "CPU Stats" residency as a witness; the platform-level freeze observed here is caught at selection. - Reporting the live GPU rail as an explicitly partial reading, instead of declining, would need a coverage field on the intercept/1 wire — a format change, so a separate decision. - The same defect in jouleclaw-energy, eoc-meter, proof-cascade and sandbox-meter, and in the callers that seal a zero delta as a measurement. Co-Authored-By: Claude Opus 5.5 <[email protected]>Round 3 left three mutations alive and one assertion whose margin shrank with load. This Mac is also the macOS CI runner, often at load averages of 24-104, so every pin on how the probe paces itself had to stop depending on wall time. This commit closes all four. What changes in the probe: - A tick now burns thread CPU time. It spins until the thread's own clock, clock_gettime(CLOCK_THREAD_CPUTIME_ID), has advanced 25 ms, with a 500 ms wall-clock cap. Before, a tick spun 25 ms of wall time, and on a loaded host that is a few milliseconds of CPU. Under 36 extra spinners, the old tick got a median of 3.2 ms of CPU in 48 ms. - The probe records the wall time of each of its own FFI sample calls, and the CPU and wall time of each tick. Tests read how it sampled and burned from that record, not by timing it from outside. - With no Energy Model subscription, the status is now Unavailable, through the same pure status_of as a probe that saw no interval. Before, a failed group open beside an openable counter said CpuRailAbsent, which claims a group was read and had no CPU rail. probe_with() is generic over the opener, so that path now runs in a test. Tests: - Group-only subscription: the MEDIAN wall time of the probe's own sample calls is under 50 ms. Group samples measured 5.7-12.8 ms; all-channel ones 142-714 ms. This replaces the >= 10-interval floor. No hardware test asserts a wall-clock ratio. - Burning: thread CPU per interval is at least 12.5 ms by the tests' own clock (clock_gettime_nsec_np); only the 500 ms wall cap could cut it short, and the message says so. From the probe's record, every tick burned 25 ms of thread CPU or hit the cap, and a tick came before every re-sample. - New: the_probe_sampler_reads_each_cpu_rail_as_the_oracle_does. The oracle reads each Energy Model CPU and GPU rail absolutely, on its own all-channel subscription, before and after each of two probe samples. A rail it saw hold must read EQUAL in the probe's sample; a rail that moved must read between the two. This catches a sampler that returns constant 0 (round 3's X3), sums rails, or reads the wrong channel. - Pure-rule pins, one test each: a decrease is not an advance (X5); a rail missing from the previous sample only sets its baseline; no subscription, or no sample, is Unavailable (X4); no verdict is Unavailable. - Oracle evidence: fewer than two reads after the first is now a failure (Oracle::TooFewReads), never CpuRailMoved(false). The oracle extends its 3 s window up to 5x to get the two reads. - The cache pin is process-wide. Eight threads, released together by a barrier, ask for the status and build the meter. The static PROBE_RUNS counter must read exactly 1. - The IOReport hardware tests now share one lock. Side by side, one test's all-channel reads slowed another's group samples: max sample calls reached 132-279 ms, and 12 probes at once pushed the median to 112 ms. Serialised, the median is 6-13 ms. The suite takes ~12-16 s instead of ~5 s. - `the_ioreport_rung_is_never_selected_on_a_frozen_cpu_rail` still prints "ioreport liveness: status=". It now shows how long the oracle actually read. Evidence, on this exact tree: - M5 Max, 10 runs of the lib tests with 36 extra spinners (2 x hw.ncpu), at 1-minute load averages of 61-180: 31/31 in all 10. Median sample cost was 7.0-12.8 ms, thread CPU per interval 32.3-33.6 ms, CPU per tick 25.00 ms, and the oracle took 5-17 reads. Every run printed status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false. - M3 Ultra, same binary: 31/31. DIE_0 and DIE_1 read equal to the oracle (28237793 and 30845042), and the median sample cost was 5.9 ms. - Each mutation below was restored with git checkout, and each one fails a test: X3 constant-0 sampler, X4 no subscription -> Live, X5 decrease counts, a new rail counts, per-thread cache, sum of CPU-named rails, GPU value given as CPU, tick sleeps, tick is a no-op (both the burn call and the closure), tick burns wall time, probe on the all-channel subscription, no OnceLock, compare with the first sample, TimePower{0} when declined, None -> Live, and a coarse threshold. Summing the CPU Energy rails is the identity on the M5 Max's single rail, so it cannot fail there. On the M3 Ultra it fails: "held at 28237793 ... but the probe's sampler read 59082835". - jcp-cli, jcp-conformance (lib and pack) and jcp-intercept pass. So does the conformance suite, including "C9 energy provenance honesty", on both machines. clippy --no-deps is clean for aarch64-apple-darwin, x86_64-apple-darwin and x86_64-unknown-linux-gnu, with and without --tests. Not done here, deliberately: - C9 still meters `|| ()`, so a declined meter giving 0 passes it. That is a conformance-suite change. - The standards-build.yml comment is stale, and its job lacks --nocapture. PR #102 owns that workflow. - read_uj still samples every channel. counts_once admits CPU sub-rails that do not contain "cpu" (e.g. PACC_*) beside CPU Energy, a double count once a rail is live. The receipt carries no IoReportStatus (a wire decision). CPU_RAIL_LIVENESS_BUDGET is public on macOS only. Co-Authored-By: Claude Opus 5.5 <[email protected]>The CPU-rail liveness rule said Live once the same CPU rail had advanced in two separate sample intervals. On 2026-09-30 the jouleclaw-energy verifier found a batch refresh that passes it. On this M5 Max (macOS 27.0.1), a group-only watcher sampling the Energy Model every ~16 ms saw a refresh published in two steps: CPU Energy 2643843378 -> 2705607863 (+61764485) CPU Energy 2705607863 -> 2705611298 (+3435) 64 ms later and MCPU0, MCPU1 and PCPU each stepped twice with it. The probe's intervals are ~31 ms (a 25 ms thread-CPU tick and a ~6 ms sample), so a probe window holding such a refresh sees two advancing intervals and says Live, and the Live is cached for the process. Two real probes did say Live while the oracle saw no sustained movement, coinciding with a refresh. Refreshes are ~30 minutes apart, so this is rare, but it is exactly the failure the rule exists to prevent: the rung selected on a frozen rail, and every later refresh billed whole to whichever metered span straddles it. The rail on this host still holds at 2,705,611,298, the value that refresh left. The rule is now, for one CPU rail (name + ordinal): - it advanced in at least MIN_LIVE_ADVANCES = 5 distinct intervals; - those are at least 80% of all the intervals observed so far (advancing * 5 >= intervals * 4); - the window observed so far spans at least MIN_LIVE_WINDOW = 300 ms of wall time from the first usable sample. It is checked after each interval, and the rail is Live from the first interval at which all three hold. The probe keeps sampling until Live, or until the 1 s budget has elapsed and at least five intervals were observed, capped at five budgets. A live rail is now called live about 300 ms in (12 intervals on an idle host) rather than ~60 ms. The rule needs each interval's wall time, so watch() reads the clock after every sample and hands that reading to RailWatch::observe; the tests script it. Everything else stands: per-rail keys, consecutive samples, a fall or a first appearance is no advance, one advance per rail per interval, the group-only subscription, the thread-CPU tick, the pure status mapping, the OnceLock, the test seams, and the "ioreport liveness: status=" line. The oracle gets the same spirit. CpuRailMoved(true) now needs one rail to have changed at 5 or more reads making up at least 80% of its reads. Its all-channel reads are 0.13 s or more apart, so even a refresh spread over 150 ms shows as three changes at most, and a refresh coinciding with the probe can no longer vouch for the Live it caused. It extends its window, up to 5x, until it has five reads after the first, and still fails as TooFewReads when it cannot. Its loop is now oracle_watch_with, over a read function and a clock, so its verdict is tested on scripts. Tests, on a scripted clock at 31 ms an interval unless stated; (*) fail under the two-advance rule: - (*) the observed two-step refresh, with the steps in consecutive intervals, 62 ms apart, and on a host at 160 ms an interval: Frozen; - (*) a refresh in 3, 4 or 5 steps within 150 ms at the start of the window, and in 5 steps mid-window: Frozen; - (*) the M3 Ultra shape, both dies stepping twice within 64 ms: Frozen; - a rail advancing in every interval: Live at the 10th (310 ms), not at the 5th (155 ms), on either die; - missing 1 interval in 5 (exactly 80%): Live; missing 2 in 5: never; on a loaded host, 2 early misses: not at 5 of 7, 6 of 8 or 7 of 9, Live at 8 of 10; - a loaded host at 100 ms an interval: Live at the 5th (500 ms), not at the 3rd, where the window is already met; - keep-sampling: at 600 ms an interval the probe goes past the budget to five intervals (where a live rail is proven Live, at 3 s); at 1.5 s it stops at the 5 s cap with four; - through probe_with: a sustained advance is Live at 10 intervals, and (*) the two-step refresh is Frozen; - through host_status itself (the real opener, burn tick and clocks, with scripted FFI reads): (*) the two-step refresh is CpuRailFrozen; a sustained advance is Live with 5+ advances over a 300+ ms window by both the probe's clock and the tests' own, stopping as soon as it is live; - the two-die summing check now has the dies advance in turn (each in half the intervals, summed in all): two one-step dies, summed, are only two advances, which no longer trips the rule; - the oracle on scripts: the two-step refresh is CpuRailMoved(false) (it was true), a three-step refresh false, a change at every read true at the 5th, 4 in 5 true, 3 in 5 false; slow reads are extended to five, reads too slow for that are TooFewReads. Mutations, each a temporary edit restored with git checkout, the tree clean after each: - MIN_LIVE_ADVANCES = 2: 4 tests fail (the two-step refresh on a loaded host, loaded-host Live before the 5th interval, keep-sampling, the stopping rule); - the 80% check removed: 4 fail (the 80% test, the 5-step refresh, two dies in turn through probe_with and through host_status); - the 300 ms window removed: 6 fail (Live at the 10th, the 80% test, the 5-step refresh at the start, the sustained advance through probe_with and through host_status, the stopping rule); - the oracle's bar back to >= 2 changes: both oracle tests fail. The whole old oracle (2 changes, 2 reads) fails with "a two-step refresh vouched for a moving rail: OracleRun { verdict: CpuRailMoved(true), reads: 4, ..., cpu_changes: [2] ..."; - the whole old rule (2 advances, no share, no window): 15 fail, every (*) test among them. Runs. The crate's tests pass (51 lib, 1 integration). Three runs under a helper process sampling IOReport over all channels back to back (~250-280 ms a sample, load average 14-16), 51/51 each: ioreport liveness: status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false (oracle: 6 reads over 3.857275292s of a 3s window with a helper thread burning CPU; changes per CPU rail [0], per GPU rail [4]) ioreport liveness: status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false (oracle: 7 reads over 3.051596791s of a 3s window with a helper thread burning CPU; changes per CPU rail [0], per GPU rail [6]) ioreport liveness: status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false (oracle: 9 reads over 3.133878417s of a 3s window with a helper thread burning CPU; changes per CPU rail [0], per GPU rail [5]) On the M3 Ultra (macOS 27.0.1), the same binary, 51/51: ioreport liveness: status=CpuRailFrozen oracle=CpuRailMoved(false) selected=false (oracle: 21 reads over 3.033503042s of a 3s window with a helper thread burning CPU; changes per CPU rail [0, 0], per GPU rail [19]) jcp-cli (it builds; it has no tests), jcp-conformance (with the conformance binary: all checks passed, C9 energy provenance honesty among them) and jcp-intercept pass. Clippy --no-deps and rustdoc over private items with -D warnings are clean on jcp-energy. Co-Authored-By: Claude Opus 5.5 <[email protected]>jcp-energy: never select IOReport when its CPU rail is frozento jcp-energy: IOReport only when its CPU rail keeps advancing, never on a batch refresh