jcp-energy: meter a closure's CPU work with the per-process energy counter, which macOS 27 keeps live #122

Merged

dcharlot merged 3 commits from jcp-energy/process-energy into main 2026-10-01 06:02:25 -04:00

Conversation 0 Commits 3 Files changed 3 +1280 -52

dcharlot commented 2026-09-30 21:10:59 -04:00

Owner

Copy link

Stacked on #110 (base jcp-energy/cpu-rail-liveness). Merge #110 first; this PR then retargets to main.

On macOS 27 an unprivileged process sees IOReport's CPU rails republished only in lumps, so #110 makes jcp-energy fall back to time×power there. The kernel keeps a per-process counter, ri_energy_nj from proc_pid_rusage(getpid(), RUSAGE_INFO_V6), and that one is live. It is a public libproc call, with no privilege. Meter::measure(closure) runs its work in-process, so a per-process reading is the work's own CPU energy.

The rung

• Meter::ProcessEnergy reads ri_energy_nj around the closure and grades the figure HwShunt.
• Order. It sits below RAPL/NVML and above IOReport: a per-process figure attributes the work's own CPU energy, where IOReport is SoC-wide.
• Liveness. The shared rule from #110, cached once per process; it is Live in about 310 ms. A span where the count did not advance gets the time×power figure, graded ModelBased.
• Domain, documented exactly. This process's threads; not other processes, children, GPU, ANE or DRAM. A span where the process's children did work is graded Partial (see Updates).
• Explanation API, additive. Rung, Meter::rung(), Detection, Meter::detect_explained().

Measured (macOS 27.0.1)

	M5 Max	M3 Ultra
status	Live (12 intervals, 315 ms)	Live (12 intervals, 300 ms)
200 ms one thread	0.403 J, HwShunt, Whole	1.355 J
200 ms asleep	77 µJ	744 µJ
1 thread vs 2 threads	0.623 J vs 1.222 J (×1.96)	1.328 J vs 2.173 J (×1.64)
a span running a child (yes, 200 ms)	6,993 µJ; the child's own 0.350 J is not counted	3,351 µJ; the child's 1.214 J is not counted

Mutations caught (11):

• reading another pid;
• a constant;
• liveness ignored in detect;
• a cached status with no probe;
• ModelBased grading;
• a non-advancing span graded as a reading;
• truncating nJ→µJ;
• decoding the wrong word;
• IOReport ranked above this rung;
• an uncached status.

jcp-intercept, jcp-schema and jcp-conformance are green, and the conformance binary prints "all checks passed".

Behaviour change: on macOS, detect() now selects this rung and never probes IOReport. A span shorter than the counter's ~0.5 ms update falls back to the model.

Updates

• 830fc085: a span where children did work is Partial. The span is graded Whole only if the process's reaped-children CPU time held and no child is alive at span end; otherwise it is Energy::measured_partial.
  • Verified on the M3 Ultra: a reaped yes gives Partial at 1,322 µJ (the child's own 1.246 J is excluded), a child left running gives Partial, and a pure burn gives Whole at 1.366 J.
  • Spawning by absolute path avoids a false Partial from a failed posix_spawn.
• 22e5a6ad: the one-thread test's floor is 0.1 J. The burn already counts 200 ms of the thread's own CPU, but the energy that costs ranges 0.18–1.24 J by core class. The kernel caps a test binary at default QoS, so asking for user-interactive does nothing. The floor is now 0.1 J, still the sleeping test's ceiling. All 5 runs pass under 18 spinners.
• Rebased onto #110's final head, which includes the every-rail rule and RAPL package zones.

🤖 Generated with Claude Code

> **Stacked on #110** (base `jcp-energy/cpu-rail-liveness`). Merge #110 first; this PR then retargets to `main`. On macOS 27 an unprivileged process sees IOReport's CPU rails republished only in lumps, so #110 makes jcp-energy fall back to time×power there. The kernel keeps a per-process counter, `ri_energy_nj` from `proc_pid_rusage(getpid(), RUSAGE_INFO_V6)`, and that one is **live**. It is a public libproc call, with no privilege. `Meter::measure(closure)` runs its work in-process, so a per-process reading is the work's own CPU energy. ### The rung - **`Meter::ProcessEnergy`** reads `ri_energy_nj` around the closure and grades the figure HwShunt. - **Order.** It sits below RAPL/NVML and above IOReport: a per-process figure attributes the work's own CPU energy, where IOReport is SoC-wide. - **Liveness.** The shared rule from #110, cached once per process; it is Live in about 310 ms. A span where the count did not advance gets the time×power figure, graded ModelBased. - **Domain, documented exactly.** This process's threads; not other processes, children, GPU, ANE or DRAM. A span where the process's children did work is graded **Partial** (see Updates). - **Explanation API, additive.** `Rung`, `Meter::rung()`, `Detection`, `Meter::detect_explained()`. ### Measured (macOS 27.0.1) | | M5 Max | M3 Ultra | |---|---|---| | status | `Live` (12 intervals, 315 ms) | `Live` (12 intervals, 300 ms) | | 200 ms one thread | 0.403 J, HwShunt, Whole | 1.355 J | | 200 ms asleep | 77 µJ | 744 µJ | | 1 thread vs 2 threads | 0.623 J vs 1.222 J (×1.96) | 1.328 J vs 2.173 J (×1.64) | | a span running a child (`yes`, 200 ms) | 6,993 µJ; the child's own 0.350 J is not counted | 3,351 µJ; the child's 1.214 J is not counted | **Mutations caught (11):** - reading another pid; - a constant; - liveness ignored in `detect`; - a cached status with no probe; - ModelBased grading; - a non-advancing span graded as a reading; - truncating nJ→µJ; - decoding the wrong word; - IOReport ranked above this rung; - an uncached status. jcp-intercept, jcp-schema and jcp-conformance are green, and the conformance binary prints "all checks passed". **Behaviour change:** on macOS, `detect()` now selects this rung and never probes IOReport. A span shorter than the counter's ~0.5 ms update falls back to the model. ### Updates - **`830fc085`: a span where children did work is Partial.** The span is graded Whole only if the process's reaped-children CPU time held and no child is alive at span end; otherwise it is `Energy::measured_partial`. - Verified on the M3 Ultra: a reaped `yes` gives Partial at 1,322 µJ (the child's own 1.246 J is excluded), a child left running gives Partial, and a pure burn gives Whole at 1.366 J. - Spawning by absolute path avoids a false Partial from a failed `posix_spawn`. - **`22e5a6ad`: the one-thread test's floor is 0.1 J.** The burn already counts 200 ms of the thread's own CPU, but the energy that costs ranges 0.18–1.24 J by core class. The kernel caps a test binary at default QoS, so asking for user-interactive does nothing. The floor is now 0.1 J, still the sleeping test's ceiling. All 5 runs pass under 18 spinners. - **Rebased onto #110's final head**, which includes the every-rail rule and RAPL package zones. 🤖 Generated with [Claude Code](https://claude.com/claude-code)

dcharlot added 1 commit 2026-09-30 21:11:00 -04:00

jcp-energy: meter this process's own CPU energy, live where IOReport is not ... c3bf64ec40

On macOS 27.0.1 an unprivileged reader sees IOReport's CPU rails republished
in lumps, so the IOReport rung is declined on both the M5 Max and the M3 Ultra,
and every span gets the time×power estimate. The kernel keeps a live count
that this crate did not read. `proc_pid_rusage(getpid(), RUSAGE_INFO_V6, ...)`
from libproc (public API, no entitlement, no privilege) fills
`rusage_info_v6`, and its `ri_energy_nj` is the cumulative CPU energy the
kernel attributes to this process's threads. Measured on the M5 Max: 0.002 J/s
idle, 2.4 J/s with one thread burning, 5.3 J/s with two, changing about every
0.5 ms while polled. This commit adds it as a rung.

The rung. `Meter::ProcessEnergy` reads `ri_energy_nj` before and after the
closure `measure` runs. It is graded `HwShunt` (the owner's decision is that
vendor counters are readings) with `Coverage::Whole` for in-process CPU work.
Its domain is documented on the variant, on its module and in SPEC §5.1: the
CPU energy of this process's threads during the span, every thread of the
process and not only the one running the closure. It excludes other
processes, child processes, the GPU, the Neural Engine and DRAM.

Order. The rung sits below RAPL and NVML and above IOReport. Both it and
IOReport are vendor readings, but they read different domains. The
per-process count is the work's own CPU energy. IOReport's counter is
SoC-wide: it takes in every other process and the machine-wide GPU rail.
Where both are live, the work's own figure wins. RAPL and NVML do not exist
on macOS, so its place relative to them changes nothing there.

Liveness. The rung uses the sustained-advance rule that 475680ab shared
(`liveness::probe`), applied to `ri_energy_nj` while the probing thread burns
25 ms ticks of its own CPU. The result is cached once per process as
`process_energy_status()`, and the counter is Live in about 310 ms on both
chips. A span over which `ri_energy_nj` did not advance gets the time×power
figure at `ModelBased`, as IOReport's held spans do. A rise is rounded up to
whole µJ, so a span that spent energy never reads as zero.

FFI. The decoding is pure: `rusage_v6::decode` reads the two words at bytes
336 and 344 of the 464-byte struct. Those are the C compiler's `sizeof` and
`offsetof` for `struct rusage_info_v6` against the macOS 26, 26.5 and 27 SDKs,
which agree. The 27 SDK named three of the nine reserved words the 26 SDKs
had, and nothing before them moved. The read goes into a 464-byte buffer with
8-byte alignment.

Status. All additions; no existing name changes. `process_energy_status()`,
`enum Rung`, `Meter::rung()`, `struct Detection` and
`Meter::detect_explained()`, which returns the meter together with the
selected rung and the cached status of every rung asked on the way to it. A
rung below the selected one is never asked, so its probe never runs and its
status is `None`. `Meter::detect()` is now `detect_explained().0`.

Consequences. On this M5 Max `detect()` now selects ProcessEnergy and never
probes IOReport: in a fresh process the IOReport probe runs 0 times. The first
`detect()` therefore burns about 310 ms of CPU, where the IOReport probe
burned about one second. Spans shorter than the count's update interval fall
to the model's figure. jcp-cli's demo probe, a 20,000-term sum, now prints
"meter   HwShunt backend → 2171 µJ probe (estimated, and says so)". Three
IOReport hardware tests asked `detect()` whether IOReport was selected, and
`detect()` no longer reaches IOReport here. They now ask the IOReport gate
itself, with the rungs above it declined (`Ladder::ioreport_only()`).

Tests, with no skip-as-pass. jcp-energy has 75 lib tests (63 before) and its
integration test. All pass on the M5 Max with and without `--features nvml`,
and 75/75 pass on the M3 Ultra.
- Pure, on every platform. The layout constants equal the C compiler's
  literals and `offset_of!` on a field-by-field transcription of the SDK
  struct. On a buffer of distinct bytes, decoding reads exactly bytes 336..344
  and 344..352, and a literal little-endian buffer decodes to 2,400,000,000 nJ
  and 1. A span is a reading only on a rise: 480,000,001 nJ gives 480,001 µJ,
  and 500 nJ gives 1 µJ. A count that held, fell or failed to read gets the
  model's figure. The probe on a scripted count is Live at the tenth interval
  and Frozen when the count holds.
- The gate and the order, on macOS. Only Live selects the rung and opens its
  counter. When it is declined, the ladder goes on to IOReport and
  `Detection` says so. With the per-process rung Live, IOReport is never
  asked; with RAPL Live, the per-process status is never asked. Off macOS the
  rung is never selected.
- Against the hardware, on macOS. Each test runs in a fresh process of its
  own, because the count covers the whole process and tests running beside it
  would land in its spans. The rung is Live, and `detect_explained()` reports
  it with IOReport unasked. The reader's count sits between two reads of this
  pid by the tests' own oracle, which uses its own FFI declaration and the
  transcribed struct. 200 ms of one thread's CPU is `HwShunt`, whole, and
  between 0.2 and 20 J. 200 ms asleep meters under 0.1 J. Two threads meter
  more than one. A span that runs `yes > /dev/null` for 200 ms, then kills
  and reaps it, meters under 0.1 J, while the oracle reads the child's own
  count at 0.1 J or more.

M5 Max, verbatim from the final run:
  process energy: status=Live (first call took 316.761333ms); a fresh probe:
    Live after 12 intervals over a 314.907375ms window, advances
    [("ri_energy_nj", 12)], in 314.914166ms; detect_explained: Detection {
    selected: ProcessEnergy, rapl: Some(Unavailable), nvml: Some(Unavailable),
    process_energy: Some(Live), ioreport: None }; IOReport probe runs = 0
  process energy: 200 ms of one thread's CPU -> 402729 µJ (0.403 J), HwShunt,
    coverage Whole
  process energy: 200 ms asleep -> 77 µJ (0.000077 J), HwShunt
  process energy: 200 ms of CPU on 1 thread -> 623347 µJ (0.623 J), on each
    of 2 threads -> 1221565 µJ (1.222 J), ratio 1.96
  process energy: a span running `yes > /dev/null` for 200 ms -> 6993 µJ
    (0.006993 J), HwShunt; the child's own count 350042940 nJ (0.350 J)
Over five more runs of these five tests: one thread 0.41-0.53 J, a 2-to-1
thread ratio of 1.73-2.09, asleep 0.2-1.0 mJ, and the child span 1.2-25 mJ
against the child's own 0.32-0.46 J.

M3 Ultra, verbatim. The lib test binary was built here with
`target-cpu=apple-m1` (the global config builds native to the M5), copied to
10.10.10.2 (sha256 acf9bac254c0f97b... on both ends), run with --nocapture,
then deleted:
  process energy: status=Live (first call took 300.089625ms); a fresh probe:
    Live after 12 intervals over a 300.076ms window, advances
    [("ri_energy_nj", 12)], in 300.079042ms; detect_explained: Detection {
    selected: ProcessEnergy, rapl: Some(Unavailable), nvml: Some(Unavailable),
    process_energy: Some(Live), ioreport: None }; IOReport probe runs = 0
  process energy: 200 ms of one thread's CPU -> 1354645 µJ (1.355 J),
    HwShunt, coverage Whole
  process energy: 200 ms asleep -> 744 µJ (0.000744 J), HwShunt
  process energy: 200 ms of CPU on 1 thread -> 1328119 µJ (1.328 J), on each
    of 2 threads -> 2172758 µJ (2.173 J), ratio 1.64
  process energy: a span running `yes > /dev/null` for 200 ms -> 3351 µJ
    (0.003351 J), HwShunt; the child's own count 1213689002 nJ (1.214 J)
  ioreport liveness: status=CpuRailFrozen oracle=CpuRailMoved(false)
    selected=false
jcp-intercept (12), jcp-schema (30) and jcp-conformance (1 unit test and 5
pack tests) pass. The jcp-conformance binary prints "all checks passed", and
jcp-cli runs. clippy --no-deps is clean on jcp-energy with and without `nvml`,
for aarch64-apple-darwin, x86_64-apple-darwin and x86_64-unknown-linux-gnu.
`cargo doc` with `-D warnings` is clean.

Falsified, each by a temporary edit restored with git checkout (git diff was
empty after each):
- Reading another pid (the parent's, via getppid) fails all five hardware
  tests. The probe sees the idle parent's count hold: "detect() did not
  select the per-process rung: Detection { selected: TimePower, ...,
  process_energy: Some(Frozen), ioreport: Some(CpuRailFrozen) }".
- A reader that returns a constant fails the same five, the same way.
- Ignoring liveness in `detect` (opening the rung whatever its status) fails
  `only_a_live_status_selects_the_process_energy_rung` ("status Unavailable
  gave ProcessEnergy(...)") and the order test. A cached status of Live with
  no probe fails the fresh-process pin ("the per-process liveness probe ran 0
  times").
- Grading the rung `ModelBased` fails `the_process_energy_rung_is_live_here`.
  Grading an advancing span with `Energy::modeled` fails the pure span test
  and four hardware tests ("provenance: ModelBased").
- Grading a span with no advance as a reading fails the span test ("held:
  ... measured_uj: Some(0) ... HwShunt"). Truncating nJ to µJ fails it too
  (480000, not 480001).
- Decoding the word before `ri_energy_nj` fails the decoding test and the
  oracle check ("the reader's ri_energy_nj 977683212 is not this process's
  (1464983856 .. 1464983856)").
- Ranking IOReport above the per-process rung fails three tests. An uncached
  status fails the pin ("ran 32 times").

Not done here:
- `Whole` assumes the work stays on this process's CPU threads. A closure
  that hands work to a child process or to the GPU is under-counted, and the
  figure still says `Whole`, because the meter cannot see that. The domain
  says so, and the child test pins the boundary. Grading such work `Partial`
  would need the caller to say what it does.
- The figure is process-wide. Concurrent unrelated threads of the same
  process land in a span and over-debit it, as other processes do under a
  package counter.
- The one-thread lower bound of 0.2 J has the least margin: the lowest seen
  on the M5 Max under load was 0.351 J.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

dcharlot force-pushed jcp-energy/process-energy from c3bf64ec40 to e22f42721e 2026-09-30 21:48:02 -04:00 Compare

dcharlot force-pushed jcp-energy/process-energy from e22f42721e to 05b996fdf4 2026-09-30 22:05:32 -04:00 Compare

dcharlot force-pushed jcp-energy/process-energy from 05b996fdf4 to 830fc085f2 2026-09-30 22:05:54 -04:00 Compare

dcharlot added 1 commit 2026-09-30 22:48:24 -04:00

jcp-energy: the one-thread burn's floor fits the energy its cores can take ... 22e5a6ad9f

`one_thread_burning_200_ms_is_a_whole_hardware_reading` asserts that 200 ms
of one thread's CPU meters between 0.2 J and 20 J. On a loaded host it read
218,593 µJ in one run and fell under the floor in another. The work was not
what varied. Since bcd00518 the burn has spun until the thread's own CPU
clock (`CLOCK_THREAD_CPUTIME_ID`) advanced 200 ms, so every run did the same
200 ms of CPU. What varied is the energy of that work: it follows the core
tier and the clock the scheduler gives the thread, and 0.2 J was at the
bottom of that range.

Measured on an M5 Max (6 Super and 12 Performance cores), macOS 27.0.1,
reading the process's own `rusage_info_v6` around each burn:
- At the default QoS, 200 ms of one thread's CPU read 0.20-0.24 J in one
  quiet period, 0.50-0.61 J in another, 0.32-0.54 J with 6 to 30 busy-loop
  spinners, and up to 1.24 J. The effective clock (`ri_cycles` over the CPU
  time) was 2.5-4.0 GHz in the runs that logged it.
- In two runs held on the slower cores by background QoS (`ri_user_ptime`
  about zero), it read 0.18 J and 0.24 J at about 2 GHz. The 0.18 J run
  failed the floor.

Asking for user-interactive QoS, as eoc-meter's process-energy test does,
does not keep the thread off the slower cores. XNU clamps user-interactive
and user-initiated QoS to the default in a process with no application role,
and a test binary run by `cargo test` is one. After
`pthread_set_qos_class_self_np(QOS_CLASS_USER_INTERACTIVE, 0)` returned 0,
the burn's CPU time was all in `ri_cpu_time_qos_legacy` (the default QoS)
and none in `ri_cpu_time_qos_user_interactive`. A request for user-initiated
QoS landed in the default too. Requests for utility and background QoS were
not clamped: none of their CPU time was counted at the default. So the tests do not ask, and the burn helper's doc says why.

The changes, all in the test module:
- `burn_thread_cpu` stops at 5 s of wall time (`TESTS_BURN_WALL_CAP`) and
  fails the test with a message that says how much CPU the thread got, rather
  than spinning on unbounded. It returns the wall time the burn took, which
  the burn tests now log. The cap was seen to fire, with the burn held at
  background QoS under 18 spinners: "this thread got only 3.752959ms of the
  200ms of CPU it was to burn in 5s of wall time: the host is too loaded to
  meter a fixed amount of CPU work".
- The floor is 0.1 J, half the lowest reading above. It still means
  something. It meets the 0.1 J ceiling of
  `sleeping_200_ms_meters_under_a_tenth_of_a_joule`, so no counter that reads
  wall time at a fixed power passes both tests. A counter that holds fails
  before the floor is reached, and one that advances by a fixed step per read
  fails the floor (see below). The test's doc records the measured range.
- `two_threads_burning_meter_more_than_one` joins its second thread, so a
  burn that hits the cap there fails with its own message, and logs both
  spans' wall times.
- `a_span_that_runs_and_reaps_a_child_is_partial` had the same shape: `yes`
  ran for 200 ms of wall time and the test then required the child's own
  count to read at least 0.1 J. Under load it read 0.216 J once. The child
  now runs for at least 200 ms and until its own count, polled every 10 ms,
  reads 0.1 J. The test fails, saying so, if that takes 5 s.

Tests. `cargo test -p jcp-energy` (84 lib tests and the integration test)
passed 5 times in a row with 18 busy-loop spinners running, at load
averages from 24 to 100. The spinners were killed by a trap, and none
remained after. Per run, one thread's 200 ms of CPU, then the two-thread
test's one and two threads, then the reaped child's own count:
- 0.353 J (271 ms wall); 0.366 / 0.718 J; 0.340 J
- 0.358 J (297 ms); 0.346 / 0.739 J; 0.334 J
- 0.400 J (393 ms); 0.376 / 0.703 J; 0.324 J
- 0.367 J (367 ms); 0.411 / 0.762 J; 0.334 J
- 0.422 J (670 ms); 0.386 / 0.837 J; 0.316 J
Clippy is clean on jcp-energy with `--tests`. The change is inside
`#[cfg(test)] mod tests`, so no dependant compiles different code.

Falsified, each by a temporary edit restored with git checkout:
- `ri_energy_nj` read as a constant: the probe finds it Frozen, `detect()`
  declines it, and the test fails with "detect() did not select the
  per-process rung".
- The count held across the measured span only, detection untouched: the
  span is the model's figure (3.05 J, `ModelBased`) and the test fails on its
  provenance. That figure is inside the bounds, so this case rests on the
  provenance assertion, not the floor.
- The count advancing a fixed 1,000 nJ per read: the probe finds it Live, the
  span is 1 µJ `HwShunt`, whole, and the test fails with "200 ms of one
  thread's CPU metered 1 µJ".

Not done here: eoc-meter's process-energy test asks for user-interactive QoS
and its doc credits it with keeping the burn on the fast cores. The same
clamp applies there.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

dcharlot changed target branch from jcp-energy/cpu-rail-liveness to main 2026-10-01 05:46:03 -04:00

dcharlot merged commit 819e9759de into main 2026-10-01 06:02:25 -04:00

dcharlot referenced this pull request from a commit 2026-10-01 06:02:27 -04:00

Merge pull request 'jcp-energy: meter a closure's CPU work with the per-process energy counter, which macOS 27 keeps live' (#122) from jcp-energy/process-energy into main

Sign in to join this conversation.

Reviewers

No reviewers

Labels

Clear labels

No items

No labels

Milestone

Clear milestone

No items

No milestone

Projects

Clear projects

No items

No project

Assignees

Clear assignees

No assignees

1 participant

Notifications

Subscribe

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference

Transaction-Science/open-standards!122

No description provided.