Skip to content

Fix bottleneck analyser, duplicate console output, and add CPU affinity - #17

Merged
rasmusjen merged 6 commits into
mainfrom
fix/bottleneck-analyser-and-cpu-affinity
Aug 27, 2026
Merged

Fix bottleneck analyser, duplicate console output, and add CPU affinity#17
rasmusjen merged 6 commits into
mainfrom
fix/bottleneck-analyser-and-cpu-affinity

Conversation

@rasmusjen

Copy link
Copy Markdown
Owner

Found while running a full end-to-end validation of the pipeline: 7 days per
year, 3 years, two sites (GL-ZaF at 10 Hz, GL-Dsk at 20 Hz), every run repeated
after a discarded warm-up.

Fixes

The bottleneck analyser could not detect a CPU bottleneck. monitor.py
divides process-tree CPU by the logical core count, so a single-threaded
EddyPro saturating one core of twenty recorded ~5% against 70/90% thresholds.
Every run came back NONE: no clear bottleneck ... headroom to increase max_processes — correct only by coincidence, and identical to what it would
say on a fully saturated machine. Measured on a real run:

Signal p95
cpu_percent (÷20) 5.0% — what the classifier saw
cpu_percent_of_core 100.3% — pegging one core
system_cpu_percent 23.1% — machine 77% idle

Now judges machine saturation on system_cpu_percent (the only column a
parallel worker can see the whole machine through) and adds a
CPU_SINGLE_CORE verdict. Falls back to the old figure when the system column
is absent, so older metrics files stay classifiable.

EddyPro output was written to the console twice. setup_logging always
attaches a stdout handler, so with the shipped defaults the streaming loop's
print() duplicated every logged line: 44 560 log lines per site-year before,
22 196 after.

The format hook never ran. It invoked sys.executable — the system Python,
which has no black or ruff — and its tolerate-missing path only caught
FileNotFoundError, so every edit exited 2 with "No module named ruff".

Additions

cpu_affinity config option. On hybrid CPUs the OS parks long-running
background work on the efficiency cores. eddypro_rp is single-threaded, so
one year of 10 Hz data took 241 s pinned vs 474–501 s unpinned — and CPU
monitoring cannot see it, because a saturated E-core reads the same ~100% of a
core as a saturated P-core. Pinning also removed run-to-run variance entirely.
Accepts performance (auto-detect), an explicit CPU list, or null (default,
unchanged).

Throughput signal. work_items / work_items_per_s from the
binned-cospectra count, plus mean_seconds_per_work_item in the report. This
is what makes the above detectable: identical CPU, half the work done.

Validation results

Multiprocessing scales cleanly across years — 2.80× on 3 workers (GL-ZaF,
93% efficiency), 2.93× (GL-Dsk, 98%) — and output is byte-identical to
sequential across all 24 files compared. Disk peaked under 10 MB/s against a
450 MB/s threshold and memory at 29 MB per worker, so neither constrains
anything. Monitoring overhead is below run-to-run noise.

Also worth recording: 20 Hz data costs 3.6× more than 10 Hz, not 2×.

Notes for review

  • CPU_SINGLE_CORE is a new value for primary_bottleneck; nothing in-repo
    parses it, but downstream consumers of the manifest would see it.
  • The throughput signal points at eddypro_binned_cospectra, which only exists
    when spectral output is enabled. Without it work_items stays 0 — it
    degrades quietly rather than erroring, so the diagnostic is not universal.
  • Affinity auto-detection assumes the standard Windows enumeration where P-core
    threads are numbered first. It returns None rather than guessing when the
    topology is unexpected.

221 tests pass; ruff, black, mypy and the pre-commit suite clean.

monitor.py divides process-tree CPU by the logical core count before
writing cpu_percent, so a single-threaded EddyPro saturating one core of
twenty recorded ~5% -- far below the 70/90% thresholds the classifier
compared it against. Every run was therefore classified as
"NONE: no clear bottleneck ... headroom to increase max_processes",
advice that was correct only by coincidence and that would have read
identically on a fully saturated machine.

Confirmed against a real 7-day run whose eddypro_rp phase sustained
100.3% of one core (p95) while cpu_percent read 5.0% and the machine sat
at 23.1%.

The classifier now:

- judges machine saturation on system_cpu_percent, because each parallel
  worker's monitor sees only its own process tree and so can never
  observe that the machine as a whole is full;
- adds a CPU_SINGLE_CORE verdict from cpu_percent_of_core, naming the
  case where the workload is pinned by single-thread speed while cores
  sit idle -- the normal state for eddypro_rp, and the one that actually
  justifies raising max_processes;
- falls back to the normalised figure when system_cpu_percent is absent,
  so older metrics files stay classifiable.

The new single_core_bound_percent threshold (default 95) is tunable via
performance_thresholds. The HTML report gains separate machine-wide and
percent-of-one-core columns, replacing a single normalised figure that
reads as near-zero for any single-threaded run.
setup_logging always attaches a stdout StreamHandler, so with both
stream_output: true and log_eddypro_output: true -- the shipped defaults
-- the streaming loop's print() duplicated every line the logger had
already emitted.

Measured on a 7-day run: 44 560 log lines per site-year before, 22 196
after. It doubled log-file size and halved the interval between log
rotations on multi-hour runs.

The direct echo is now used only when the logger is not already
mirroring output, so live progress still works with
log_eddypro_output: false.

The tests assert on print() rather than on captured log records: the
logger is called exactly once either way, so a caplog-based test passes
against the very bug it is meant to catch.
CPU utilisation cannot distinguish a saturated fast core from a
saturated slow one. On Intel hybrid CPUs (12th gen and later) Windows
parks a long-running background process on the efficiency cores;
measured on a 12700K the same workload took 241 s pinned to the
performance cores and 474-501 s unpinned, while cpu_percent_of_core read
96-103% in every case. Nothing in the metrics revealed that half the
machine's performance was missing.

The monitor now counts completed work items and records work_items and
work_items_per_s alongside the CPU and disk series; the analyser derives
mean_seconds_per_work_item and the HTML report shows it. `run` points
this at the binned-cospectra directory, which EddyPro fills one file per
flux averaging period.

Opt-in via progress_dir; runs without one are unaffected.

The tests deliberately go through create_monitor and MonitoredOperation
rather than constructing PerformanceMonitor directly: the first cut of
this accepted progress_dir at every layer but never forwarded it to the
constructor, so every run silently recorded zeros, and a test that built
the monitor directly would have passed.
Intel hybrid CPUs (12th generation and later) mix performance cores with
efficiency cores, and the OS parks long-running background work on the
efficiency ones. eddypro_rp is single-threaded, so this costs roughly a
factor of two: measured on an i7-12700K, one year of 10 Hz data took
241 s pinned and 474-501 s unpinned. CPU monitoring cannot see it -- a
saturated efficiency core reports the same ~100% of a core as a
saturated performance one -- so the loss is silent. Pinning also removed
the run-to-run variance entirely; the two pinned runs agreed to the
second while the unpinned pair differed by 5.7%.

cpu_affinity accepts:

  null           leave scheduling to the OS (default, unchanged behaviour)
  performance    auto-detect the performance cores and pin to them
  [0, 1, 2, ...] pin to these logical CPU indices

Applied once in cmd_run and cmd_scenarios; child processes inherit
affinity, so this covers the ProcessPoolExecutor workers and the EddyPro
executables they launch.

Auto-detection derives the split from the core counts -- performance
cores carry two hardware threads and efficiency cores one, so
p_cores = logical - physical, occupying logical indices 0..2*p_cores-1.
Where that cannot be determined (no SMT, or no efficiency cores) the
affinity is left unchanged, which is the correct outcome rather than a
failure. An unrecognised value is logged and ignored: a failed
optimisation must not stop a multi-hour run.
- CONFIG.md: document cpu_affinity with the measured pinned-vs-unpinned
  figures and how auto-detection works; note that the CPU verdict is now
  judged machine-wide; add single_core_bound_percent to the thresholds
  table.
- MULTI_YEAR_RUNS.md: replace the "each worker's CPU% is a share of the
  machine" paragraph with a table explaining what each of the three CPU
  columns actually answers, since cpu_percent reading ~5% for a
  saturated core is the thing that misleads; add CPU_SINGLE_CORE to the
  traffic-light table; add a section on hybrid-CPU core placement.
- REPORTING.md: document work_items and work_items_per_s.
The format hook invoked sys.executable, which is whichever interpreter
runs the hook -- typically the system Python, where neither black nor
ruff is installed. Its "tool not installed, tolerate silently" path only
caught FileNotFoundError, but `python -m ruff` with ruff absent exits
non-zero with a normal message rather than raising, so every edit
reported "No module named ruff" and exited 2.

The hook now prefers .venv (Windows and POSIX layouts) and treats a
"No module named" result as the tool being unavailable rather than as a
lint failure.
@rasmusjen
rasmusjen merged commit 40d6ed7 into main Aug 27, 2026
5 checks passed
@rasmusjen
rasmusjen deleted the fix/bottleneck-analyser-and-cpu-affinity branch August 27, 2026 20:48
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant