Fix bottleneck analyser, duplicate console output, and add CPU affinity

.claude/hooks/posttooluse_format.py

@@ -13,6 +13,34 @@
 import os
 import subprocess
 import sys
+from pathlib import Path
+
+
+def project_python() -> str:
+    """Interpreter that actually has black and ruff installed.
+
+    The hook itself may be run by any interpreter -- typically the system
+    Python, which has no dev tooling. Prefer the project virtualenv so the
+    formatters are found; fall back to whatever is running us.
+    """
+    root = Path(__file__).resolve().parents[2]
+    for candidate in (
+        root / ".venv" / "Scripts" / "python.exe",  # Windows
+        root / ".venv" / "bin" / "python",  # POSIX
+    ):
+        if candidate.exists():
+            return str(candidate)
+    return sys.executable
+
+
+def missing_module(result: subprocess.CompletedProcess) -> bool:
+    """True when the interpreter ran but the tool is not installed.
+
+    `python -m ruff` with ruff absent exits non-zero with a normal message
+    rather than raising, so this case is indistinguishable from a lint failure
+    unless the output is inspected.
+    """
+    return "No module named" in ((result.stderr or "") + (result.stdout or ""))
 
 
 def run(args: list[str]) -> subprocess.CompletedProcess | None:
@@ -43,18 +71,20 @@ def main() -> None:
     if not os.path.exists(file_path):
         sys.exit(0)
 
-    black_result = run([sys.executable, "-m", "black", file_path])
-    if black_result is None:
+    python = project_python()
+
+    black_result = run([python, "-m", "black", file_path])
+    if black_result is None or missing_module(black_result):
         # black not installed / not runnable - tolerate silently.
         sys.exit(0)
 
-    ruff_fix_result = run([sys.executable, "-m", "ruff", "check", "--fix", file_path])
-    if ruff_fix_result is None:
+    ruff_fix_result = run([python, "-m", "ruff", "check", "--fix", file_path])
+    if ruff_fix_result is None or missing_module(ruff_fix_result):
         # ruff not installed / not runnable - tolerate silently.
         sys.exit(0)
 
-    ruff_check_result = run([sys.executable, "-m", "ruff", "check", file_path])
-    if ruff_check_result is None:
+    ruff_check_result = run([python, "-m", "ruff", "check", file_path])
+    if ruff_check_result is None or missing_module(ruff_check_result):
         sys.exit(0)
 
     if ruff_check_result.returncode != 0:

CHANGELOG.md

@@ -7,8 +7,62 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+### Added
+
+- **`cpu_affinity` config option.** Pins the run, its worker processes and the
+  EddyPro executables to a chosen set of logical CPUs. Accepts `performance`
+  for auto-detection, an explicit list of CPU indices, or null (the default,
+  unchanged behaviour).
+
+  On Intel hybrid CPUs the OS parks long-running background work on the
+  efficiency cores. `eddypro_rp` is single-threaded, so measured on an i7-12700K
+  one year of 10 Hz data took 241 s pinned to the performance cores against
+  474-501 s unpinned -- roughly a factor of two, invisible to CPU monitoring
+  because a saturated efficiency core reports the same ~100% of a core as a
+  saturated performance one. Pinning also removed the run-to-run variance
+  entirely. Auto-detection leaves affinity alone on CPUs with no such split, and
+  an unrecognised value is logged and ignored rather than failing the run.
+
+- **Throughput signal in the performance monitor.** The monitor can now count
+  completed work items and record `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.
+
+  This exists because CPU utilisation cannot distinguish a saturated fast core
+  from a saturated slow one. On Intel hybrid CPUs (12th gen and later) Windows
+  will park a long-running background process on the efficiency cores; measured
+  on a 12700K, the same workload took 241 s pinned to P-cores and 474-501 s
+  unpinned, while `cpu_percent_of_core` read 96-103% in *every* case. Without a
+  work-rate series there is no signal at all that half the machine's performance
+  is missing. Opt-in via `progress_dir`; runs without one are unaffected.
+
 ### Fixed
 
+- **The bottleneck analyser could not detect a CPU bottleneck.** `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 reported as `NONE: no clear bottleneck ...
+  headroom to increase max_processes`, which was the right advice only by
+  coincidence and 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%. The classifier now:
+  - judges machine-level saturation on `system_cpu_percent`, because each
+    parallel worker's monitor only ever sees its own process tree and so can
+    never observe that the machine as a whole is full;
+  - adds a `CPU_SINGLE_CORE` verdict driven by `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 old 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 now shows machine-wide CPU and
+  percent-of-one-core as separate columns, instead of a single normalised
+  figure that reads as near-zero for any single-threaded run.
+
 - **Monitor reported 0.0% CPU for every child process.** psutil records the
   CPU-times baseline on the `Process` *instance*, and `children(recursive=True)`
   builds fresh objects on every sample, so each descendant's first (always-zero)
@@ -18,6 +72,15 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
   EddyPro spawning workers — which produced exactly the all-zero CPU column the
   process-tree fix was meant to eliminate.
 
+- **EddyPro output was written to the console twice.** `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. This doubled
+  console volume and 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 the output, so live progress still works with
+  `log_eddypro_output: false`.
+
 - **`eddypro-batch` with no subcommand printed a config error instead of
   help.** `main()` validated the config file before dispatching, so on a fresh
   clone -- where `config/config.yaml` does not exist yet -- the first command

config/config.yaml.example

@@ -33,6 +33,17 @@ multiprocessing: False  # Set to True to process years in parallel
 # Rule of thumb: one worker per year, bounded by physical cores and disk throughput
 max_processes: 16
 
+# CPU affinity for the run and every process it launches.
+#   null           -> leave scheduling to the OS (default)
+#   performance    -> auto-detect and pin to the performance cores
+#   [0, 1, 2, ...] -> pin to these logical CPU indices
+# On Intel hybrid CPUs (12th gen and later) the OS will park a long-running
+# background job on the efficiency cores. EddyPro is single-threaded, so this
+# costs roughly a factor of two -- and CPU monitoring cannot see it, because a
+# saturated efficiency core reports the same ~100% as a saturated performance
+# core. Pinning also makes run times reproducible.
+cpu_affinity: null
+
 # Control output streaming (EddyPro subprocess outputs)
 stream_output: True  # Set to False to keep EddyPro output quiet
 

docs/CONFIG.md

@@ -76,6 +76,7 @@ The following keys **must** be present in your configuration file:
 | `log_backup_count` | int or null | Number of rotated log files to keep |
 | `log_eddypro_output` | bool | Write EddyPro stdout/stderr to logs |
 | `monitoring_enabled` | bool | Enable/disable performance monitoring (default: `true`) |
+| `cpu_affinity` | str, list[int], or null | Pin the run to specific logical CPUs (default: `null`, no pinning) |
 
 ## Configuration Details
 
@@ -411,6 +412,51 @@ monitoring_enabled: false
 
 ---
 
+### cpu_affinity
+
+**Type:** String, list of integers, or null
+
+**Default:** `null` (leave scheduling to the OS)
+
+**Description:** Restricts the run -- and every process it launches, since child
+processes inherit affinity -- to a set of logical CPUs.
+
+**Values:**
+
+| Value | Meaning |
+|-------|---------|
+| `null` | No pinning |
+| `performance` | Auto-detect the performance cores and pin to them |
+| `[0, 1, 2, ...]` | Pin to these logical CPU indices |
+
+**Why:** Intel hybrid CPUs (12th generation and later) mix performance cores
+with efficiency cores, and the OS will park a long-running background job 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:
+
+| | Wall time | CPU % of one core |
+|---|---|---|
+| Pinned to performance cores | 241 s, 241 s | 102.6% |
+| Unpinned | 474 s, 501 s | 96.5-97.8% |
+
+Note the second column: **CPU utilisation is identical**. A demoted run looks
+healthy in the bottleneck report. Pinning also removes the variance -- the
+pinned runs agreed exactly, the unpinned pair differed by 5.7%.
+
+**Auto-detection:** `performance` derives the split from the core counts.
+Performance cores carry two hardware threads and efficiency cores carry 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 -- affinity is
+left unchanged and a message is logged. On a CPU without efficiency cores there
+is nothing to gain, so this is the correct outcome rather than a failure.
+
+**Never fatal:** an unrecognised value is logged and ignored. A failed
+optimisation must not stop a multi-hour run.
+
+**CLI Override:** none -- config only.
+
+---
+
 ### performance_thresholds
 
 **Type:** Mapping (optional)
@@ -426,15 +472,22 @@ SATA default and a genuinely saturated disk is never flagged at all.
 
 | Key | Default | Meaning |
 |-----|---------|---------|
-| `cpu_high_percent` | 90 | At or above this sustained (p95) CPU, status is RED |
+| `cpu_high_percent` | 90 | At or above this sustained (p95) **machine-wide** CPU, status is RED |
 | `cpu_moderate_percent` | 70 | At or above this, status is YELLOW |
 | `cpu_idle_percent` | 40 | Below this, a busy disk is read as the limiting factor |
+| `single_core_bound_percent` | 95 | Applied to `cpu_percent_of_core`, where 100 = one core fully busy. At or above this, the run is reported `CPU_SINGLE_CORE` |
 | `memory_high_percent` | 85 | System memory use that counts as RED |
 | `memory_moderate_percent` | 70 | System memory use that counts as YELLOW |
 | `disk_high_mb_per_s` | 450 | Combined read+write throughput counting as RED |
 | `disk_moderate_mb_per_s` | 250 | Throughput counting as YELLOW |
 | `disk_high_iops` | 20000 | Combined IOPS above which latency is the suspect |
 
+The CPU verdict is judged on `system_cpu_percent` (machine-wide). Each parallel
+worker runs its own monitor and sees only its own process tree, so per-process
+CPU can never reveal that the machine as a whole is full. Files written by a
+monitor that did not record the system column fall back to the normalised
+process figure.
+
 Unknown keys are ignored, so a config written for a newer version still loads.
 
 Suggested disk limits by medium:

docs/MULTI_YEAR_RUNS.md

@@ -153,16 +153,66 @@ decide whether `max_processes` is set well:
 
 | Classification | What it means | What to do |
 |---|---|---|
-| CPU | Workers are compute-bound; cores are the limit | Lower `max_processes` toward the physical core count if you see thrashing; otherwise this is healthy utilization |
+| CPU | The **machine** is compute-bound; cores are the limit | Lower `max_processes` toward the physical core count if you see thrashing; otherwise this is healthy utilization |
+| CPU_SINGLE_CORE | EddyPro is pegging one core while the machine sits idle. This is the normal state for a single-year run, because `eddypro_rp` is largely single-threaded | Raise `max_processes` and run more years concurrently. A faster disk will not help |
 | MEMORY | Workers are approaching available RAM | Lower `max_processes`, or process fewer years concurrently |
 | DISK_THROUGHPUT | Aggregate read/write MB/s is saturating the disk | Lower `max_processes`, or move input/output to faster storage (SSD/NVMe) |
 | DISK_IOPS | Many small reads/writes are the limit (common with many small raw files) | Move data to faster storage; concatenating raw files can help more than adding workers |
 
-With N years running in parallel, remember that each worker's own CPU% is a
-share of the *whole machine* — a healthy multi-year run with `max_processes:
-6` on an 8-core machine will show each worker around 60-80% CPU, not 100%.
-Read the aggregate/system columns in the metrics CSVs, not just one worker's
-process columns, when deciding whether you're actually CPU-bound.
+The metrics CSV carries three different CPU columns and they answer different
+questions:
+
+| Column | Meaning | Use it for |
+|---|---|---|
+| `cpu_percent_of_core` | 100 = one core fully busy, 200 = two | Is the workload itself pinned by single-thread speed? |
+| `system_cpu_percent` | Machine-wide utilisation | Is the *machine* full? This drives the CPU verdict |
+| `cpu_percent` | The process tree's share of the whole machine | Comparing one worker's footprint against the box |
+
+`cpu_percent` is divided by the logical core count, so on a 20-thread machine a
+single-threaded EddyPro saturating one core reads as ~5%. That is not idleness --
+check `cpu_percent_of_core` before concluding a run was cheap.
+
+## Hybrid CPUs: pin EddyPro to the performance cores
+
+On Intel hybrid CPUs (12th generation and later) the cores are not all equal:
+an i7-12700K has 8 performance cores (logical 0-15) and 4 efficiency cores
+(16-19). Windows will park a long-running background process on the efficiency
+cores, especially while you are using the machine for something else.
+
+`eddypro_rp` is single-threaded, so this costs about a factor of two. Measured
+on a 12700K, one year of 10 Hz data:
+
+| | Wall time | s per flux period | `cpu_percent_of_core` p95 |
+|---|---|---|---|
+| Pinned to P-cores | 241 s, 241 s | 0.70 | 102.6% |
+| Unpinned | 474 s, 501 s | 1.39, 1.47 | 96.5-97.8% |
+
+Note the last column: **CPU utilisation is identical**. A demoted run looks
+perfectly healthy in the bottleneck report -- it is saturating a core, it is
+just a slower core. Only the `work_items_per_s` throughput series reveals it.
+System CPU sat at 17-21% in all four runs, so this is core placement, not
+contention.
+
+Pinning also makes runs reproducible: the two pinned runs agreed exactly, while
+the unpinned pair differed by 5.7%.
+
+Set `cpu_affinity` in the config and the pipeline handles it -- child
+processes inherit affinity, so pinning the launching process covers the workers
+and the EddyPro executables they run:
+
+```yaml
+cpu_affinity: performance    # or an explicit list, e.g. [0, 1, 2, ..., 15]
+```
+
+Auto-detection derives the split from the core counts and logs what it chose.
+On a CPU without efficiency cores there is nothing to gain and affinity is left
+alone. See [CONFIG.md](CONFIG.md#cpu_affinity) for the details.
+
+Check your own topology with:
+
+```powershell
+Get-CimInstance Win32_Processor | Select-Object Name, NumberOfCores, NumberOfLogicalProcessors
+```
 
 ## Choosing `max_processes`
 

docs/REPORTING.md

@@ -226,6 +226,11 @@ timestamp,relative_time,system_cpu_percent,system_memory_total,system_memory_ava
 - `system_memory_total`, `system_memory_available`, `system_memory_percent`
 - `system_disk_read_bytes`, `system_disk_write_bytes`, `system_disk_read_count`, `system_disk_write_count`
 - `process_cpu_percent`, `process_memory_rss`, `process_memory_vms`, `process_memory_percent`
+- `work_items`, `work_items_per_s`: completed work items and their rate, when a
+  progress directory is configured. For `run` these count binned-cospectra
+  files, i.e. flux averaging periods finished. This is the only column that
+  distinguishes a saturated *fast* core from a saturated *slow* one -- see
+  [MULTI_YEAR_RUNS.md](MULTI_YEAR_RUNS.md) on hybrid-CPU core placement
 - `process_io_read_bytes`, `process_io_write_bytes`, `process_io_read_count`, `process_io_write_count`
 
 Column presence can vary by platform and psutil capabilities. The CSV is a raw