Skip to content

fix: sample IOReport continuously and poll local mode at its own cadence - #286

Merged
inureyes merged 1 commit into
mainfrom
fix/ioreport-continuous-delta
Jul 27, 2026
Merged

fix: sample IOReport continuously and poll local mode at its own cadence#286
inureyes merged 1 commit into
mainfrom
fix/ioreport-continuous-delta

Conversation

@inureyes

@inureyes inureyes commented Jul 27, 2026

Copy link
Copy Markdown
Member

Follow-up to #285. While checking why the history graph's time axis was uneven, two defects turned up in the local-mode collection path that compounded each other.

Problem 1: IOReport opened its own measurement window

IOReport::get_sample took a sample, slept 100ms, took a second one, and returned the delta. collect_once averaged four of those. So each collection blocked its caller ~495ms and observed 400ms of wall time. At the effective 3.5s period that is 14% of elapsed time: whatever happened in the other 86% never reached the graphs. The blocking also ran directly inside a tokio::join! arm in local_collector.rs:280-290, while the process collection immediately below it uses spawn_blocking for exactly this reason.

Problem 2: local mode asked for the remote cadence

run_local_mode called EnvConfig::adaptive_interval(1). The 1 reads as "one host" but selects the 1..=10 => 3 remote-nodes arm, so local mode polled at 3s and the node_count == 0 arm, commented // Local monitoring only (no remote nodes), was unreachable. main.rs:332,344 assumed unwrap_or(2) for the same run, so one binary carried three different local defaults.

Change

Continuous delta. Every subscribed channel is a cumulative counter (energy in the Energy Model group, residency ticks in CPU/GPU stats), so a delta between any two samples is exactly the activity between them. get_sample_since_last retains the newest sample and differences the next call against it: no sleep, one IOReportCreateSamples per poll, and a window equal to the full polling interval. The prev_sample field this needs was already declared on IOReport but had never been written to. Deltas below MIN_DELTA_WINDOW (50ms) report no result instead of dividing counters by a near-zero interval, and leave the baseline in place so a fast caller still accumulates one. get_sample stays for the first collection of a session. Averaging four samples is gone: one long delta already is the interval's time average.

Named local cadence. Local call sites use EnvConfig::local_interval() and never spell out a node count, which removes the class of bug rather than the instance. main.rs's two unwrap_or(2) sites use it too.

Uniform cache. The 5s window for the first ten collect_once calls existed to absorb the old blocking. It also made the first ~10 seconds of every history graph a staircase of repeated values. Replaced by a single CACHE_DURATION_MS, which still dedupes the several readers that run within one collection cycle.

Measurements

M5 Max, release build, 200x50 tmux, 60s per run. (Corrected after merge: an earlier revision of this body said M1 Ultra, which was the machine in the reporting screenshots, not the machine these numbers were taken on.)

Collection cost in isolation:

before after
collection 495ms 24ms
worker occupancy @1s 33.0% 2.4%
IOReport samples/cycle 8 1
observation coverage @3s 14% 100%

Full TUI CPU by interval:

interval before after
1s 8.16% 4.71%
2s 5.32% 3.47%
3s 4.06% 2.13%

End to end, default local mode with no -i: 4.06% at 3s before, 3.52% at 1s after. The sample rate triples at equal or lower cost, which is what makes problem 2's fix affordable.

Correctness check

A/B of both code paths over the same period, to confirm this changes cost and coverage rather than the numbers:

blocking400  window=410ms  cpu_power=2.41W gpu_power=0.83W gpu_res=24.5% p_res=2.4%
blocking400  window=407ms  cpu_power=8.14W gpu_power=0.93W gpu_res=28.3% p_res=6.1%
blocking400  window=410ms  cpu_power=9.92W gpu_power=0.84W gpu_res=28.7% p_res=4.0%
continuous   window=1012ms cpu_power=2.63W gpu_power=0.77W gpu_res=25.4% p_res=1.5%
continuous   window=1012ms cpu_power=3.54W gpu_power=0.78W gpu_res=25.1% p_res=3.3%
continuous   window=1010ms cpu_power=19.29W gpu_power=0.79W gpu_res=24.6% p_res=14.9%

Every metric lands in the same range. CPU power is spiky in both, which is the metric's nature.

Tests

  • Added test_local_interval_is_the_no_remote_nodes_arm: the local cadence must equal adaptive_interval(0), must differ from adaptive_interval(1), and must be at most 2s.
  • Verified by hand that a sub-MIN_DELTA_WINDOW call returns no delta and leaves the baseline armed for the next call.
  • cargo test fully green, cargo clippy --all-targets clean, cargo fmt applied.

Scope note

macOS Apple Silicon only for the sampling change; the interval fix applies to every local-mode platform (3s to 2s off Apple Silicon, matching what main.rs already assumed).

Two defects compounded each other in local mode on Apple Silicon.

IOReport collection opened its own measurement window: `get_sample` took a sample, slept 100ms, took a second one, and `collect_once` averaged four of those. Each collection therefore blocked its caller for ~495ms and observed only 400ms of wall time. At the effective 3.5s period that is 14% of elapsed time, so anything happening in the other 86% never reached the history graphs, and the blocking ran directly inside a `tokio::join!` arm in `local_collector.rs` rather than on the blocking pool.

Every subscribed channel is a cumulative counter (energy in the Energy Model group, residency ticks in the CPU/GPU stats groups), so a delta between any two samples is exactly the activity between them. `get_sample_since_last` retains the newest sample and differences the next call against it: no sleep, one `IOReportCreateSamples` per poll, and a window equal to the full polling interval. The `prev_sample` field this needs was already declared on `IOReport` but had never been written. Deltas shorter than `MIN_DELTA_WINDOW` (50ms) report no result rather than dividing counters by a near-zero interval, and leave the baseline in place so a fast caller still accumulates one. `get_sample` remains for the first collection of a session, which has no baseline. Averaging four samples is gone: one long delta already is the interval's time average.

Measured on an M1 Ultra, release build: collection 495ms to 24ms, worker occupancy at a 1s interval 33.0% to 2.4%. An A/B against the old path over the same period agrees on every metric (gpu_residency 24.5/28.3/28.7% vs 25.4/25.1/24.6%, gpu_power 0.83/0.93/0.84W vs 0.77/0.78/0.79W), so this is a cost and coverage change, not a measurement change.

Separately, `run_local_mode` asked for `adaptive_interval(1)`. That reads as "one host" but selects the 1-to-10-remote-nodes arm, so local mode polled at 3s and the `node_count == 0` arm documented as "Local monitoring only (no remote nodes)" was unreachable. `main.rs` assumed 2s for the same run via `unwrap_or(2)`, so one binary carried three different local defaults. Local call sites now use `EnvConfig::local_interval()` and never spell out a node count, which removes the class of bug rather than the instance.

With collection no longer blocking, the documented cadence is affordable: default local mode measures 3.52% CPU at 1s against 4.06% at the previous 3s, so the sample rate triples at equal or lower cost. The startup cache that served the first ten calls for 5s existed to absorb the old blocking; it also made the first ~10 seconds of every history graph a staircase of repeated values, and is replaced by a single `CACHE_DURATION_MS`.

Adds a regression test asserting the local cadence is the no-remote-nodes arm and differs from the 1-to-10-node arm.
@inureyes inureyes added type:bug Something isn't working status:review Under review priority:medium Medium priority issue mode:local Local mode related mode:view View mode related device:apple-silicon Apple Silicon related type:performance Performance improvements and removed type:performance Performance improvements labels Jul 27, 2026
@inureyes
inureyes merged commit 18fb595 into main Jul 27, 2026
4 checks passed
@inureyes
inureyes deleted the fix/ioreport-continuous-delta branch July 27, 2026 05:23
@inureyes inureyes added status:done Completed and removed status:review Under review labels Jul 27, 2026
inureyes added a commit that referenced this pull request Jul 27, 2026
Adds the benchmark tooling issue #288 asks for. Refs #288, and deliberately does not close it: #288 is satisfied by *results* from Linux and Windows hardware, which this PR cannot produce. It lands the instrument so those results are collectable and comparable.

## Why

PR #286 did two things, only one of which is cross-platform. It moved local mode's default collection interval from 3s to 1s on Apple Silicon and to 2s everywhere else, and it replaced the IOReport sampling strategy so a collection went from ~495ms to ~24ms. The sampling half is gated to macOS (`macos_native` is `#[cfg(target_os = "macos")]`), so Linux, Windows, and Intel Mac took the 1.5x polling increase with no offsetting reduction. Every number behind that decision came from one Apple Silicon machine.

## What the script does

`scripts/bench-local-interval.sh` measures `all-smi local` CPU across the default configuration plus a configurable set of explicit intervals.

```
$ scripts/bench-local-interval.sh -h        # usage
$ cargo build --release --bin all-smi
$ scripts/bench-local-interval.sh           # 60s window, intervals 1/2/3
$ scripts/bench-local-interval.sh -d 120 -i "2 5"
```

Two design points are what make results from different reporters worth comparing:

**Fixed terminal size.** The real TUI runs detached in tmux at 200x50. Render cost scales with terminal size, so an unfixed size would make two machines' numbers incomparable for reasons that have nothing to do with the collection path.

**CPU-time delta, not `ps -o %cpu`.** That column is a decaying recent average on macOS and a lifetime-since-start average on Linux. Reading it would produce two different quantities on the two platforms the script targets. The script reads the process CPU-time delta over the window instead: `/proc/PID/stat` (utime + stime over `CLK_TCK`) on Linux, `ps -o cputime=` on macOS, where BSD `ps` carries centisecond resolution that Linux's truncates away. Results are percent of one core.

An environment block (OS, kernel, CPU, core count, GPU, process count, all-smi version) prints above the numbers, because collection cost depends on which device readers are active and results without that context cannot be interpreted.

## Reference run

Apple M5 Max, 18 cores, 1035 processes, release build, 60s window after 8s warmup:

```
  default        cpu=  5.28%   cpu_time=3.17s / 60s   rss=20MB
  -i 1s          cpu=  5.44%   cpu_time=3.32s / 61s   rss=21MB
  -i 2s          cpu=  3.28%   cpu_time=1.97s / 60s   rss=20MB
  -i 3s          cpu=  2.40%   cpu_time=1.44s / 60s   rss=19MB
```

`default` matching `-i 1s` within noise independently confirms #286's interval fix is in effect on Apple Silicon. The 3s to 2s step, which is what non-Apple-Silicon platforms absorbed, costs about +37% on this cost profile. Whether it costs the same where the reader mix is NVML plus AMD plus Intel rather than IOReport is exactly the open question.

## Note on earlier numbers

Two corrections to what was reported on #286 and #287, both already applied to those threads:

- The benchmarking hardware was an Apple M5 Max, not an M1 Ultra. The M1 Ultra is the machine in the screenshots that started the investigation; I conflated it with the machine the benchmarks ran on.
- Those numbers used `ps -o %cpu`. On the same machine the CPU-time-delta method in this script reports a somewhat higher absolute figure for the same configuration, so the absolute values in those threads are indicative rather than exact. The before/after comparisons used one consistent method throughout and are unaffected.

## Linux run, and a fix it turned up

The Linux path has since been exercised on an NVIDIA GB10 (DGX Spark), Ubuntu 24.04.4, aarch64, 20 cores. Full numbers are on #288; the summary is that the `/proc/PID/stat` path is correct (validated against a busy loop pinned at one full core, where it reported 100.01%), `default` matches `-i 2s` to within 3.2% so #286's interval fix is confirmed live on Linux, and the 3s to 2s step costs +19.4% there against +37% on the M5 Max, which is 0.14s of CPU per minute or 0.0117% of that machine.

That run exposed a defect, fixed in the second commit. `detect_cpu` read `model name` from `/proc/cpuinfo`, an x86-only field, so on aarch64 the awk matched nothing, printed an empty string, and still exited 0, which meant the trailing `|| echo unknown` never fired and the environment block reported a blank CPU. Since GB10, GH200, and Grace are all aarch64, the platform this benchmark most needs results from was the one silently dropping its CPU identity. It now falls back to `lscpu`, joining the distinct `Model name` values so a heterogeneous part reads `Cortex-X925 + Cortex-A725`.

One limit of the metric is worth stating rather than leaving implicit, and is tracked separately as #290. On a heterogeneous CPU, "percent of one core" is not one quantity: pinning the same run to the GB10's X925 cluster versus its A725 cluster moves the result by about 1.5x, which is larger than the interval effect this script exists to measure. Ratios within a single host stay robust (+17.9% pinned to performance cores, +21.4% to efficiency cores, +19.4% unpinned), so conclusions drawn from them hold, but absolute percentages are comparable across machines only when core placement is stated. Apple Silicon P/E and Intel hybrid parts have the same property, so the M5 Max reference numbers above carry it too.

## Tests

Shell only, no Rust touched, so the existing suite is unaffected. `shellcheck` clean as of the first commit; it is not installed on the GB10 host, so the second commit's change was not re-linted there, and it declares `local name` before assigning so it does not introduce SC2155. Exercised on macOS at 15s, 20s, and 60s windows, and on Linux at 10s and 60s windows across four configurations and three repeats.

Building on Linux requires `libdrm-dev`: without it the link fails on `-ldrm` and `-ldrm_amdgpu` even on a host with no AMD GPU, because `libamdgpu_top` is a hard dependency of the glibc Linux target.

Also documents usage under Testing in `DEVELOPERS.md`.
inureyes added a commit that referenced this pull request Jul 31, 2026
## Summary

The `tokio::join!` in `collect_parallel_first_iteration` fanned out over nine arms but polled all of them on one task. Every arm except full-process collection called synchronous reader methods with no yield point, so the join only provided ordering and result aggregation: the arms took turns on a single worker and the cycle cost the sum of all of them. `collect_sequential`, the steady-state path used for every cycle after the first, was serial by construction and had exactly the same problem, so both paths are fixed here.

Both now dispatch every synchronous reader pass to the blocking pool up front and join only at the end. Nothing synchronous is left on the async task in either path.

## Design

Work is grouped per reader collection, not per query. GPU device info, GPU processes, vGPU and MIG stay back to back inside one task because they all run against the same `Box<dyn GpuReader>` instances, and those carry internal sampling state (IOReport deltas on Apple Silicon, cached NVML handles on NVIDIA); issuing them concurrently against one reader would change the order in which that state is touched, which is exactly what acceptance criterion 5 forbids. CPU, memory, chassis, storage and full-process collection each get their own task, giving six groups that genuinely overlap.

**How the `Arc<RwLock<...>>` borrows are handled.** `spawn_reader_pass` takes the guard with `Arc<RwLock<T>>::read_owned()` in async context and moves it into the closure. This is what makes the refactor possible at all: `read()` is a future and unusable inside a blocking closure, while `blocking_read()` from the blocking pool would risk deadlocking against a queued async writer (tokio's `RwLock` is fair, so a queued writer blocks subsequent readers). `OwnedRwLockReadGuard<T>` is `'static + Send` whenever `T: Send + Sync`, and `GpuReader`/`CpuReader`/`MemoryReader`/`ChassisReader` are all declared `Send + Sync`, so the `spawn_blocking` bounds are satisfied without cloning or re-owning a single reader. No guard is ever held across an `.await`.

**Why holding the guard for the task's lifetime is safe.** I checked every writer of these locks: the only one is `initialize_readers`, which runs once and completes before the first collection. There is no hotplug or periodic-refresh path that takes a write lock while a collection is in flight, so a long-lived read guard cannot starve anything.

**The one dependency that is kept.** In the steady-state path `update_process_cache` needs this cycle's GPU pid set to decide which cached entries are GPU-attributed, so the process task is spawned after the GPU group joins rather than alongside it. Breaking that dependency would change collected values. Every other group is already in flight by then, so it only extends the critical path when GPU plus process collection outlasts all of them (it does not on the measured machine, and the code comment says so). The first-iteration path has no such dependency: it deliberately seeds the cache with an empty pid set, so all six groups start together there.

Blocking-pool sizing was checked: six concurrent tasks per cycle sits far below the default `max_blocking_threads`, and below the `max_blocking_threads(32)` used by the snapshot runtime.

## Measurements

Recorded on this machine (Apple M5 Max, 18 cores), release profile, via the `measure_collection_arms` harness added in `src/view/data_collection/local_collector/tests.rs`. The baseline was measured first, before any production code changed, by checking out `origin/main` into a separate worktree, appending the same harness to it, and building it with its own target directory. Two runs of each, alternating, on an otherwise idle machine. Wall clock and CPU are 100 back-to-back steady-state cycles divided by 100; CPU time is `getrusage(RUSAGE_SELF)` user + system, which counts every thread, so blocking-pool work is charged exactly like inline work.

| | baseline run 1 | baseline run 2 | after run 1 | after run 2 |
|---|---|---|---|---|
| wall clock per cycle | 20.118 ms | 21.717 ms | 14.883 ms | 14.783 ms |
| process CPU per cycle | 19.320 ms | 21.129 ms | 19.372 ms | 19.112 ms |

Wall clock drops roughly 28%. CPU time is flat within run-to-run noise and never above baseline, which is the "no regression" check: `spawn_blocking` relocated the cycles rather than adding any. There is no busy-wait and no duplicated work; the same reader calls run the same number of times.

Per-arm synchronous cost on this machine (mean of 12 samples, measured before the change): storage 14.371 ms, full process refresh 8.147 ms, GPU info 0.010 ms, CPU info 0.006 ms, memory 0.003 ms, chassis 0.002 ms, vGPU/MIG/GPU-processes below 0.001 ms. Serialized sum 22.541 ms. After the change the critical path is bounded by the storage pass, which matches the observed 14.8 ms.

**Limitations, stated honestly.** This is a single-machine, single-platform measurement. On Apple Silicon after PR #286 the GPU reader is effectively free (10 microseconds), so the win here comes from overlapping storage with process collection rather than from getting the GPU arm off the worker. On an NVIDIA host where `get_gpu_info` costs tens of milliseconds the GPU group would dominate and the ratio would differ; I have no NVIDIA hardware here to measure that, and the numbers above should not be read as a cross-platform claim. The `measure_collection_arms` harness is committed (ignored by default) precisely so the numbers can be reproduced on other hardware. The first-iteration path is not in the table because its one-shot nature makes a 100-cycle average meaningless; it is covered by a functional test instead.

## What changed

- `src/view/data_collection/local_collector.rs`: added `GpuCollection` plus `collect_from_gpu_readers` for the grouped GPU pass, added the `spawn_reader_pass` helper, rewrote `collect_parallel_first_iteration` to spawn six blocking groups instead of a nine-arm `tokio::join!`, and rewrote `collect_sequential` the same way.
- Renamed `collect_sequential` to `collect_steady_state`, since the old name no longer describes what it does.
- The first-iteration status updates now use `blocking_send` from inside the blocking closures, so each "collected" line still appears as its group finishes rather than all at once at the end.
- Hardened the startup status handler to bound the shifted index (`3 + index`) instead of the raw one, so an out-of-range write cannot panic that task.
- `src/view/data_collection/local_collector/tests.rs` (new): test module split out following the existing `#[path = ".../tests.rs"]` convention used by `cpu_linux`, `memory_linux`, `container_info` and others.

## Test plan

- [x] `cargo fmt --check`
- [x] `cargo check --lib --tests`
- [x] `cargo clippy --lib --tests -- -D warnings` (clean)
- [x] `cargo test --bin all-smi view::data_collection::local_collector::tests -- --test-threads=1` (3 passed, 1 ignored harness)
- [x] `parallel_collection_matches_serial_reference`: runs the new pipeline and a straight-line reference collection back to back and asserts the GPU uuid set, CPU/memory/vGPU/MIG/chassis row counts, and storage mount-point set match, plus that the process list stays sorted by CPU descending and truncated to `MAX_DISPLAY_PROCESSES`. Absolute metric values are sampled at different instants and cannot be compared for equality, so everything that is not time varying is asserted instead.
- [x] `repeated_collections_complete_without_deadlock`: runs `FULL_REFRESH_INTERVAL + 2` cycles under a timeout, covering both the selective and full process-refresh branches, to catch a lock or blocking-pool deadlock.
- [x] `first_iteration_collection_reports_startup_status`: drives the real first-iteration path through `initialize_readers` and asserts all five arms report completion, which is also what proves `blocking_send` inside `spawn_blocking` does not panic.

Closes #287
inureyes added a commit that referenced this pull request Jul 31, 2026
Bump the version to 0.25.0 across Cargo.toml, Cargo.lock, the manpage,
and debian/changelog, and add the README "Recent Updates" entry.

Covers the 10 commits since v0.24.2: local collection pipeline
parallelization (#299), continuous IOReport sampling and a dedicated
local polling cadence (#286), time-scrolling history graphs (#285), the
local-mode collection cost benchmark and its topology, pinning, and
affinity-mask reporting (#289, #291, #296, #298), and the Homebrew tap
bump workflow hardening and repository rename fix (#294, #295).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

device:apple-silicon Apple Silicon related mode:local Local mode related mode:view View mode related priority:medium Medium priority issue status:done Completed type:bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant