diff --git a/.agents/benchmark-record.md b/.agents/benchmark-record.md index 126cb961e..f72b11729 100644 --- a/.agents/benchmark-record.md +++ b/.agents/benchmark-record.md @@ -20354,6 +20354,81 @@ Method: third time drift has fooled a before/after here. Pairing caught the first, pinned clocks the second, and only an in-process toggle catches this one. Future perf claims on this row need the toggle, not two runs. +## CLOCK PROVENANCE: the SM clock differs BETWEEN BOOTS on dgx.casa, and nothing recorded it (2026-08-12, `row/BENCH-ASSERT-CLOCK-STATE`, #543 / #545, no GPU work) + +This entry adds no measurement and withdraws none. It records the **box state** +that every existing figure was taken at and could not name, and the assertion +that stops the next one repeating it. + +### The observation + +Same binary, same argv, same model, driver `580.159.03`, persistence `Enabled`, +`clocks_throttle_reasons.active = 0x0` on both sides: + +| boot | SM clock over the captured window | our ms/step | +|---|---|---| +| `f6bbbfc6` | n=61, min 2398 / **med 2470** / max 2489 | **82.1664** | +| `2fca2b02` | n=50, **flat 2190** (`clocks.max.sm` 3003, applications 2418) | **88.1000** | + +A **12.79%** median-clock delta, **+7.22%** step time. The control settles it: +`marlin::Marlin`, 129 calls/step, byte-identical invocation and **no source +change** between `a170c81c` and `4064558d0`, moved **45.2845 -> 49.6544 +ms/step = +9.65%**. + +### What that retracts + +That control drift is **larger than either deficit it was used to rank** — +`in_proj` +2.97%, `out_proj`/`o_proj` +6.28%. Both are **NOT ESTABLISHED**: +neither was ever taken against a clock control. The same effect explains a +same-binary same-arm swing of 382.60 -> 357.59 us/call (-6.5%) across a reboot, +and two probes disagreeing ~6% uniformly eight minutes apart *within one boot* +(2398 MHz against 1781). + +Nothing else on this page is withdrawn. Everything recorded before today +predates clock assertion, which is a statement about attribution, not about +correctness: these figures carry no clock, so a difference of a few percent +between two of them is not established **by them alone**. + +### What now happens instead + +`tools/bench/gpu_clock_state.py` samples the SM clock across the measured +window and records min/median/max/n, `clocks.max.sm`, +`clocks.applications.graphics`, the union of active throttle reasons, +persistence mode, and the **boot id**. Idle samples are excluded from the +statistics and counted, never silently dropped. `online_gate_summary.py` folds +an arm's three legs, refuses a cross-boot pair, voids a run whose within-window +spread exceeds **5%** or whose arms' medians differ by more than **1%**, and +attaches the clock block to every ratio so the clock can be sized against the +effect without leaving the row. `--allow-cross-boot` stamps a recorded caveat and +waives **`boot_id` and nothing else** — the GPU, driver, `clocks.max.sm`, +applications clock and persistence mode are compared across the arms +unconditionally, because same-boot equality was the only thing standing in for +"same machine" and the override removes it. + +A window must also have been **observed**: at least **30 retained busy samples** +and a **majority** of the window busy. Without those floors the incentive is +inverted — `spread_pct` over `n == 1` is definitionally **0.00%**, the best score +the gate can award, so six legs each holding one busy sample and 300 idle scored +a clean pass at `+0.00%`. Both counts are now carried in the ratio's clock block +and printed beside the offset. + +All four thresholds are arguments from the table above and from the grid +definition, derived in `.agents/specs/bench-assert-clock-state.md`. The **5%** +spread ceiling is deliberately *not* held to the forward criterion the **1%** +offset was chosen by; the spec says why and states the residual. The transfer +used to report an estimated effect — **0.7548** points of kernel time per point +of clock — is `n = 1`, is reported and never gated on, and is owed a second pair +once #545 allows one; the offset threshold no longer rests on it, holding +instead at the transfer's physical ceiling of 1.0. + +### Live state at the time of writing + +A read-only `ssh dgx.casa` probe on 2026-08-12 returned boot id +`13dc5579-455c-45c8-8e4d-d09c457fa826` — a **third** boot — at the degraded +2190 MHz with `clocks.max.sm` 3003 and applications 2418. The defect is live, +not historical. No clock was pinned and no GPU work was queued: another session +held `$HOME/gpu.lock`, and `nvidia-smi -lgc` would have repriced their +in-flight measurement. ## SPEC-DSPARK: storage ruled out; ratio stable at ~0.966 across three sessions (2026-08-12) Question raised: are the weights on NAS, or not fully resident, distorting the diff --git a/.agents/benchmarking.md b/.agents/benchmarking.md index 43e3c3db8..8d3d957b2 100644 --- a/.agents/benchmarking.md +++ b/.agents/benchmarking.md @@ -30,6 +30,68 @@ single pair is an anecdote. Prefer an instrument that is immune to page-cache effects (GPU-active time per step) over wall clock when the host is doing heavy I/O. +## The clock is part of the measurement + +**The SM clock differs between boots and does not announce it.** On `dgx.casa` +one boot ran the timed window at a median 2470 MHz and the next at a flat +2190 — a 12.79% delta, with `clocks_throttle_reasons.active = 0x0` and +persistence `Enabled` throughout, so nothing looked wrong. It repriced a +byte-identical `marlin::Marlin` with no source change by **+9.65%**, which is +larger than either deficit that comparison was being used to rank (#543). Two +probes eight minutes apart *inside one boot* disagreed by ~6% uniformly. + +So a number is quotable only with the clock it was taken at. +`tools/bench/gpu_clock_state.py` is the one helper that samples, folds and +asserts it: the SM clock across the measured window (min/median/max, the +retained sample count and the idle count), `clocks.max.sm`, +`clocks.applications.graphics`, the active throttle reasons, persistence mode, +and the **boot id**. + +**Only one harness calls it today.** `scripts/dgx-online-serving.sh` records a +clock window per leg, and `tools/bench/online_gate_summary.py` asserts it. The +trace and per-kernel harnesses — `finalize_*_trace.py`, +`summarize_torch_kernels.py`, `gdn_packed_component.py` — are **not wired**, so +a `us/call` or per-kernel figure from those paths carries **no clock +attribution** and cannot be quoted as one. That is not a footnote: it is the +path both retracted #543 findings came from. Wiring them is owed work tracked in +[`specs/bench-assert-clock-state.md`](specs/bench-assert-clock-state.md); until +it lands, import the helper and record a window yourself before ranking anything +from a trace, or say plainly that the figure is unattributed. Any new harness +imports this helper rather than rolling its own. + +Two arms on **different boots are not comparable**. The summary refuses that +pair outright; `--allow-cross-boot` waives the **boot id and nothing else**, and +stamps a recorded caveat rather than passing silently — the GPU, driver, maximum +SM clock, applications clock and persistence mode are compared across the arms +unconditionally, because a waived boot is not a waived machine. Within a run the +SM-clock spread must stay at or below **5%**, and the two arms' medians within +**1%** of each other. A window must also have been **observed**: at least **30 +retained busy samples** and a **majority** of the window busy, because the +spread over one sample is definitionally 0.00% — the best score the gate can +award — so without a floor the window nobody watched outscores the one that was. +The argument for all four numbers, including why the spread ceiling is +deliberately *not* held to the criterion the offset was chosen by, is in +[`specs/bench-assert-clock-state.md`](specs/bench-assert-clock-state.md). + +**Pin the clocks before measuring, under the lock.** Passwordless `sudo` is +available on `dgx`, and `-lgc` is supported: + +```sh +sudo nvidia-smi -lgc 2100 # pin, before the first leg +sudo nvidia-smi -rgc # release, after the last one +``` + +Pinning is a **shared-host mutation**. Never run `-lgc` or `-rgc` while another +session holds `$HOME/gpu.lock` — it silently reprices their in-flight +measurement, which is the very defect this section exists for. Take the lock, +pin, measure, reset, release. It is a **pre-measurement step**, not a standing +configuration: leaving the box pinned makes every later run inherit a state +nobody recorded, which is where this started. + +Figures recorded before 2026-08-12 predate clock assertion. They are not +withdrawn and are not restated — they simply carry no clock attribution, so a +delta smaller than ~10% between two of them is not established by them alone. + Budget the disk before the run. A production RelWithDebInfo CUDA build tree is about **169 GiB** — the build contract claimed ~3 GiB until 2026-08-10, a 56x underestimate on the one number that decides whether a grid fits. A full disk @@ -60,7 +122,8 @@ tool on the same workload and compare what actually ran. Record the exact build and run recipe, revisions, model hashes, environment, clock and contention state, raw output, and the same-binary A/B. Reproduce on an -idle box before acceptance. +idle box before acceptance. "Clock state" is the concrete list in §The clock is +part of the measurement, boot id included, not a prose adjective. Record every required axis — throughput, latency, memory — as both values and ratios. An axis below floor is an open gap, not a rounding error. diff --git a/.agents/roadmap_v1.md b/.agents/roadmap_v1.md index e9e3a4d37..f47a19e36 100644 --- a/.agents/roadmap_v1.md +++ b/.agents/roadmap_v1.md @@ -49,6 +49,8 @@ issue is not yet placed. Keyed record: update in place, never append. | [#125](https://github.com/mudler/vllm.cpp/issues/125) | `BACKEND-VULKAN` | Vulkan on AMD Strix Halo (gfx1151) does not load | bug | | [#203](https://github.com/mudler/vllm.cpp/issues/203) | `BACKEND-VULKAN` | Vulkan on unified memory holds TWO copies of the weights: 27B peaks at 100.8 GiB RSS and OOM-reboots a Spark | bug | | [#310](https://github.com/mudler/vllm.cpp/issues/310) | `BACKEND-VULKAN` | docs/FEATURES.md understates Vulkan: says decode 4.24 vs 4.35 where the binding figure is 4.36 vs 4.35 | bug | +| [#543](https://github.com/mudler/vllm.cpp/issues/543) | `BENCH-ASSERT-CLOCK-STATE` | The SM clock differs BETWEEN BOOTS without throttling and no manifest records it: a 12.79% clock delta repriced a byte-identical `marlin::Marlin` by +9.65%, larger than either deficit it was used to rank, spec [`bench-assert-clock-state.md`](specs/bench-assert-clock-state.md) | bug | +| [#545](https://github.com/mudler/vllm.cpp/issues/545) | `BENCH-ASSERT-CLOCK-STATE` | BLOCKER: `dgx.casa` MTBF is now shorter than one four-leg measurement chain, so same-boot capture cannot be assumed and cross-boot is the normal case | bug | | [#520](https://github.com/mudler/vllm.cpp/issues/520) | `BENCH-ORACLE-PIN-RECONCILE` | The benchmark harness ENFORCES the 0.25.0 rollback oracle and would REJECT the recorded pin `555967922`, so nobody could have measured correctly even deliberately, spec [`bench-oracle-pin-reconcile.md`](specs/bench-oracle-pin-reconcile.md) | bug | | [#522](https://github.com/mudler/vllm.cpp/issues/522) | `BENCH-ORACLE-PIN-RECONCILE` | BLOCKER: the pinned oracle venv lacks `pandas`, which `vllm bench serve` requires — installing it mutates a shared oracle and needs recorded authority | bug | | [#224](https://github.com/mudler/vllm.cpp/issues/224) | `ENG-DOCS-SITE` | Publish `docs/` as a GitHub Pages site without owning a second copy | feature | diff --git a/.agents/specs/bench-assert-clock-state.md b/.agents/specs/bench-assert-clock-state.md new file mode 100644 index 000000000..b6c5fabb1 --- /dev/null +++ b/.agents/specs/bench-assert-clock-state.md @@ -0,0 +1,439 @@ +# BENCH-ASSERT-CLOCK-STATE — a ratio may not be quoted without the clock it was measured at + +Issue: [#543](https://github.com/mudler/vllm.cpp/issues/543) (the defect — +per-call attribution is not reproducible across box states), +[#545](https://github.com/mudler/vllm.cpp/issues/545) (the reboot blocker that +makes cross-boot comparison the *normal* case rather than the exception) +Row: `BENCH-ASSERT-CLOCK-STATE` +Prior art: [#375](https://github.com/mudler/vllm.cpp/issues/375) and +[#520](https://github.com/mudler/vllm.cpp/issues/520) — the same class. An +environment variable nobody recorded silently repriced every number, and the +harness could not tell because it never wrote the variable down. + +## The defect + +On `dgx.casa` (GB10, driver `580.159.03`) the SM clock differs **between boots** +and is not throttling — `clocks_throttle_reasons.active = 0x0`, persistence +`Enabled`: + +| boot | SM clock over the captured window | our ms/step | +|---|---|---| +| `f6bbbfc6` | n=61, min 2398 / **med 2470** / max 2489 | **82.1664** | +| `2fca2b02` | n=50, **flat 2190** (`clocks.max.sm` 3003, applications 2418) | **88.1000** | + +A **12.79%** median-clock delta produced **+7.22%** step time. The control is +what settles it: `marlin::Marlin`, 129 calls/step, byte-identical invocation, +**no source change** between `a170c81c` and `4064558d0`, moved +**45.2845 → 49.6544 ms/step = +9.65%**. + +That control drift is **larger than either deficit it was used to rank** — +`in_proj` +2.97%, `out_proj`/`o_proj` +6.28%. Those two are therefore **NOT +ESTABLISHED**: they were never taken against a clock control. The same effect +explains a same-binary same-arm swing of 382.60 → 357.59 us/call (−6.5%) across +a reboot, and two probes disagreeing ~6% uniformly eight minutes apart *within +one boot* (a 2398 MHz entry against a 1781 MHz one). + +Nothing in the tree records any of this. `grep -rn 'clocks\.' tools/ scripts/` +returns one hit, in prose, inside `.agents/benchmark-record.md`. The three +harness scripts that touch `nvidia-smi` capture `-q -d +PERFORMANCE,TEMPERATURE,POWER` into an **unparsed text blob** that no summary +reads, or query `--query-compute-apps` for idleness. No manifest carries a clock +value, a boot id, or a throttle state, so no ratio in this repository can be +attributed to the clock it was measured at. + +## Scope + +**In scope.** + +1. **One helper**, `tools/bench/gpu_clock_state.py`: sample `nvidia-smi`, build + the per-leg record, validate it fail-closed, and compare two arms. Other + harnesses import it; it duplicates nothing and defines no framework. It is + standard-library-only, like `serve_low_common.py`, so its logic runs in CPU + CI with no GPU and no `nvidia-smi`. +2. **Recording** in the leg-producing harness, `scripts/dgx-online-serving.sh`, + as a background sampler across the timed bench loop, written to + `clocks///r.{samples.jsonl,summary.json}` beside + `memory/…`. + + It carries **both** of the memory sampler's lifetime properties, which is + what "the same shape" has to mean. `mpid` is a **global** the EXIT trap waits + on, and `sample_process_memory.py` is **bounded** by `--pid "${spid}"`. The + clock sampler's `clock_pid` was `local` to `run_leg` and therefore invisible + to the trap, and it was launched with neither `--pid` nor `--max-duration`, + so its only stop condition was a `SIGTERM` that `set -euo pipefail` skips + whenever `online_gate.py bench` fails inside the loop: the sampler was + orphaned on **every** abort path and went on polling `nvidia-smi` once a + second forever, on a shared box another session may hold `$HOME/gpu.lock` + on. `clock_pid` is now a global reaped by `cleanup_server`, and the sampler + is bounded by `--max-duration ${clock_sampler_max_seconds}` (7200 s, 4× the + driver's own `ready_timeout_seconds`, so it is a safety net that cannot + truncate a leg the rest of the driver still considers live). +3. **Asserting** in the ratio-producing surface, `tools/bench/ + online_gate_summary.py`, through the existing `reasons` seam: a violated + clock contract makes a leg *not binding-eligible*, which is this harness's + spelling of NOT ESTABLISHED. Every ratio additionally carries a `clock` + block naming both arms' medians, their offset, and the estimated timing + effect, so a reader can size the clock against the effect without leaving + the row. +4. **The operational fix** in `.agents/benchmarking.md`, including the + shared-host hazard. +5. **A note where existing numbers are cited** that they predate clock + assertion. + +**Out of scope, deliberately.** + +- **Editing any recorded number.** AGENTS.md: never delete evidence. The past + figures stay exactly as they are and gain a note; nothing is restated. +- **Re-measuring.** The GPU is held by another session, `$HOME/gpu.lock` is + taken, and #545 means the box does not survive a four-leg chain. This row + makes the *next* measurement attributable; it takes none. +- **Changing the clock.** `nvidia-smi -lgc` is documented here and executed by + nobody in this row — it is a shared-host mutation (§Operational fix). +- **The trace/per-kernel harnesses** (`finalize_*_trace.py`, + `summarize_torch_kernels.py`, `gdn_packed_component.py`). They import the same + helper and the same sampler CLI is what they would call, but wiring each one + is a separate change with its own fixtures. Recorded as **owed** below rather + than quietly skipped — and it is the trace path, not the online gate, that + produced the two retracted findings. + +## Design + +### What is recorded + +Per leg, `clocks///r.summary.json`: + +| field | source | +|---|---| +| `boot_id` | `/proc/sys/kernel/random/boot_id` | +| `sm_clock_mhz` | `{n, min, median, max, spread_pct}` over the window | +| `clocks_max_sm_mhz` | `clocks.max.sm` | +| `clocks_applications_graphics_mhz` | `clocks.applications.graphics` | +| `throttle_reasons_active` | sorted union of `clocks_throttle_reasons.active` | +| `persistence_mode` | `persistence_mode` | +| `driver_version`, `gpu_name` | `driver_version`, `name` | +| `idle_samples_excluded` | count of samples with `utilization.gpu == 0` | + +`spread_pct` is `(max − min) / median × 100` over the retained samples. The raw +per-sample rows stay in `r.samples.jsonl`, because a summary that cannot be +recomputed from its own evidence is a claim, not a record. + +**Idle samples are excluded from the statistics and counted, not dropped.** A +clock read while the GPU is doing nothing did not price any work, and the timed +window necessarily contains the harness's own gaps between concurrency points. +Excluding them silently would be a lie; the count is in the record, and a leg +that is *entirely* idle has `n == 0` and fails validation. + +### What is asserted + +| assertion | value | how justified | +|---|---|---| +| both arms of a ratio share `boot_id` | exact | cross-boot comparison is what produced the retracted findings; there is no threshold that makes it safe | +| both arms share every `STATIC_FIELDS` value | exact | see **the override**, below | +| within-run spread | `≤ 5.0%` | see below | +| cross-arm median offset | `≤ 1.0%` | see below | +| retained busy samples | `≥ 30` | see below | +| busy fraction of the window | `≥ 50%` | see below | +| `throttle_reasons_active` carries no non-benign bit | mask | a throttled window is not the window the number claims | +| `persistence_mode == Enabled` | exact | already true on the box; its absence changes idle clock behavior | + +**Within-run spread, 5.0%.** The admissible band is bounded on both sides by the +data above. It must *accept* the only clean window we have — +`(2489 − 2398) / 2470 = 3.68%` — because a threshold that voids our one good +measurement is useless. It must *reject* the within-boot disagreement that a +2398 MHz entry and a 1781 MHz one represent, which is ~26% however it is +normalized. 5.0 sits just above the clean observation, with ~1.3 points of +headroom so a marginally noisier but still healthy window is not spuriously +voided, and roughly five times below the failure it exists to catch. + +It is deliberately **not** held to the forward criterion the offset is held to, +and the reason is recorded rather than left to be rediscovered. +`5.0 × 0.7548 = 3.77%` exceeds the `2.97%` smallest deficit ranked, so a leg +sitting *at* the spread ceiling can carry an artifact larger than that deficit. +The two rules defend different things. The **offset** bounds a *systematic* +difference between the arms — one arm ran at one clock and the other at another, +and the whole of it transfers into the ratio — so it must sit under the smallest +effect anyone ranks. **Spread** bounds *dispersion inside one arm's window*, +which does not transfer that way: both arms sweep the same six concurrency +points on the same box, so most of the dispersion is common, and what survives +into the ratio is the difference of two medians, which the offset rule already +bounds at 1.0%. The spread rule exists to detect that a window was not one state +*at all* — the ~26% within-boot disagreement — not to bound a transferable bias. +Tightening it to satisfy the forward criterion would mean `≤ 3.93%`, which sits +0.25 points above our only clean capture and would void it on any +noisier-but-healthy day, the exact failure the both-sides bound was chosen to +avoid. The residual is therefore stated: **passing spread establishes that each +arm was one state; it does not on its own establish a sub-4% deficit.** The +offset rule is what qualifies the ratio. + +**Cross-arm median offset, 1.0%.** For any kernel whose time scales with clock +the transfer is **bounded above by 1.0** — a 12.79% clock deficit can cost at +most 12.79% of time — so a 1.0% offset implies **at most a 1.0% effect on +physics**, with no appeal to any measurement. That is already under the ~2.97% +smallest deficit this harness has been used to rank, so a pair inside the +threshold cannot have had its ranking inverted by clocks. + +The one cross-boot event we have repriced a byte-identical kernel by **+9.65%** +for a **12.79%** median-clock offset: a transfer of **0.7548** percentage points +of kernel time per point of clock (step-level transfer was lower, 0.565; the +larger is used). That coefficient is `n = 1`, and it sits *below* the 1.0 +ceiling exactly as a partly memory-bound kernel should — which is corroboration, +not the argument. The distinction matters and is recorded: the coefficient is +**not a gate term** (no gate expression evaluates it, which the mutation set +proves) but it *was* a gate **premise**, because the threshold was originally +chosen by multiplying through it. The physics bound retires it from that role — +the threshold holds at the transfer's theoretical ceiling — leaving the +coefficient to *report* an estimated effect and nothing else. + +**Retained busy samples, 30, and busy fraction, 50%.** Without a floor the +incentive is **inverted**: `spread_pct` over `n == 1` is definitionally +**0.00%**, the best score the gate can award, so a window the sampler barely +observed outscores one it actually watched — and `idle_samples_excluded`, the +field that would betray it, was written to `r.summary.json` and then never +asserted, never folded into the ratio's `clock` block, and never printed. Six +legs each holding one busy sample and 300 idle scored `gate_pass: true`, `clock +reasons: []`, and a report line reading `+0.00%`. + +The count floor is bounded on both sides like the spread rule. It must *accept* +the real windows: #543's two captures are `n = 61` and `n = 50`, and 30 sits 40% +below the smaller. It must *reject* the degenerate window, and 30 is 30× above +`n == 1`. And it reads off the sampler and the grid rather than off what happens +to pass: at the driver's `--interval 1` a busy sample is **a second of observed +busy GPU**, while the smallest configured leg (`POINTS_BY_MODEL`'s four-point +set: 6+6+12+24 prompts at 128 output tokens = 1920 sequential decode steps) +would have to average under ~16 ms/step *including* its 48 prefills of 1024 +tokens to finish inside 30 busy seconds. This box measures 82–88 ms/step. A leg +under the floor is not a fast leg; it is an unobserved one. + +The count alone does not catch dilution — 30 busy among 3000 idle clears it — so +the busy **fraction** is floored too. The sampler covers the bench loop only: it +starts after the preflight stream and stops before the after-thermal snapshot, +so the non-busy time inside the window is client startup between six +`online_gate.py bench` invocations, not model load, not cache drops, not server +start, while the GPU serves 336 requests of 1024-in/128-out across the span. +Requiring the *majority* of the window to be busy is the weakest form of the +claim the record makes. It is also the field that betrays a sampler which +outlived its leg: an orphan accrues idle samples without bound and nothing else +in the record notices. + +Both counts are now surfaced in the ratio's `clock` block +(`_busy_samples`, `_idle_samples_excluded`) and printed on the +report's `observed:` line beside the offset, because a number nobody prints is a +number nobody checks. + +**The override.** `--allow-cross-boot` exists because #545 makes same-boot +capture of a four-leg chain unreliable, and a gate nobody can satisfy is a gate +everybody routes around. It does not make the comparison clean: it converts the +refusal into a recorded caveat (`cross_boot_override: true` plus the boot ids +and the offset in the ratio's `clock` block and in the report). Every other +assertion still applies — **the override waives `boot_id` and nothing else.** + +That has to be enforced explicitly, not implied. `STATIC_FIELDS` was checked +*within* a window (`build_clock_record`) and *between one arm's legs* +(`merge_clock_records`), and same-boot equality was doing duty as the implicit +proxy for "same machine" on the third edge. Removing the boot check removed the +proxy with it: an **NVIDIA GB10 / driver 580.159.03 / max 3003** arm compared +**clean** against an **NVIDIA H100 80GB HBM3 / driver 550.54.15 / max 1980** +one, with a caveat that said only "different boots". `compare_clock_records` now +asserts every `STATIC_FIELDS` value across the arms **unconditionally**. #545 +makes the override the normal path, so this was reachable, not theoretical. + +### Why this seam + +`online_gate_summary._memory_for_leg` already reads an optional per-leg evidence +artifact and turns every defect into a `reason` that clears +`binding_eligible`. `_clock_for_leg` is the same function shape against the same +seam. Nothing new is invented, no gate is weakened, and a missing clock record +voids a leg exactly the way a missing memory summary already does. + +That has a consequence worth stating rather than discovering: **re-summarizing +an existing evidence tree now yields NOT ESTABLISHED**, because no tree on disk +carries a clock record. That is the correct answer — those trees genuinely +cannot be attributed to a clock — and it is why the note in §Records exists +instead of a retroactive edit. + +## Risks + +- **The gate is unpassable if the spread rule is too tight.** Mitigated by + excluding idle samples and by choosing the threshold from the clean window + rather than from theory. If a real leg still exceeds 5%, that is a + *measurement finding to record*, not a threshold to widen quietly. +- **`nvidia-smi` field names drift.** Driver 580 accepts + `clocks_throttle_reasons.active`; newer drivers prefer + `clocks_event_reasons.active`. The sampler queries the throttle spelling, and + a query failure is a refusal to sample, never a default. +- **The sampler perturbs the measurement.** One `nvidia-smi` per second against + a 128-token × six-concurrency leg, launched identically on both arms, so it + cancels in the ratio — the same argument `start_server` already makes for the + memory sampler, and it is recorded in the same place. +- **The coverage floors are unpassable if a real leg falls under them.** Same + posture as the spread rule: a real leg voided by the 30-sample or 50%-busy + floor is a *measurement finding to record*, not a threshold to widen quietly. + The floors were chosen so the failure direction is loud — a voided leg — never + a silent pass, which is what the unfloored version did. +- **`--max-duration` truncates a genuinely long leg.** At 7200 s the sampler + would stop while the leg continued and the record would under-cover the + window. That is 4× the driver's readiness budget and far above any leg the + grid can produce; it is a bound on an orphan, not a budget on a leg. If a leg + ever reaches it, the record is partial and the leg is not established. + +## Tests + +`tests/tools/test_gpu_clock_state.py`, synthetic manifests only, no GPU: + +- parsing a real `--query-gpu` CSV line, including the `nounits` form +- summary statistics, idle exclusion, and the `n == 0` refusal +- fail-closed validation: missing field, non-finite value, wrong type, + negative clock, empty throttle list +- **the cross-boot refusal**, and that `--allow-cross-boot` records a caveat + rather than silently passing +- **the over-spread refusal**, at the threshold, either side of it +- the cross-arm offset refusal and the reported estimated effect +- the throttle mask: benign bits accepted, each non-benign bit refused +- **the coverage floors**: the one-busy-sample-of-301 record refused on the + COUNT rather than on the spread it has no right to report; a diluted window + that clears the count and fails the fraction; both floors at and either side + of the threshold; a non-integer idle count refused rather than crashing the + division +- **the hardware identity across arms**: each `STATIC_FIELDS` value, under the + override *and* without it, plus the full GB10-against-H100 shape +- **the staircase arm**: three individually-flat legs at 2470 / 2300 / 2190 on + ONE boot, with the vLLM arm pinned at the merged median so the cross-arm + offset stays 0.00% and cannot mask the removal +- wiring: `online_gate_summary` voids a leg with a missing, cross-boot, or + over-spread clock record, matched against **that call site's own** message — + #520 established that an unanchored `assertRaises` stays green on a gutted + check + +Fixture legs now carry a realistic window. A three-sample leg was never a leg +anyone could have captured — the driver samples at 1 Hz across a bench loop of +minutes — so `_window`/`_clock_window` repeat each pattern to clear the floor. +Whole-list repetition preserves min, median, max and therefore `spread_pct` +*exactly*, so every threshold case still asserts what it asserted; only the +count changes, which is the floor's subject. + +Regression surface: `tests/tools` in full — **233** tests on the base SHA +`8b00f79f2`, **295** at `3e0f2b2d3`, **310** here; 0 removed at either step, +proven by a sorted test-name diff. A changed count is RED even when it prints +`OK`. + +**Twenty-four mutations**, applied one at a time with `count == 1` anchors and +restored byte-for-byte by sha256 — the original twelve (`M1`–`M12`) plus twelve +against this round's surfaces (`R13`–`R24`). **24 / 24 RED.** + +| mutation | what it breaks | +|---|---| +| `M1` | the cross-boot refusal | +| `M2` | within-run spread widened to 1000% | +| `M3` | cross-arm offset widened to 1000% | +| `M4` | throttle mask opened to every bit | +| `M5` | idle samples counted as busy | +| `M6` | the straddled-boot fold | +| `M7` | leg clock reasons dropped from the aggregate | +| `M8` | arm clock reasons dropped from the aggregate | +| `M9` | the THROUGHPUT ratio's `clock_established` term | +| `M10` | the MEMORY ratio's `clock_established` term | +| `M11` | the missing-record reason | +| `M12` | the stream/summary reconciliation | +| `R13` | the retained-busy-sample floor | +| `R14` | the busy-fraction floor | +| `R15` | **the override waives spread, throttle AND persistence** | +| `R16` | the cross-arm `STATIC_FIELDS` assertion | +| `R17` | `idle_samples_excluded` type validation | +| `R18` | the busy-sample floor lowered to 1 | +| `R19` | the busy-fraction floor lowered to 0 | +| `R20` | the override waives hardware identity after all | +| `R21` | the merged spread spans only the first leg | +| `R22` | busy-sample surfacing | +| `R23` | idle-sample surfacing | +| `R24` | the report's `observed:` line | + +**Three of `M1`–`M12` survived the author's first round** — both ratio-level +terms and the missing-record reason. That is #520's lesson repeating: the +leg-level reason already voided every gate assertion, so each ratio-level site +was dominated and a `gate_pass` assertion let the two ratio families mask each +other's removal. Two cases assert the two families' `binding_eligible` +SEPARATELY on a pair whose arms are individually clean, and a third pins the +reason text that names the offending arm. + +**`R15` survived review** and is the reason the staircase case exists. Both +tests that named "the override does not waive state" missed it: one asserts an +*offset* reason, appended OUTSIDE the mutated expression, and the other writes +an over-spread LEG that `_clock_for_leg` has already voided at leg level. +Exactly one check lives only at the compare site — the **merged-arm spread**, +an arm whose three legs each sat flat at a different clock — +because `merge_clock_records` raises only on a straddled boot and on a static +field, and `_clock_for_arm` surfaces only what it raises. + +**`R17` survived this round's first pass** and was a genuine gap in the new +code, not a dominated site: nothing constructed a record with a non-integer +`idle_samples_excluded`, so the guard that keeps `busy + idle` out of the +arithmetic was unasserted. Two cases now pin it — the refusal and the +"reason, not a crash" path. + +One methodological note worth keeping: `M11` first read SURVIVED because the +mutation itself was inert — `"reasons": [] or [...]` evaluates to the non-empty +list. A byte-level sha256 check proves the file changed, not that the *behavior* +did. `[] and [...]` is the encoding that actually removes the reason, and under +it `M11` is RED. + +## Gates + +- `python3 -m unittest discover -s tests/tools -t .` — full, serial. `pytest` + mis-collects this tree (16 false failures on clean `main`); do not use it. +- `scripts/agent-preflight.sh --staged`, then again on committed HEAD. +- `bash -n scripts/dgx-online-serving.sh`. +- **No benchmark gate.** The GPU is held, the box is at 99% disk, and #545 is + open. Recorded `PENDING` with the exact handoff rather than waived. + +## Stop conditions + +- Stop before running any GPU work or changing any clock: `$HOME/gpu.lock` is + held by another session and `-lgc` would corrupt their in-flight measurement. +- Stop before editing a recorded number to agree with the new contract. A past + figure that cannot be attributed gains a note, never an edit. +- Stop if satisfying the contract requires weakening an existing eligibility + reason. The clock rule is additive or it is wrong. +- Stop if the helper starts to need a plugin surface, a registry, or a second + file. One module, imported. + +## Evidence + +- Live read-only `ssh dgx.casa` sample, 2026-08-12, used to fix the fixture + format verbatim: `0, NVIDIA GB10, 580.159.03, 2190 MHz, 3003 MHz, 2418 MHz, + 0x0000000000000000, Enabled, P0`, boot id + `13dc5579-455c-45c8-8e4d-d09c457fa826`. That is a **third** boot id, and the + clock is again the degraded 2190 — the defect is live, not historical. +- The two-boot table and the `marlin::Marlin` control are #543's, already + commented there. + +## Owed + +- The trace/per-kernel harnesses do not yet call the helper (§Scope). Until they + do, a per-call `us/call` figure carries no clock attribution — which is + precisely where #543's retracted findings came from. + [`.agents/benchmarking.md`](../benchmarking.md) now says so in the same words + rather than describing the wiring in the present tense. +- The `0.7548` transfer coefficient is `n = 1`. A second cross-boot pair, once + #545 allows one, either confirms it or replaces it. It is no longer load + bearing for the offset threshold, which holds at the transfer's physical + ceiling of 1.0. +- **`all-runs.json` carries no clock block and no `allow_cross_boot` flag.** + `report.md` prints `(OVERRIDDEN)` and `CAVEAT:`, so it is not buried for a + human reader, but the JSON a consumer parses is silent about both. Recorded + rather than fixed: the ratio document is the surface that qualifies a ratio, + and widening the runs document is a change with its own fixtures. +- **`compare_clock_records` builds its keys as `f"{ours_label}_boot_id"`.** Two + identical labels would collapse one arm's block into the other's. Unreachable + from any current call site — `online_gate_summary` passes the defaults — and + recorded so a future caller that takes labels from data knows the shape. +- **The busy floors are asserted, but never yet measured against a real leg.** + They are derived from the sampling rate and the grid definition (§What is + asserted); the first attributable grid is what confirms the derivation. If a + real leg lands under either floor, that is a finding to record, not a + threshold to widen. + +## Now + +`ACTIVE` — recorded, asserted, and documented; no measurement is taken and none +is restated. The first attributable grid is `PENDING` on `$HOME/gpu.lock` and +on #545. diff --git a/docs/BENCHMARKS.md b/docs/BENCHMARKS.md index 3a2fa3149..4c4b414fa 100644 --- a/docs/BENCHMARKS.md +++ b/docs/BENCHMARKS.md @@ -15,6 +15,7 @@ | **DSR fix: async readback capability (2026-08-08)** | **No number owed**: behavior-neutral (CPU/CUDA async-ON, discrete non-CUDA async-OFF, unchanged); moves a `kCUDA` check onto `Backend`, unblocking red CI on #127/#154/#155 | | **`ROAD-V1-MEM` M1+M2 (2026-08-08)** | KV auto-sizing CPU brick: `--kv-cache-memory` sizes the pool from a byte budget via the group-aware `KVBytesPerBlock` divisor (ABI v16, CPU-gated). M3 profile run dgx-gated | | **Record/checker repair 2026-08-07–08** | Gates fixed. Public: `VT_GEMMA4_EXPERT_VRAM_MB` (positive-MiB LRU cap; unset/0 unlimited), `VT_SERVER_MAX_{PROMPT_CHARS,NEW_TOKENS}` (200000/4096; 0 disables); nine Gemma4/ROCm tuners internal. No runtime/perf change. | +| **Clock attribution (`BENCH-ASSERT-CLOCK-STATE`, #543)** | dgx.casa GB10, driver 580.159.03, no throttling either side | **Every figure here predates clock assertion.** SM clock differs BETWEEN BOOTS: med 2470 vs flat 2190 MHz (12.79%) repriced byte-identical `marlin::Marlin` **+9.65%**. Next figure needs an OBSERVED window, same box | n/a, nothing withdrawn | | **vLLM** | Qwen3.6-27B NVFP4 `unsloth` @`890bdef7`, GB10 | ahead 4.5% at c1, **tie** at c2 to c32 | identical | | **vLLM** | Qwen3.6-27B NVFP4 `nvidia` @`0893e160` (ModelOpt `modelopt_mixed`), GB10 | **0.937x to 0.956x, BEHIND** and FLAT over c1-c32 (canonical 6-point 2026-08-11). The 2026-08-10 c1 0.838 did NOT reproduce (#349); gap NOT attributed | near-tie | | **vLLM** | Qwen3.6-35B-A3B NVFP4 `nvidia` @`491c2f1e`, GB10 | **CANONICAL 2026-08-11 @`348c265d`: 0.918x-0.972x** over c1-c32 (first c16/c32); best c4 0.9719. Supersedes the ad-hoc grid | near-tie | diff --git a/docs/STATUS.md b/docs/STATUS.md index 6df60e9c4..f2d80483c 100644 --- a/docs/STATUS.md +++ b/docs/STATUS.md @@ -34,6 +34,22 @@ attributed rather than withdrawn (our engine is unchanged by the advance, and the two oracles tie in speed where that was checked); a re-benchmark at the pin is pending and blocked on [#522](https://github.com/mudler/vllm.cpp/issues/522). +**Clock attribution (`BENCH-ASSERT-CLOCK-STATE`, ACTIVE, 2026-08-12, +[#543](https://github.com/mudler/vllm.cpp/issues/543)):** the SM clock on +`dgx.casa` differs BETWEEN BOOTS without throttling — a 12.79% delta repriced a +byte-identical `marlin::Marlin` by +9.65%, larger than either deficit that +comparison ranked. The harness now records the clock window, `clocks.max.sm`, +the applications clock, the active throttle reasons, persistence mode and the +**boot id** per leg, refuses a cross-boot pair, and voids a run whose window was +over-spread or barely observed — a single busy sample scores a perfect 0.00% +spread, so the retained sample count and the busy fraction are floored and +printed. The cross-boot override waives the boot id and nothing else: the GPU, +driver and clock ceilings are compared across the arms either way +([spec](../.agents/specs/bench-assert-clock-state.md)). Every speed figure +recorded before this date predates the assertion: not withdrawn, not restated, +but carrying no clock attribution. The first attributable grid is pending on the +box lock and on [#545](https://github.com/mudler/vllm.cpp/issues/545). + ## Capability status Cold start: `MEASURED`. Load (#150): 27B bf16 loads **1.54x warm / 1.61x cold**, moving diff --git a/scripts/dgx-online-serving.sh b/scripts/dgx-online-serving.sh index 0fe4033b0..ca256c5c5 100755 --- a/scripts/dgx-online-serving.sh +++ b/scripts/dgx-online-serving.sh @@ -52,6 +52,8 @@ gdn_packed_mode="" # the old 360 x 5 s timeout, preserved exactly. ready_poll_interval=0.2 ready_timeout_seconds=1800 +# Hard ceiling on the SM-clock sampler's own lifetime (#543). See run_leg. +clock_sampler_max_seconds=7200 while (($#)); do case "$1" in @@ -345,11 +347,32 @@ profile_control_flag=$([[ ${mode} == trace-only ]] && echo on || echo off) spid="" mpid="" +# GLOBAL, exactly like mpid, because the EXIT trap has to be able to reap it. As +# a `local` in run_leg it was invisible to cleanup_server, so any failure inside +# the bench loop -- and `set -e` makes a failing `online_gate.py bench` exactly +# that -- left the sampler polling nvidia-smi once a second forever on a box +# another session may be measuring on. +clock_pid="" startup_launch_epoch="" startup_ready_epoch="" profiled_pid="" profiled_pgid="" +# Stop the clock sampler and REQUIRE it to have written its record. A leg whose +# clock was not captured is not a leg with an unknown clock -- it is a number +# that cannot be attributed to a box state, and online_gate_summary.py voids it. +# Reads and clears the GLOBAL clock_pid so that calling it twice -- once on the +# normal path, once from the EXIT trap -- is a no-op the second time. +stop_clock_sampler() { + local pid=${clock_pid} + clock_pid="" + [[ -n ${pid} ]] || return 0 + kill -TERM "${pid}" 2>/dev/null || true + wait "${pid}" +} cleanup_server() { + # Before the server, because the sampler's window ends with the leg and an + # orphan here outlives the whole script. + stop_clock_sampler || true if [[ -n ${profiled_pid} ]] && kill -0 "${profiled_pid}" 2>/dev/null; then if [[ -n ${profiled_pgid} && ${profiled_pgid} == "${profiled_pid}" ]]; then kill -TERM -- "-${profiled_pgid}" 2>/dev/null || true @@ -558,13 +581,15 @@ run_leg() { local baseline final idle_ok=0 local memory_dir="${evidence}/memory/${model}/${engine}" local thermal_dir="${evidence}/thermal/${model}/${engine}" + local clock_dir="${evidence}/clocks/${model}/${engine}" local return_dir="${evidence}/memory-return/${model}/${engine}" local cache_dir="${evidence}/cache-drop/${model}/${engine}" local preflight_dir="${evidence}/preflight/${model}/${engine}" local before_cache="${cache_dir}/r${repetition}-before.json" local after_cache="${cache_dir}/r${repetition}-after.json" mkdir -p \ - "${memory_dir}" "${thermal_dir}" "${return_dir}" "${cache_dir}" "${preflight_dir}" + "${memory_dir}" "${thermal_dir}" "${clock_dir}" "${return_dir}" "${cache_dir}" \ + "${preflight_dir}" gpu_idle || { echo "GPU is not idle before ${model}/${engine}/r${repetition}" >&2; return 1; } drop_caches "${before_cache}" @@ -584,10 +609,33 @@ run_leg() { # online_gate.points_for so the summary never flags a missing result group. local concurrency_points="1 2 4 8 16 32" [[ ${model} == q3mxfp4 ]] && concurrency_points="1 2 4 8" + # The SM clock the TIMED window actually ran at (#543). The clock differs + # between boots on this box without throttling, and a 12.79% delta repriced a + # byte-identical kernel by 9.65% -- larger than the deficits it was used to + # rank. Sampling starts after the preflight stream so the window is the timed + # grid's rather than the server's warm-up, and stops before the after-thermal + # snapshot. One probe per second, launched identically on both arms, so its + # cost cancels in the ratio exactly as the memory sampler's does. + # + # --max-duration is the sampler's OWN stop condition, carried over from the + # memory sampler's --pid: that one dies with the process it watches, and this + # one must likewise not depend on a signal an aborting caller may never send. + # The ceiling is a safety net, not a budget -- it sits above the driver's own + # readiness budget (ready_timeout_seconds, 1800 s) by 4x, so it cannot truncate + # a leg the rest of the driver would still consider live, while an orphan dies + # instead of polling nvidia-smi once a second forever on a SHARED box. + python3 "${repo_root}/tools/bench/gpu_clock_state.py" sample \ + --output "${clock_dir}/r${repetition}.samples.jsonl" \ + --summary "${clock_dir}/r${repetition}.summary.json" \ + --interval 1 \ + --max-duration "${clock_sampler_max_seconds}" & + clock_pid=$! + local concurrency for concurrency in ${concurrency_points}; do kill -0 "${spid}" 2>/dev/null || { echo "server died before c${concurrency}" >&2 + stop_clock_sampler || true return 1 } python3 "${repo_root}/tools/bench/online_gate.py" bench \ @@ -600,6 +648,11 @@ run_leg() { --concurrency "${concurrency}" \ --repetition "${repetition}" done + stop_clock_sampler || { + echo "SM-clock sampler failed for ${model}/${engine}/r${repetition}" >&2 + cleanup_server + return 1 + } nvidia-smi -q -d TEMPERATURE,POWER >"${thermal_dir}/r${repetition}-after.txt" cleanup_server diff --git a/tests/tools/test_gpu_clock_state.py b/tests/tools/test_gpu_clock_state.py new file mode 100644 index 000000000..2b676e205 --- /dev/null +++ b/tests/tools/test_gpu_clock_state.py @@ -0,0 +1,724 @@ +"""Clock-state recording and assertion (`BENCH-ASSERT-CLOCK-STATE`, #543). + +Every case here is synthetic: no GPU, no `nvidia-smi`, no driver. The one real +input is the CSV row captured read-only from `dgx.casa` on 2026-08-12, which +fixes the parser's format contract rather than a value. + +The numbers the thresholds are argued from live in +`.agents/specs/bench-assert-clock-state.md` and in #543: + + boot f6bbbfc6 n=61 min 2398 / med 2470 / max 2489 82.1664 ms/step + boot 2fca2b02 n=50 flat 2190 88.1000 ms/step + +and the byte-identical `marlin::Marlin` control moved 45.2845 -> 49.6544 +ms/step across that pair. +""" + +from __future__ import annotations + +import json +import pathlib +import tempfile +import unittest + +from tools.bench.gpu_clock_state import ( + BENIGN_THROTTLE_MASK, + CLOCK_TIME_TRANSFER, + MAX_CROSS_ARM_OFFSET_PCT, + MAX_WITHIN_RUN_SPREAD_PCT, + MIN_BUSY_FRACTION, + MIN_BUSY_SAMPLES, + build_clock_record, + clock_reasons, + compare_clock_records, + merge_clock_records, + parse_query_row, + read_boot_id, + run_sampler, + summarize_sm_clocks, + validate_clock_record, +) +from tools.bench.serve_low_common import HarnessError + +# Verbatim `nvidia-smi --query-gpu=... --format=csv,noheader` output, dgx.casa, +# driver 580.159.03, 2026-08-12. The trailing `utilization.gpu` column is the +# one field the live probe did not request; its `%` unit form is asserted below. +LIVE_ROW = ( + "0, NVIDIA GB10, 580.159.03, 2190 MHz, 3003 MHz, 2418 MHz, " + "0x0000000000000000, Enabled, 97 %" +) +LIVE_ROW_NOUNITS = "0, NVIDIA GB10, 580.159.03, 2190, 3003, 2418, 0x0000000000000000, Enabled, 97" + +BOOT_GOOD = "f6bbbfc6-0000-4000-8000-000000000000" +BOOT_BAD = "2fca2b02-0000-4000-8000-000000000000" + + +def _samples(values, *, utilization=97, throttle="0x0000000000000000"): + return [ + { + "clocks_applications_graphics_mhz": 2418, + "clocks_max_sm_mhz": 3003, + "driver_version": "580.159.03", + "gpu_name": "NVIDIA GB10", + "persistence_mode": "Enabled", + "sm_clock_mhz": value, + "throttle_reasons_active": throttle, + "utilization_gpu_pct": utilization, + } + for value in values + ] + + +def _window(values): + """Repeat a clock pattern until it clears ``MIN_BUSY_SAMPLES``. + + Whole-list repetition preserves min, median, max and therefore + ``spread_pct`` EXACTLY, so every threshold case below still asserts what it + asserted before the coverage floor existed; only the sample COUNT changes, + which is the floor's entire subject. A fixture leg of three samples was + never a leg anyone could have measured -- the driver samples at 1 Hz across + a bench loop of minutes. + """ + + values = list(values) + repeats = -(-MIN_BUSY_SAMPLES // len(values)) + return values * repeats + + +def _record(values, *, boot_id=BOOT_GOOD, **kwargs): + return build_clock_record(_samples(_window(values), **kwargs), boot_id=boot_id) + + +class ParseTests(unittest.TestCase): + def test_live_row_with_units(self) -> None: + sample = parse_query_row(LIVE_ROW) + self.assertEqual(sample["gpu_name"], "NVIDIA GB10") + self.assertEqual(sample["driver_version"], "580.159.03") + self.assertEqual(sample["sm_clock_mhz"], 2190) + self.assertEqual(sample["clocks_max_sm_mhz"], 3003) + self.assertEqual(sample["clocks_applications_graphics_mhz"], 2418) + self.assertEqual(sample["throttle_reasons_active"], "0x0000000000000000") + self.assertEqual(sample["persistence_mode"], "Enabled") + self.assertEqual(sample["utilization_gpu_pct"], 97) + + def test_nounits_row_parses_identically(self) -> None: + self.assertEqual(parse_query_row(LIVE_ROW), parse_query_row(LIVE_ROW_NOUNITS)) + + def test_not_available_is_a_refusal_never_a_zero(self) -> None: + row = LIVE_ROW.replace("2190 MHz", "[N/A]") + with self.assertRaises(HarnessError) as caught: + parse_query_row(row) + self.assertIn("clocks.sm", str(caught.exception)) + + def test_short_row_is_refused(self) -> None: + with self.assertRaises(HarnessError) as caught: + parse_query_row("0, NVIDIA GB10, 580.159.03") + self.assertIn("expected", str(caught.exception)) + + +class BootIdTests(unittest.TestCase): + def test_boot_id_is_read_and_stripped(self) -> None: + with tempfile.TemporaryDirectory() as raw: + path = pathlib.Path(raw) / "boot_id" + path.write_text("13dc5579-455c-45c8-8e4d-d09c457fa826\n", encoding="utf-8") + self.assertEqual(read_boot_id(path), "13dc5579-455c-45c8-8e4d-d09c457fa826") + + def test_absent_boot_id_refuses_rather_than_defaults(self) -> None: + with tempfile.TemporaryDirectory() as raw: + with self.assertRaises(HarnessError) as caught: + read_boot_id(pathlib.Path(raw) / "absent") + self.assertIn("boot id", str(caught.exception)) + + def test_empty_boot_id_refuses(self) -> None: + with tempfile.TemporaryDirectory() as raw: + path = pathlib.Path(raw) / "boot_id" + path.write_text("\n", encoding="utf-8") + with self.assertRaises(HarnessError): + read_boot_id(path) + + +class SummaryTests(unittest.TestCase): + def test_min_median_max_and_n_over_the_window(self) -> None: + summary = summarize_sm_clocks([2398, 2470, 2489, 2470]) + self.assertEqual(summary["n"], 4) + self.assertEqual(summary["min"], 2398) + self.assertEqual(summary["max"], 2489) + self.assertEqual(summary["median"], 2470.0) + self.assertAlmostEqual(summary["spread_pct"], (2489 - 2398) / 2470.0 * 100.0) + + def test_the_clean_boot_window_is_368_percent(self) -> None: + # The observed clean window: this is the value the threshold has to + # accept, so it is pinned here rather than left implicit. + summary = summarize_sm_clocks([2398, 2470, 2489]) + self.assertAlmostEqual(summary["spread_pct"], 3.6842, places=3) + self.assertLess(summary["spread_pct"], MAX_WITHIN_RUN_SPREAD_PCT) + + def test_empty_window_refuses(self) -> None: + with self.assertRaises(HarnessError): + summarize_sm_clocks([]) + + def test_idle_samples_are_excluded_and_counted_not_dropped(self) -> None: + record = build_clock_record( + [ + *_samples([2470, 2470]), + *_samples([300], utilization=0), + ], + boot_id=BOOT_GOOD, + ) + self.assertEqual(record["idle_samples_excluded"], 1) + self.assertEqual(record["sm_clock_mhz"]["n"], 2) + self.assertEqual(record["sm_clock_mhz"]["min"], 2470) + + def test_an_entirely_idle_window_is_refused(self) -> None: + with self.assertRaises(HarnessError) as caught: + build_clock_record(_samples([300, 300], utilization=0), boot_id=BOOT_GOOD) + self.assertIn("idle", str(caught.exception)) + + def test_static_fields_must_not_change_mid_window(self) -> None: + samples = [*_samples([2470]), *_samples([2470])] + samples[1]["clocks_max_sm_mhz"] = 2000 + with self.assertRaises(HarnessError) as caught: + build_clock_record(samples, boot_id=BOOT_GOOD) + self.assertIn("clocks_max_sm_mhz", str(caught.exception)) + + def test_throttle_reasons_are_a_sorted_union(self) -> None: + samples = [*_samples([2470]), *_samples([2470], throttle="0x0000000000000001")] + record = build_clock_record(samples, boot_id=BOOT_GOOD) + self.assertEqual( + record["throttle_reasons_active"], + ["0x0000000000000000", "0x0000000000000001"], + ) + + +class ValidationTests(unittest.TestCase): + def test_a_complete_record_validates(self) -> None: + validate_clock_record(_record([2398, 2470, 2489]), label="ours") + + def test_every_required_field_is_required(self) -> None: + for field in ( + "boot_id", + "clocks_applications_graphics_mhz", + "clocks_max_sm_mhz", + "driver_version", + "gpu_name", + "idle_samples_excluded", + "persistence_mode", + "sm_clock_mhz", + "throttle_reasons_active", + ): + with self.subTest(field=field): + record = _record([2470]) + record.pop(field) + with self.assertRaises(HarnessError) as caught: + validate_clock_record(record, label="ours") + self.assertIn(field, str(caught.exception)) + + def test_non_finite_clock_is_refused(self) -> None: + record = _record([2470]) + record["sm_clock_mhz"]["median"] = float("inf") + with self.assertRaises(HarnessError): + validate_clock_record(record, label="ours") + + def test_non_positive_clock_is_refused(self) -> None: + record = _record([2470]) + record["sm_clock_mhz"]["median"] = 0.0 + with self.assertRaises(HarnessError) as caught: + validate_clock_record(record, label="ours") + self.assertIn("positive", str(caught.exception)) + + def test_a_non_integer_idle_count_is_refused(self) -> None: + # The floors divide by `busy + idle`, so an idle count that is not a + # non-negative integer has to fail validation rather than reach the + # arithmetic: `int("many")` is an uncaught ValueError, not a reason. + for value in ("many", 2.5, -1, True, None): + with self.subTest(value=value): + record = _record([2470]) + record["idle_samples_excluded"] = value + with self.assertRaises(HarnessError) as caught: + validate_clock_record(record, label="ours") + self.assertIn("idle_samples_excluded", str(caught.exception)) + + def test_a_non_integer_idle_count_becomes_a_reason_not_a_crash(self) -> None: + record = _record([2470]) + record["idle_samples_excluded"] = "many" + reasons = clock_reasons(record, label="ours") + self.assertEqual(len(reasons), 1) + self.assertIn("idle_samples_excluded", reasons[0]) + + def test_empty_throttle_list_is_refused(self) -> None: + record = _record([2470]) + record["throttle_reasons_active"] = [] + with self.assertRaises(HarnessError): + validate_clock_record(record, label="ours") + + def test_a_json_round_trip_still_validates(self) -> None: + record = json.loads(json.dumps(_record([2398, 2470, 2489]))) + validate_clock_record(record, label="ours") + + +class WithinRunTests(unittest.TestCase): + def test_the_clean_window_is_established(self) -> None: + self.assertEqual(clock_reasons(_record([2398, 2470, 2489]), label="ours"), []) + + def test_the_flat_degraded_window_is_also_established(self) -> None: + # 2190 flat is the WRONG clock, not an unstable one. The within-run rule + # cannot see that; only the cross-arm rule can. Pinned so a future edit + # cannot quietly repurpose the spread rule into an absolute-clock rule. + self.assertEqual(clock_reasons(_record([2190] * 50), label="vllm"), []) + + def test_over_spread_window_is_not_established(self) -> None: + # The two probes eight minutes apart inside ONE boot: 2398 against 1781. + reasons = clock_reasons(_record([1781, 2100, 2398]), label="ours") + self.assertEqual(len(reasons), 1) + self.assertIn("spread", reasons[0]) + self.assertIn(str(MAX_WITHIN_RUN_SPREAD_PCT), reasons[0]) + + def test_the_threshold_is_inclusive_on_both_sides(self) -> None: + # median 2000 -> a 100 MHz range is exactly 5.0%. + self.assertEqual(clock_reasons(_record([1950, 2000, 2050]), label="ours"), []) + self.assertEqual(len(clock_reasons(_record([1949, 2000, 2050]), label="ours")), 1) + + def test_a_non_benign_throttle_bit_is_not_established(self) -> None: + for bit, name in ( + (0x4, "SwPowerCap"), + (0x8, "HwSlowdown"), + (0x20, "SwThermalSlowdown"), + (0x40, "HwThermalSlowdown"), + (0x80, "HwPowerBrakeSlowdown"), + ): + with self.subTest(name=name): + record = _record([2470], throttle=f"0x{bit:016x}") + reasons = clock_reasons(record, label="ours") + self.assertEqual(len(reasons), 1) + self.assertIn("throttl", reasons[0]) + + def test_benign_bits_are_accepted(self) -> None: + for bit in (0x0, 0x1, 0x2, 0x100): + with self.subTest(bit=bit): + self.assertTrue(bit & ~BENIGN_THROTTLE_MASK == 0) + record = _record([2470], throttle=f"0x{bit:016x}") + self.assertEqual(clock_reasons(record, label="ours"), []) + + def test_persistence_off_is_not_established(self) -> None: + record = _record([2470]) + record["persistence_mode"] = "Disabled" + reasons = clock_reasons(record, label="ours") + self.assertEqual(len(reasons), 1) + self.assertIn("persistence", reasons[0]) + + def test_one_busy_sample_is_not_the_cleanest_possible_record(self) -> None: + """The incentive without a floor is INVERTED, so the floor is pinned. + + `spread_pct` over n == 1 is definitionally 0.00% -- the best score the + gate can award -- so a window the sampler barely observed outscores one + it actually watched. The record below is exactly that shape and must be + refused on the COUNT, not on the spread it has no right to report. + """ + + record = build_clock_record( + [*_samples([2470]), *_samples([300] * 300, utilization=0)], + boot_id=BOOT_GOOD, + ) + self.assertEqual(record["sm_clock_mhz"]["n"], 1) + self.assertEqual(record["sm_clock_mhz"]["spread_pct"], 0.0) + reasons = clock_reasons(record, label="ours") + self.assertTrue(any("retained only 1 busy" in reason for reason in reasons)) + self.assertTrue(any(str(MIN_BUSY_SAMPLES) in reason for reason in reasons)) + + def test_the_busy_sample_floor_is_inclusive(self) -> None: + exactly = build_clock_record( + _samples([2470] * MIN_BUSY_SAMPLES), boot_id=BOOT_GOOD + ) + self.assertEqual(clock_reasons(exactly, label="ours"), []) + one_short = build_clock_record( + _samples([2470] * (MIN_BUSY_SAMPLES - 1)), boot_id=BOOT_GOOD + ) + self.assertEqual(len(clock_reasons(one_short, label="ours")), 1) + self.assertIn("retained only", clock_reasons(one_short, label="ours")[0]) + + def test_a_diluted_window_is_refused_even_with_enough_busy_samples(self) -> None: + """The count floor alone does not catch dilution; the fraction does. + + 30 busy samples among 3000 idle clears the count and still reports a + spread over 1% of the window. + """ + + record = build_clock_record( + [ + *_samples([2470] * MIN_BUSY_SAMPLES), + *_samples([300] * (MIN_BUSY_SAMPLES * 100), utilization=0), + ], + boot_id=BOOT_GOOD, + ) + self.assertEqual(record["sm_clock_mhz"]["n"], MIN_BUSY_SAMPLES) + reasons = clock_reasons(record, label="ours") + self.assertFalse(any("retained only" in reason for reason in reasons)) + self.assertTrue(any("was idle for" in reason for reason in reasons)) + + def test_the_busy_fraction_floor_is_inclusive(self) -> None: + busy = MIN_BUSY_SAMPLES * 2 + idle = int(busy * (1.0 - MIN_BUSY_FRACTION) / MIN_BUSY_FRACTION) + at_floor = build_clock_record( + [*_samples([2470] * busy), *_samples([300] * idle, utilization=0)], + boot_id=BOOT_GOOD, + ) + self.assertEqual(clock_reasons(at_floor, label="ours"), []) + below = build_clock_record( + [*_samples([2470] * busy), *_samples([300] * (idle + 1), utilization=0)], + boot_id=BOOT_GOOD, + ) + self.assertTrue(any("was idle for" in reason for reason in clock_reasons(below, label="ours"))) + + def test_a_malformed_record_becomes_a_reason_not_a_crash(self) -> None: + record = _record([2470]) + record.pop("boot_id") + reasons = clock_reasons(record, label="ours") + self.assertEqual(len(reasons), 1) + self.assertIn("boot_id", reasons[0]) + + def test_the_reason_names_its_arm(self) -> None: + reasons = clock_reasons(_record([1781, 2100, 2398]), label="vllm") + self.assertIn("vllm", reasons[0]) + + +class CrossArmTests(unittest.TestCase): + def test_same_boot_matched_clocks_compare(self) -> None: + comparison = compare_clock_records( + _record([2470, 2470, 2470]), _record([2470, 2470, 2470]) + ) + self.assertEqual(comparison["reasons"], []) + self.assertTrue(comparison["same_boot"]) + self.assertAlmostEqual(comparison["median_offset_pct"], 0.0) + self.assertAlmostEqual(comparison["estimated_effect_pct"], 0.0) + + def test_a_cross_boot_pair_is_refused(self) -> None: + comparison = compare_clock_records( + _record([2470] * 3, boot_id=BOOT_GOOD), + _record([2470] * 3, boot_id=BOOT_BAD), + ) + self.assertFalse(comparison["same_boot"]) + self.assertFalse(comparison["cross_boot_override"]) + self.assertTrue(any("boot" in reason for reason in comparison["reasons"])) + self.assertIn(BOOT_GOOD, comparison["ours_boot_id"]) + self.assertIn(BOOT_BAD, comparison["vllm_boot_id"]) + + def test_the_override_records_a_caveat_rather_than_silence(self) -> None: + comparison = compare_clock_records( + _record([2470] * 3, boot_id=BOOT_GOOD), + _record([2470] * 3, boot_id=BOOT_BAD), + allow_cross_boot=True, + ) + self.assertTrue(comparison["cross_boot_override"]) + self.assertFalse(comparison["same_boot"]) + self.assertEqual(comparison["reasons"], []) + self.assertTrue(any("boot" in note for note in comparison["caveats"])) + + def test_the_override_does_not_waive_state_only_identity(self) -> None: + comparison = compare_clock_records( + _record([2470] * 3, boot_id=BOOT_GOOD), + _record([2190] * 3, boot_id=BOOT_BAD), + allow_cross_boot=True, + ) + self.assertTrue(comparison["cross_boot_override"]) + self.assertTrue(any("offset" in reason for reason in comparison["reasons"])) + + def test_the_override_waives_the_boot_and_not_the_hardware(self) -> None: + """A GB10 against an H100 compared CLEAN under the override. + + Same-boot equality was the implicit proxy for "same machine". #545 makes + the override the normal path, so the proxy is gone and the identity has + to be asserted in its own right -- unconditionally, because no override + can make two different GPUs two arms of one comparison. + """ + + ours = _record([2470] * 3, boot_id=BOOT_GOOD) + theirs = _record([2470] * 3, boot_id=BOOT_BAD) + theirs["gpu_name"] = "NVIDIA H100 80GB HBM3" + theirs["driver_version"] = "550.54.15" + theirs["clocks_max_sm_mhz"] = 1980 + comparison = compare_clock_records(ours, theirs, allow_cross_boot=True) + self.assertTrue(comparison["cross_boot_override"]) + for field in ("gpu_name", "driver_version", "clocks_max_sm_mhz"): + with self.subTest(field=field): + self.assertTrue( + any(field in reason for reason in comparison["reasons"]), + comparison["reasons"], + ) + + def test_every_static_field_is_compared_across_the_arms(self) -> None: + for field, other in ( + ("gpu_name", "NVIDIA H100 80GB HBM3"), + ("driver_version", "550.54.15"), + ("clocks_max_sm_mhz", 1980), + ("clocks_applications_graphics_mhz", 1980), + ("persistence_mode", "Disabled"), + ): + for override in (False, True): + with self.subTest(field=field, allow_cross_boot=override): + theirs = _record([2470] * 3) + theirs[field] = other + comparison = compare_clock_records( + _record([2470] * 3), theirs, allow_cross_boot=override + ) + self.assertTrue( + any( + field in reason and "not two arms" in reason + for reason in comparison["reasons"] + ), + comparison["reasons"], + ) + + def test_matched_hardware_adds_no_reason(self) -> None: + comparison = compare_clock_records(_record([2470] * 3), _record([2470] * 3)) + self.assertEqual(comparison["reasons"], []) + + def test_the_observed_window_is_surfaced_next_to_the_ratio(self) -> None: + ours = build_clock_record( + [*_samples([2470] * 40), *_samples([300] * 5, utilization=0)], + boot_id=BOOT_GOOD, + ) + comparison = compare_clock_records(ours, _record([2470] * 3)) + self.assertEqual(comparison["ours_busy_samples"], 40) + self.assertEqual(comparison["ours_idle_samples_excluded"], 5) + self.assertEqual(comparison["vllm_busy_samples"], len(_window([2470] * 3))) + self.assertEqual(comparison["vllm_idle_samples_excluded"], 0) + + def test_the_measured_pair_is_refused_and_its_effect_reported(self) -> None: + # 2470 against 2190: the exact pair behind #543. + comparison = compare_clock_records( + _record([2470] * 3, boot_id=BOOT_GOOD), + _record([2190] * 3, boot_id=BOOT_BAD), + ) + self.assertAlmostEqual(comparison["median_offset_pct"], 12.7854, places=3) + self.assertAlmostEqual( + comparison["estimated_effect_pct"], 12.7854 * CLOCK_TIME_TRANSFER, places=3 + ) + # The marlin control actually moved +9.65%; the estimate must land on it. + self.assertAlmostEqual(comparison["estimated_effect_pct"], 9.65, places=1) + self.assertGreaterEqual(len(comparison["reasons"]), 2) + + def test_the_offset_threshold_is_inclusive(self) -> None: + inside = compare_clock_records(_record([2020] * 3), _record([2000] * 3)) + self.assertAlmostEqual(inside["median_offset_pct"], 1.0) + self.assertEqual(inside["reasons"], []) + outside = compare_clock_records(_record([2021] * 3), _record([2000] * 3)) + self.assertGreater(abs(outside["median_offset_pct"]), MAX_CROSS_ARM_OFFSET_PCT) + self.assertTrue(any("offset" in reason for reason in outside["reasons"])) + + def test_the_offset_is_signed_and_the_gate_is_not(self) -> None: + slower = compare_clock_records(_record([1900] * 3), _record([2000] * 3)) + self.assertLess(slower["median_offset_pct"], 0.0) + self.assertTrue(any("offset" in reason for reason in slower["reasons"])) + + def test_a_within_run_defect_on_either_arm_propagates(self) -> None: + comparison = compare_clock_records( + _record([1781, 2100, 2398], boot_id=BOOT_GOOD), + _record([2100] * 3, boot_id=BOOT_GOOD), + ) + self.assertTrue(any("spread" in reason for reason in comparison["reasons"])) + + def test_both_arms_spread_pct_are_surfaced_next_to_the_ratio(self) -> None: + comparison = compare_clock_records( + _record([2398, 2470, 2489]), _record([2470] * 3) + ) + self.assertAlmostEqual(comparison["ours_spread_pct"], 3.6842, places=3) + self.assertAlmostEqual(comparison["vllm_spread_pct"], 0.0) + self.assertEqual(comparison["ours_median_sm_mhz"], 2470.0) + self.assertEqual(comparison["vllm_median_sm_mhz"], 2470.0) + + +class MergeTests(unittest.TestCase): + def test_three_steady_legs_fold_into_one_arm(self) -> None: + merged = merge_clock_records([_record([2470] * 3) for _ in range(3)]) + self.assertEqual(merged["legs"], 3) + self.assertEqual(merged["sm_clock_mhz"]["n"], 3 * len(_window([2470] * 3))) + self.assertEqual(merged["sm_clock_mhz"]["median"], 2470.0) + self.assertAlmostEqual(merged["sm_clock_mhz"]["spread_pct"], 0.0) + self.assertEqual(clock_reasons(merged, label="ours"), []) + + def test_an_arm_may_not_straddle_two_boots(self) -> None: + with self.assertRaises(HarnessError) as caught: + merge_clock_records( + [_record([2470] * 3, boot_id=BOOT_GOOD), _record([2470] * 3, boot_id=BOOT_BAD)] + ) + self.assertIn("straddles two boots", str(caught.exception)) + + def test_legs_at_different_clocks_widen_the_merged_spread(self) -> None: + # Each leg is individually steady; the ARM is not. The within-run rule + # has to catch that, which is why the fold spans every leg. + merged = merge_clock_records([_record([2470] * 3), _record([2190] * 3)]) + self.assertGreater(merged["sm_clock_mhz"]["spread_pct"], MAX_WITHIN_RUN_SPREAD_PCT) + self.assertTrue(clock_reasons(merged, label="ours")) + + def test_merging_nothing_refuses(self) -> None: + with self.assertRaises(HarnessError): + merge_clock_records([]) + + def test_a_defective_leg_refuses_the_fold(self) -> None: + bad = _record([2470]) + bad.pop("persistence_mode") + with self.assertRaises(HarnessError) as caught: + merge_clock_records([_record([2470]), bad]) + self.assertIn("leg 2", str(caught.exception)) + + def test_idle_exclusions_are_summed_not_lost(self) -> None: + leg = build_clock_record( + [*_samples([2470, 2470]), *_samples([300], utilization=0)], boot_id=BOOT_GOOD + ) + merged = merge_clock_records([leg, leg]) + self.assertEqual(merged["idle_samples_excluded"], 2) + + +class SamplerTests(unittest.TestCase): + """The sampler is what the leg harness actually calls, so it is exercised. + + A stub stands in for `nvidia-smi`: the point is that a window of probes + becomes the two artifacts `online_gate_summary` reads, not that the driver + works. + """ + + def _stub(self, directory: pathlib.Path, body: str) -> pathlib.Path: + stub = directory / "nvidia-smi-stub" + stub.write_text(body, encoding="utf-8") + stub.chmod(0o755) + return stub + + def test_a_window_becomes_a_stream_and_a_record(self) -> None: + with tempfile.TemporaryDirectory() as raw: + directory = pathlib.Path(raw) + stub = self._stub( + directory, + "#!/bin/sh\necho '0, NVIDIA GB10, 580.159.03, 2470, 3003, 2418, " + "0x0000000000000000, Enabled, 97'\n", + ) + boot = directory / "boot_id" + boot.write_text(BOOT_GOOD + "\n", encoding="utf-8") + # Long enough to clear MIN_BUSY_SAMPLES with ~20x margin: the stub + # loop runs ~590 probes in this window on an idle box and would have + # to be 20 times slower to fall under the floor. The count is + # asserted directly below so a shortfall reads as a shortfall rather + # than as an unexplained clock reason. + record = run_sampler( + samples_output=directory / "r1.samples.jsonl", + summary_output=directory / "r1.summary.json", + interval_s=0.001, + max_duration_s=1.0, + smi=str(stub), + boot_id_path=boot, + ) + stream = [ + json.loads(line) + for line in (directory / "r1.samples.jsonl").read_text().splitlines() + if line.strip() + ] + self.assertGreaterEqual(record["sm_clock_mhz"]["n"], MIN_BUSY_SAMPLES) + self.assertGreaterEqual(len(stream), 1) + self.assertEqual(record["boot_id"], BOOT_GOOD) + self.assertEqual(record["sm_clock_mhz"]["median"], 2470.0) + self.assertEqual( + record["sm_clock_mhz"]["n"] + record["idle_samples_excluded"], + len(stream), + ) + on_disk = json.loads((directory / "r1.summary.json").read_text()) + self.assertEqual(on_disk, record) + self.assertEqual(clock_reasons(on_disk, label="ours"), []) + + def test_a_failed_probe_refuses_rather_than_recording_a_guess(self) -> None: + with tempfile.TemporaryDirectory() as raw: + directory = pathlib.Path(raw) + stub = self._stub(directory, "#!/bin/sh\nexit 3\n") + boot = directory / "boot_id" + boot.write_text(BOOT_GOOD + "\n", encoding="utf-8") + with self.assertRaises(HarnessError) as caught: + run_sampler( + samples_output=directory / "r1.samples.jsonl", + summary_output=directory / "r1.summary.json", + interval_s=0.01, + max_duration_s=0.05, + smi=str(stub), + boot_id_path=boot, + ) + self.assertIn("exited 3", str(caught.exception)) + self.assertFalse((directory / "r1.summary.json").exists()) + + def test_existing_evidence_is_never_overwritten(self) -> None: + with tempfile.TemporaryDirectory() as raw: + directory = pathlib.Path(raw) + stub = self._stub(directory, "#!/bin/sh\nexit 0\n") + (directory / "r1.summary.json").write_text("{}", encoding="utf-8") + with self.assertRaises(HarnessError) as caught: + run_sampler( + samples_output=directory / "r1.samples.jsonl", + summary_output=directory / "r1.summary.json", + smi=str(stub), + ) + self.assertIn("refusing to overwrite", str(caught.exception)) + + +class ThresholdProvenanceTests(unittest.TestCase): + """The thresholds are arguments from data, so the data is asserted here.""" + + def test_the_spread_threshold_accepts_the_clean_window_and_rejects_the_disagreement( + self, + ) -> None: + clean = summarize_sm_clocks([2398, 2470, 2489])["spread_pct"] + disagreement = summarize_sm_clocks([1781, 2398])["spread_pct"] + self.assertLess(clean, MAX_WITHIN_RUN_SPREAD_PCT) + self.assertGreater(disagreement, MAX_WITHIN_RUN_SPREAD_PCT) + + def test_the_offset_threshold_stays_under_the_smallest_ranked_deficit(self) -> None: + # in_proj +2.97% is the smallest deficit this harness has been used to + # rank. A pair inside the offset threshold may not be able to explain it. + self.assertLess(MAX_CROSS_ARM_OFFSET_PCT * CLOCK_TIME_TRANSFER, 2.97) + + def test_the_offset_threshold_holds_on_physics_not_on_n_equals_one(self) -> None: + """The threshold must not DEPEND on the n = 1 coefficient. + + For a kernel whose time scales with clock the transfer is bounded above + by 1.0 -- a 12.79% clock deficit can cost at most 12.79% of time. So the + 1.0% offset implies at most a 1.0% effect with no appeal to any + measurement, and still lands under the 2.97% smallest ranked deficit. + The measured coefficient is corroboration: it sits BELOW that ceiling, + exactly as a partly memory-bound kernel should. + """ + + self.assertLess(MAX_CROSS_ARM_OFFSET_PCT * 1.0, 2.97) + self.assertLess(CLOCK_TIME_TRANSFER, 1.0) + + def test_the_spread_ceiling_is_not_held_to_the_offsets_criterion(self) -> None: + """Stated, not hidden: at the ceiling a leg can carry a 3.77% artifact. + + The forward criterion the offset was chosen by would demand <=3.93% of + spread, which sits 0.25 points above the only clean window we have + (3.68%) and would void it on a noisier-but-healthy day. The residual is + recorded here so nobody re-derives it as a defect: passing spread + establishes that an arm was ONE state, not that a sub-4% deficit is + established. The offset rule is what qualifies the ratio. + """ + + self.assertGreater(MAX_WITHIN_RUN_SPREAD_PCT * CLOCK_TIME_TRANSFER, 2.97) + self.assertLess(summarize_sm_clocks([2398, 2470, 2489])["spread_pct"], 2.97 / CLOCK_TIME_TRANSFER) + + def test_the_transfer_coefficient_is_the_measured_one(self) -> None: + measured = (49.6544 / 45.2845 - 1.0) / (2470.0 / 2190.0 - 1.0) + self.assertAlmostEqual(CLOCK_TIME_TRANSFER, measured, places=3) + + def test_the_busy_floors_accept_the_two_real_windows(self) -> None: + """Both floors are bounded on the accepting side by real captures. + + #543's two windows are n=61 and n=50 busy samples; a floor above either + would void the only real data the row is built from, which is the same + both-sides bound the spread threshold was chosen under. + """ + + for observed in (61, 50): + with self.subTest(n=observed): + self.assertLessEqual(MIN_BUSY_SAMPLES, observed) + # And it is far above the degenerate window that scores a perfect 0.00%. + self.assertGreaterEqual(MIN_BUSY_SAMPLES, 30 * 1) + self.assertGreater(MIN_BUSY_FRACTION, 0.0) + self.assertLessEqual(MIN_BUSY_FRACTION, 1.0) + + +if __name__ == "__main__": + unittest.main() diff --git a/tests/tools/test_online_gate_summary.py b/tests/tools/test_online_gate_summary.py index dbd25c3d5..355f74dd3 100644 --- a/tests/tools/test_online_gate_summary.py +++ b/tests/tools/test_online_gate_summary.py @@ -28,9 +28,58 @@ VLLM_GENERATION_WINDOW_CONTRACTS, _fingerprint_tree, ) -from tools.bench.online_gate_summary import summarize_evidence +from tools.bench.gpu_clock_state import MIN_BUSY_SAMPLES, build_clock_record +from tools.bench.online_gate_summary import _report, summarize_evidence from tools.bench.serve_low_common import HarnessError, VLLM_COMMIT, sha256_file +# One boot id for the whole fixture grid: a clean four-leg capture is same-boot +# by construction, and every clock case below perturbs exactly one field of it. +FIXTURE_BOOT_ID = "f6bbbfc6-0000-4000-8000-000000000000" +OTHER_BOOT_ID = "2fca2b02-0000-4000-8000-000000000000" + + +def _clock_samples(values, *, utilization=97, throttle="0x0000000000000000"): + return [ + { + "clocks_applications_graphics_mhz": 2418, + "clocks_max_sm_mhz": 3003, + "driver_version": "580.159.03", + "gpu_name": "NVIDIA GB10", + "persistence_mode": "Enabled", + "sm_clock_mhz": value, + "throttle_reasons_active": throttle, + "utilization_gpu_pct": utilization, + } + for value in values + ] + + +def _clock_window(values): + """Repeat a clock pattern until it clears the sampler's coverage floor. + + Whole-list repetition leaves min, median, max and `spread_pct` untouched, so + every clock case below still asserts exactly what it asserted; only the + sample COUNT changes. The driver samples at 1 Hz across a bench loop of + minutes, so a three-sample leg was never a leg anyone could have captured. + """ + + values = list(values) + return values * -(-MIN_BUSY_SAMPLES // len(values)) + + +def _write_clock_leg(root, engine, repetition, values, *, boot_id=FIXTURE_BOOT_ID, **kwargs): + """Write one leg's clock evidence the way the sampler does.""" + + samples = _clock_samples(_clock_window(values), **kwargs) + base = root / "clocks" / "27" / engine + base.mkdir(parents=True, exist_ok=True) + (base / f"r{repetition}.samples.jsonl").write_text( + "".join(json.dumps(sample) + "\n" for sample in samples), encoding="utf-8" + ) + (base / f"r{repetition}.summary.json").write_text( + json.dumps(build_clock_record(samples, boot_id=boot_id)), encoding="utf-8" + ) + def _record(*, faster: bool, repetition: int) -> dict: requests = 2 @@ -362,6 +411,10 @@ def _write_fixture(root: pathlib.Path) -> None: encoding="utf-8", ) + # The clock the leg was measured at. Its absence is the #543 + # defect: a number nobody can attribute to a clock state. + _write_clock_leg(root, engine, repetition, [2470, 2470, 2470]) + thermal = root / "thermal" / "27" / engine thermal.mkdir(parents=True, exist_ok=True) for suffix in ("before", "after"): @@ -402,7 +455,7 @@ def setUp(self) -> None: window_patch.start() self.addCleanup(window_patch.stop) - def _summarize(self, root: pathlib.Path): + def _summarize(self, root: pathlib.Path, *, allow_cross_boot: bool = False): patches = ( mock.patch("tools.bench.online_gate.POINTS", ((1, 2),)), mock.patch("tools.bench.online_gate_summary.POINTS", ((1, 2),)), @@ -412,7 +465,7 @@ def _summarize(self, root: pathlib.Path): ), ) with patches[0], patches[1], patches[2]: - return summarize_evidence(root) + return summarize_evidence(root, allow_cross_boot=allow_cross_boot) def _summarize_model(self, root: pathlib.Path): with ( @@ -633,6 +686,324 @@ def test_hash_drifted_execution_artifact_cannot_pass(self) -> None: runs, _ = self._summarize(root) self.assertFalse(runs["gate_pass"]) + def test_every_ratio_carries_the_clock_it_was_measured_at(self) -> None: + """A ratio without its clock is not quotable (#543).""" + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + _, ratios = self._summarize(root) + self.assertTrue(ratios["ratios"]) + for ratio in ratios["ratios"]: + clock = ratio["clock"] + self.assertTrue(clock["same_boot"]) + self.assertEqual(clock["reasons"], []) + self.assertEqual(clock["ours_median_sm_mhz"], 2470.0) + self.assertEqual(clock["vllm_median_sm_mhz"], 2470.0) + self.assertAlmostEqual(clock["median_offset_pct"], 0.0) + self.assertAlmostEqual(clock["estimated_effect_pct"], 0.0) + + def test_a_missing_clock_record_cannot_pass(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + (root / "clocks" / "27" / "ours" / "r2.summary.json").unlink() + runs, ratios = self._summarize(root) + self.assertFalse(runs["gate_pass"]) + self.assertFalse(ratios["gate_pass"]) + self.assertTrue( + any( + "clock" in reason + for aggregate in runs["aggregates"] + for reason in aggregate["reasons"] + ) + ) + + def test_a_missing_clock_record_names_the_offending_arm_in_every_ratio(self) -> None: + """The leg reason already voids the gate; the READER still needs to know. + + Nothing else in the summary says WHICH arm lost its clock, so this is + the only site that can be gutted without any gate going green-to-red. + """ + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + (root / "clocks" / "27" / "vllm" / "r1.summary.json").unlink() + _, ratios = self._summarize(root) + self.assertTrue(ratios["ratios"]) + for ratio in ratios["ratios"]: + named = [ + reason + for reason in ratio["clock"]["reasons"] + if "no usable SM-clock record" in reason + ] + self.assertTrue(named, ratio["clock"]["reasons"]) + self.assertIn("vllm", named[0]) + self.assertNotIn("ours arm", named[0]) + + def test_a_cross_boot_pair_cannot_pass(self) -> None: + """The exact shape that produced the retracted #543 findings.""" + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + for repetition in (1, 2, 3): + _write_clock_leg( + root, + "vllm", + repetition, + [2470, 2470, 2470], + boot_id=OTHER_BOOT_ID, + ) + runs, ratios = self._summarize(root) + self.assertFalse(ratios["gate_pass"]) + self.assertFalse(runs["gate_pass"]) + offenders = [ + reason + for ratio in ratios["ratios"] + for reason in ratio["clock"]["reasons"] + if "DIFFERENT boots" in reason + ] + self.assertTrue(offenders) + self.assertIn(OTHER_BOOT_ID, offenders[0]) + # Each arm is internally clean here, so NOTHING at leg or arm level + # voids these ratios -- only the ratio's own clock term can. The two + # ratio families are asserted SEPARATELY because they carry that + # term at two different call sites, and a single gate_pass assertion + # lets either site mask the other's removal (the #520 lesson). + throughput = [ + ratio for ratio in ratios["ratios"] if ratio["concurrency"] is not None + ] + memory = [ + ratio for ratio in ratios["ratios"] if ratio["concurrency"] is None + ] + self.assertTrue(throughput) + self.assertTrue(memory) + self.assertFalse(any(ratio["binding_eligible"] for ratio in throughput)) + self.assertFalse(any(ratio["binding_eligible"] for ratio in memory)) + + def test_the_cross_boot_override_records_a_caveat_rather_than_silence(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + for repetition in (1, 2, 3): + _write_clock_leg( + root, + "vllm", + repetition, + [2470, 2470, 2470], + boot_id=OTHER_BOOT_ID, + ) + runs, ratios = self._summarize(root, allow_cross_boot=True) + self.assertTrue(runs["gate_pass"]) + self.assertTrue(ratios["gate_pass"]) + for ratio in ratios["ratios"]: + self.assertTrue(ratio["clock"]["cross_boot_override"]) + self.assertFalse(ratio["clock"]["same_boot"]) + self.assertTrue(ratio["clock"]["caveats"]) + + def test_the_override_does_not_waive_a_staircase_arm(self) -> None: + """Three individually-flat legs at three DIFFERENT clocks, one boot. + + This is the only check that lives ONLY at the compare site. + `_clock_for_leg` sees three steady legs and says nothing; + `merge_clock_records` folds them without complaint because they share a + boot and every static field; `_clock_for_arm` raises only on those two. + The merged spread -- (2470 - 2190) / 2300 = 12.17% -- is first evaluated + inside `compare_clock_records`, so rewriting that call's reason list to + `[] if allow_cross_boot else [...]` is invisible to every other case. + + The vLLM arm is pinned flat at the merged median so the CROSS-ARM OFFSET + stays 0.00%: the offset reason is appended outside that expression and + would otherwise mask the removal, which is how the two tests that name + this guarantee came to be dominated. + """ + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + for repetition, clock in zip((1, 2, 3), (2470, 2300, 2190)): + _write_clock_leg(root, "ours", repetition, [clock]) + for repetition in (1, 2, 3): + _write_clock_leg(root, "vllm", repetition, [2300], boot_id=OTHER_BOOT_ID) + runs, ratios = self._summarize(root, allow_cross_boot=True) + + # Nothing below the compare site objects: every leg is steady, the + # fold succeeds, and no aggregate carries a clock reason. Asserted so + # a future edit that moves the check earlier makes this case say so + # rather than passing for a new reason. + self.assertEqual(runs["campaign_reasons"], []) + self.assertEqual( + [ + reason + for aggregate in runs["aggregates"] + for reason in aggregate["reasons"] + if "clock" in reason + ], + [], + ) + clock = ratios["clocks"]["27"] + self.assertTrue(clock["cross_boot_override"]) + self.assertAlmostEqual(clock["median_offset_pct"], 0.0) + self.assertAlmostEqual(clock["ours_spread_pct"], 280.0 / 2300.0 * 100.0) + self.assertFalse( + any("offset" in reason for reason in clock["reasons"]), clock["reasons"] + ) + + self.assertFalse(ratios["gate_pass"]) + spread = [reason for reason in clock["reasons"] if "spread" in reason] + self.assertTrue(spread, clock["reasons"]) + self.assertIn("ours", spread[0]) + # The two ratio families carry the clock term at two different call + # sites, so they are asserted SEPARATELY (the #520 lesson). + throughput = [ + ratio for ratio in ratios["ratios"] if ratio["concurrency"] is not None + ] + memory = [ratio for ratio in ratios["ratios"] if ratio["concurrency"] is None] + self.assertTrue(throughput) + self.assertTrue(memory) + self.assertFalse(any(ratio["binding_eligible"] for ratio in throughput)) + self.assertFalse(any(ratio["binding_eligible"] for ratio in memory)) + + def test_a_diluted_window_cannot_pass_and_says_so_in_the_report(self) -> None: + """One busy sample among three hundred scored a perfect +0.00%. + + The record every leg wrote already counted the exclusions; nothing + asserted them, folded them into the ratio's clock block, or printed + them, so the window the sampler barely observed outscored the one it + watched. + """ + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + for engine in ("ours", "vllm"): + for repetition in (1, 2, 3): + base = root / "clocks" / "27" / engine + samples = _clock_samples([2470]) + _clock_samples( + [300] * 300, utilization=0 + ) + (base / f"r{repetition}.samples.jsonl").write_text( + "".join(json.dumps(sample) + "\n" for sample in samples), + encoding="utf-8", + ) + (base / f"r{repetition}.summary.json").write_text( + json.dumps(build_clock_record(samples, boot_id=FIXTURE_BOOT_ID)), + encoding="utf-8", + ) + runs, ratios = self._summarize(root) + clock = ratios["clocks"]["27"] + self.assertEqual(clock["ours_busy_samples"], 3) + self.assertEqual(clock["ours_idle_samples_excluded"], 900) + self.assertAlmostEqual(clock["ours_spread_pct"], 0.0) + self.assertFalse(runs["gate_pass"]) + self.assertFalse(ratios["gate_pass"]) + report = _report(runs, ratios) + self.assertIn("3 busy / 900 idle", report) + + def test_the_override_does_not_waive_an_over_spread_window(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + _write_clock_leg( + root, "ours", 1, [1781, 2100, 2398], boot_id=OTHER_BOOT_ID + ) + runs, _ = self._summarize(root, allow_cross_boot=True) + self.assertFalse(runs["gate_pass"]) + + def test_an_over_spread_window_cannot_pass(self) -> None: + """Two probes eight minutes apart inside ONE boot: 2398 against 1781.""" + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + _write_clock_leg(root, "ours", 3, [1781, 2100, 2398]) + runs, ratios = self._summarize(root) + self.assertFalse(runs["gate_pass"]) + self.assertFalse(ratios["gate_pass"]) + self.assertTrue( + any( + "spread" in reason + for aggregate in runs["aggregates"] + for reason in aggregate["reasons"] + ) + ) + + def test_a_cross_arm_clock_offset_cannot_pass_even_same_boot(self) -> None: + """The measured pair: 2470 against 2190, one boot apart in reality.""" + + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + for repetition in (1, 2, 3): + _write_clock_leg(root, "vllm", repetition, [2190, 2190, 2190]) + runs, ratios = self._summarize(root) + self.assertFalse(ratios["gate_pass"]) + self.assertFalse(runs["gate_pass"]) + clock = ratios["ratios"][0]["clock"] + self.assertTrue(clock["same_boot"]) + self.assertAlmostEqual(clock["median_offset_pct"], 12.7854, places=3) + self.assertAlmostEqual(clock["estimated_effect_pct"], 9.65, places=1) + self.assertTrue(any("offset" in reason for reason in clock["reasons"])) + + def test_a_throttled_window_cannot_pass(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + _write_clock_leg( + root, "ours", 2, [2470, 2470], throttle="0x0000000000000040" + ) + runs, _ = self._summarize(root) + self.assertFalse(runs["gate_pass"]) + self.assertTrue( + any( + "throttl" in reason + for aggregate in runs["aggregates"] + for reason in aggregate["reasons"] + ) + ) + + def test_a_clock_summary_that_disagrees_with_its_stream_cannot_pass(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + path = root / "clocks" / "27" / "ours" / "r1.summary.json" + record = json.loads(path.read_text(encoding="utf-8")) + record["sm_clock_mhz"]["n"] = 99 + path.write_text(json.dumps(record), encoding="utf-8") + runs, _ = self._summarize(root) + self.assertFalse(runs["gate_pass"]) + + def test_one_arm_may_not_straddle_two_boots(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + _write_clock_leg( + root, "ours", 2, [2470, 2470, 2470], boot_id=OTHER_BOOT_ID + ) + runs, _ = self._summarize(root) + self.assertFalse(runs["gate_pass"]) + self.assertTrue( + any( + "boot" in reason + for aggregate in runs["aggregates"] + for reason in aggregate["reasons"] + ) + ) + + def test_the_report_prints_the_clock_next_to_the_verdict(self) -> None: + with tempfile.TemporaryDirectory() as temporary: + root = pathlib.Path(temporary) + _write_fixture(root) + for repetition in (1, 2, 3): + _write_clock_leg(root, "vllm", repetition, [2190, 2190, 2190]) + runs, ratios = self._summarize(root) + report = _report(runs, ratios) + self.assertIn("SM clock", report) + self.assertIn("2470", report) + self.assertIn("2190", report) + def test_hash_drifted_corpus_cannot_pass(self) -> None: with tempfile.TemporaryDirectory() as temporary: root = pathlib.Path(temporary) diff --git a/tools/bench/gpu_clock_state.py b/tools/bench/gpu_clock_state.py new file mode 100644 index 000000000..c88ca348d --- /dev/null +++ b/tools/bench/gpu_clock_state.py @@ -0,0 +1,787 @@ +#!/usr/bin/env python3 +"""Record and assert the GPU clock a measurement was actually taken at (#543). + +On `dgx.casa` (GB10, driver 580.159.03) the SM clock differs **between boots** +and is not throttling — `clocks_throttle_reasons.active = 0x0`, persistence +`Enabled`: + + boot f6bbbfc6 n=61, min 2398 / med 2470 / max 2489 82.1664 ms/step + boot 2fca2b02 n=50, flat 2190 (max 3003, apps 2418) 88.1000 ms/step + +A 12.79% median-clock delta produced +7.22% step time, and the control settles +it: `marlin::Marlin`, 129 calls/step, byte-identical invocation and **no source +change**, moved 45.2845 -> 49.6544 ms/step = **+9.65%**. That drift is larger +than either deficit it was used to rank (`in_proj` +2.97%, `out_proj` +6.28%), +so both are NOT ESTABLISHED. + +Nothing in the tree recorded any of it. This module is the one place that +samples the state, writes it down, and refuses a comparison that cannot be +attributed to it — the same shape as the oracle-identity pin (#520), for the +same reason: an environment variable nobody recorded silently reprices every +number. + +Standard library only, like `serve_low_common`, so every assertion here runs in +CPU CI with no GPU and no `nvidia-smi`. Sampling needs the binary; the logic +does not. +""" + +from __future__ import annotations + +import argparse +import datetime as dt +import math +import pathlib +import signal +import statistics +import subprocess +import sys +import time +from collections.abc import Iterable, Mapping, Sequence +from types import FrameType +from typing import Any + +from tools.bench.serve_low_common import HarnessError, canonical_json, write_json_atomic + +BOOT_ID_PATH = pathlib.Path("/proc/sys/kernel/random/boot_id") +NVIDIA_SMI = "nvidia-smi" + +# The query is ordered, and `parse_query_row` is positional against it: a driver +# that reorders or drops a column produces a length mismatch, which is a +# refusal, rather than a value silently read from the wrong position. +QUERY_FIELDS: tuple[tuple[str, str], ...] = ( + ("index", "index"), + ("name", "gpu_name"), + ("driver_version", "driver_version"), + ("clocks.sm", "sm_clock_mhz"), + ("clocks.max.sm", "clocks_max_sm_mhz"), + ("clocks.applications.graphics", "clocks_applications_graphics_mhz"), + # Driver 580 accepts the `throttle` spelling; newer drivers prefer + # `clocks_event_reasons.active`. A failed query is a refusal to sample, so a + # rename surfaces as a loud stop rather than as an absent field. + ("clocks_throttle_reasons.active", "throttle_reasons_active"), + ("persistence_mode", "persistence_mode"), + ("utilization.gpu", "utilization_gpu_pct"), +) +_INTEGER_FIELDS = frozenset( + { + "index", + "sm_clock_mhz", + "clocks_max_sm_mhz", + "clocks_applications_graphics_mhz", + "utilization_gpu_pct", + } +) +# Held constant for the whole window; a mid-window change means the sampler +# watched two different GPUs or the applications clock moved under it. +STATIC_FIELDS: tuple[str, ...] = ( + "gpu_name", + "driver_version", + "clocks_max_sm_mhz", + "clocks_applications_graphics_mhz", + "persistence_mode", +) + +# --- Thresholds. All four are arguments from the data above, not preferences. - +# +# Within-run spread, 5.0%. The admissible band is bounded on both sides: it must +# ACCEPT the only clean window we have, (2489-2398)/2470 = 3.68%, because a +# threshold that voids our one good measurement is useless; and it must REJECT +# the two probes eight minutes apart inside ONE boot, 2398 against 1781, which +# is ~26% however it is normalized. 5.0 clears the clean observation by ~1.3 +# points so a marginally noisier but healthy window is not spuriously voided, +# and sits roughly five times below the failure it exists to catch. +# +# It is deliberately NOT held to the forward criterion the offset below is held +# to. 5.0 x the transfer is 3.77%, above the 2.97% smallest deficit ranked, so a +# leg sitting AT the spread ceiling can carry an artifact larger than that +# deficit. The two rules defend different things and the difference is the +# reason. The offset bounds a SYSTEMATIC difference between the arms -- one arm +# ran at one clock and the other at another, and the whole of it transfers into +# the ratio -- so it must sit under the smallest effect anyone ranks. Spread +# bounds DISPERSION inside one arm's window, which does not transfer that way: +# both arms sweep the same six concurrency points on the same box, so most of +# the dispersion is common, and what survives into the ratio is the difference +# of two medians, which MAX_CROSS_ARM_OFFSET_PCT already bounds at 1.0%. The +# spread rule's job is to detect that a window was not ONE state at all (the 26% +# within-boot disagreement), not to bound a transferable bias. Tightening it to +# satisfy the forward criterion would mean <=3.93%, which sits 0.25 points above +# our only clean capture and would void it on any noisier-but-healthy day -- the +# exact failure the both-sides bound was chosen to avoid. The residual is stated +# rather than hidden: passing spread establishes that each arm was one state, it +# does NOT by itself establish a sub-4% deficit. The offset rule is what +# qualifies the ratio. +MAX_WITHIN_RUN_SPREAD_PCT = 5.0 +# +# Cross-arm median offset, 1.0%. For any kernel whose time scales with clock the +# transfer is bounded above by 1.0 -- a 12.79% clock deficit can cost at most +# 12.79% of time -- so a 1.0% offset implies AT MOST a 1.0% effect on physics, +# with no appeal to any measurement. That is already under the 2.97% smallest +# deficit this harness has been used to rank, so a pair inside the threshold +# cannot have had its ranking inverted by clocks. The measured 0.7548 below is +# consistent with that ceiling and sits under it exactly as a partly +# memory-bound kernel should, which is corroboration, not the argument. +MAX_CROSS_ARM_OFFSET_PCT = 1.0 +# +# Retained busy samples per window, 30. `spread_pct` over n == 1 is definitionally +# 0.00% -- the BEST score the gate can award -- so without a floor the window the +# sampler barely observed outscores the one it actually watched. Bounded on both +# sides like the spread rule. It must ACCEPT the real windows: the only two +# #543 captured are n=61 and n=50, and 30 sits 40% below the smaller. It must +# REJECT the degenerate window, and 30 is 30x above n == 1. And it reads +# straight off the sampler and the grid rather than off what happens to pass: at +# the driver's `--interval 1` a busy sample is a second of OBSERVED BUSY GPU, +# while the smallest configured leg (online_gate.POINTS_BY_MODEL's four-point +# set: 6+6+12+24 prompts at 128 output tokens = 1920 sequential decode steps) +# would have to average under ~16 ms/step INCLUDING its 48 prefills of 1024 +# tokens to finish in 30 busy seconds. #543's own table for this box is 82-88 +# ms/step. A leg below this floor is not a fast leg; it is an unobserved one. +MIN_BUSY_SAMPLES = 30 +# +# Busy fraction of the window, 0.5. The count floor alone does not catch +# dilution: 30 busy among 3000 idle still clears it, and the reported spread +# still describes 1% of the window. The sampler covers the BENCH LOOP only -- it +# starts after the preflight stream and stops before the after-thermal snapshot +# -- so the non-busy time inside it is the client startup between six +# `online_gate.py bench` invocations, not model load, not cache drops, not +# server start, while the GPU serves 336 requests of 1024-in/128-out across the +# span. Requiring the MAJORITY of the window to be busy is the weakest form of +# the claim the record makes, namely that it describes the measured work. It is +# also the field that betrays a sampler which outlived its leg: an orphan accrues +# idle samples without bound and nothing else in the record notices. +MIN_BUSY_FRACTION = 0.5 +# +# Percentage points of kernel time per percentage point of clock, from the one +# cross-boot pair we have: +9.65% marlin over a 12.79% clock offset. The +# step-level transfer was lower (0.565); the larger is used. THIS IS n = 1. It is +# not a gate TERM -- no gate expression evaluates it, which the mutation set +# proves -- but it was a gate PREMISE, because MAX_CROSS_ARM_OFFSET_PCT was +# chosen by multiplying through it. The physics bound above retires it from that +# role: the threshold now holds at the transfer's theoretical ceiling of 1.0, so +# the coefficient only ever REPORTS an estimated effect. +CLOCK_TIME_TRANSFER = (49.6544 / 45.2845 - 1.0) / (2470.0 / 2190.0 - 1.0) + +# GpuIdle | ApplicationsClocksSetting | DisplayClockSetting. These say something +# about configuration or occupancy, not about the GPU being held back while it +# worked. Every other bit -- power cap, hardware slowdown, sync boost, thermal, +# power brake -- means the window is not the window the number claims. +BENIGN_THROTTLE_MASK = 0x1 | 0x2 | 0x100 +THROTTLE_BIT_NAMES: dict[int, str] = { + 0x1: "GpuIdle", + 0x2: "ApplicationsClocksSetting", + 0x4: "SwPowerCap", + 0x8: "HwSlowdown", + 0x10: "SyncBoost", + 0x20: "SwThermalSlowdown", + 0x40: "HwThermalSlowdown", + 0x80: "HwPowerBrakeSlowdown", + 0x100: "DisplayClockSetting", +} + +_REQUIRED_RECORD_FIELDS: tuple[str, ...] = ( + "boot_id", + "clocks_applications_graphics_mhz", + "clocks_max_sm_mhz", + "driver_version", + "gpu_name", + "idle_samples_excluded", + "persistence_mode", + "sm_clock_mhz", + "throttle_reasons_active", +) +_REQUIRED_SUMMARY_FIELDS: tuple[str, ...] = ("n", "min", "median", "max", "spread_pct") + +# Both thresholds are INCLUSIVE, and a ratio of two integer clocks lands on them +# only to within double rounding (2020/2000 - 1 == 0.010000000000000009). The +# tolerance is a floating-point artifact allowance, not slack in the rule: it is +# nine orders of magnitude below the smallest effect either threshold defends. +_THRESHOLD_EPSILON = 1e-9 + + +def read_boot_id(path: pathlib.Path = BOOT_ID_PATH) -> str: + """Return the running kernel's boot id, or refuse. + + This is the only field that can tell two measurements apart when everything + else -- binary, argv, model, driver -- is identical, which is exactly the + #543 shape. An absent or empty value is a refusal, never a default: a + default would make every cross-boot pair look same-boot. + """ + + try: + text = path.read_text(encoding="utf-8") + except OSError as error: + raise HarnessError(f"boot id is unreadable: {path}: {error}") from error + value = text.strip() + if not value: + raise HarnessError(f"boot id is empty: {path}") + return value + + +def _parse_scalar(raw: str, query_name: str, field: str) -> Any: + value = raw.strip() + if not value or value.upper() in {"N/A", "[N/A]", "NA", "[NOT SUPPORTED]"}: + raise HarnessError(f"{query_name} is unavailable: {raw!r}") + if field in _INTEGER_FIELDS: + # `--format=csv` appends a unit ("2190 MHz", "97 %"); `nounits` does + # not. Both are accepted so a fixture captured either way parses. + token = value.split()[0] + try: + return int(token) + except ValueError as error: + raise HarnessError(f"{query_name} is not an integer: {raw!r}") from error + return value + + +def parse_query_row(row: str) -> dict[str, Any]: + """Parse one `nvidia-smi --query-gpu` CSV row into a sample.""" + + cells = row.split(",") + if len(cells) != len(QUERY_FIELDS): + raise HarnessError( + f"nvidia-smi row expected {len(QUERY_FIELDS)} columns, got {len(cells)}: {row!r}" + ) + sample: dict[str, Any] = {} + for (query_name, field), cell in zip(QUERY_FIELDS, cells): + sample[field] = _parse_scalar(cell, query_name, field) + sample["throttle_reasons_active"] = _normalize_throttle( + sample["throttle_reasons_active"] + ) + return sample + + +def _normalize_throttle(value: object) -> str: + text = str(value).strip().lower() + try: + bits = int(text, 16) + except ValueError as error: + raise HarnessError( + f"clocks_throttle_reasons.active is not hexadecimal: {value!r}" + ) from error + if bits < 0: + raise HarnessError(f"clocks_throttle_reasons.active is negative: {value!r}") + return f"0x{bits:016x}" + + +def query_once(*, smi: str = NVIDIA_SMI, timeout_s: float = 10.0) -> dict[str, Any]: + """Sample the GPU once. A failed probe refuses; it never returns a guess.""" + + argv = [ + smi, + "--query-gpu=" + ",".join(name for name, _ in QUERY_FIELDS), + "--format=csv,noheader,nounits", + ] + try: + result = subprocess.run( + argv, check=False, capture_output=True, text=True, timeout=timeout_s + ) + except (OSError, subprocess.TimeoutExpired) as error: + raise HarnessError(f"nvidia-smi clock probe failed: {error}") from error + if result.returncode != 0: + raise HarnessError( + f"nvidia-smi clock probe exited {result.returncode}: {result.stderr.strip()!r}" + ) + rows = [line for line in result.stdout.splitlines() if line.strip()] + if not rows: + raise HarnessError("nvidia-smi clock probe returned no rows") + if len(rows) > 1: + # More than one GPU is a real configuration, but this harness records + # ONE clock per leg and would have to pick. Refuse rather than pick. + raise HarnessError( + f"nvidia-smi clock probe returned {len(rows)} GPUs; this harness records one" + ) + return parse_query_row(rows[0]) + + +def summarize_sm_clocks(values: Sequence[float]) -> dict[str, float]: + """Return `{n, min, median, max, spread_pct}` over the measured window.""" + + if not values: + raise HarnessError("cannot summarize an empty SM-clock window") + numbers = [float(value) for value in values] + for number in numbers: + if not math.isfinite(number) or number <= 0.0: + raise HarnessError(f"SM clock must be finite and positive, got {number!r}") + median = statistics.median(numbers) + return { + "max": max(numbers), + "median": median, + "min": min(numbers), + "n": len(numbers), + "spread_pct": (max(numbers) - min(numbers)) / median * 100.0, + } + + +def build_clock_record( + samples: Sequence[Mapping[str, Any]], *, boot_id: str +) -> dict[str, Any]: + """Reduce a window of samples to the per-leg record. + + Idle samples are EXCLUDED from the statistics and COUNTED, not dropped: a + clock read while the GPU is doing nothing did not price any work, and the + timed window necessarily contains the harness's own gaps between + concurrency points. Excluding them silently would be a lie; a window that is + entirely idle has nothing to summarize and is refused. + """ + + if not samples: + raise HarnessError("cannot build a clock record from an empty window") + if not str(boot_id).strip(): + raise HarnessError("clock record requires a boot id") + first = samples[0] + for field in STATIC_FIELDS: + if field not in first: + raise HarnessError(f"clock sample omits {field}") + for sample in samples[1:]: + if sample.get(field) != first[field]: + raise HarnessError( + f"{field} changed mid-window: {first[field]!r} -> {sample.get(field)!r}" + ) + busy: list[float] = [] + idle = 0 + throttle: set[str] = set() + for sample in samples: + if "sm_clock_mhz" not in sample: + raise HarnessError("clock sample omits sm_clock_mhz") + throttle.add(_normalize_throttle(sample.get("throttle_reasons_active", "0x0"))) + utilization = sample.get("utilization_gpu_pct") + if utilization is None: + raise HarnessError("clock sample omits utilization_gpu_pct") + if float(utilization) <= 0.0: + idle += 1 + continue + busy.append(float(sample["sm_clock_mhz"])) + if not busy: + raise HarnessError( + f"every one of {len(samples)} clock samples was idle; " + "there is no window to attribute the measurement to" + ) + return { + "boot_id": str(boot_id).strip(), + "clocks_applications_graphics_mhz": first["clocks_applications_graphics_mhz"], + "clocks_max_sm_mhz": first["clocks_max_sm_mhz"], + "driver_version": first["driver_version"], + "gpu_name": first["gpu_name"], + "idle_samples_excluded": idle, + "persistence_mode": first["persistence_mode"], + "sm_clock_mhz": summarize_sm_clocks(busy), + "throttle_reasons_active": sorted(throttle), + } + + +def merge_clock_records(records: Sequence[Mapping[str, Any]]) -> dict[str, Any]: + """Fold one arm's repeated legs into the arm's clock record. + + A ratio is taken between two ARMS, not two legs, so the clock the ratio was + measured at is the arm's. Folding refuses what it cannot fold: repetitions + that straddle two boots, or that saw different hardware or a different + applications clock, are not one arm's measurement and merging them would + manufacture a window that never existed. + + The merged spread spans every leg. That is deliberate -- an arm whose three + repetitions individually looked steady but sat at different clocks is + exactly the case the within-run rule must still catch. + """ + + if not records: + raise HarnessError("cannot merge an empty set of clock records") + for index, record in enumerate(records): + validate_clock_record(record, label=f"leg {index + 1}") + first = records[0] + for index, record in enumerate(records[1:], start=2): + if record["boot_id"] != first["boot_id"]: + raise HarnessError( + "arm straddles two boots: leg 1 ran on " + f"{first['boot_id']} and leg {index} on {record['boot_id']}; " + "these are not one measurement" + ) + for field in STATIC_FIELDS: + if record.get(field) != first.get(field): + raise HarnessError( + f"{field} differs between legs: " + f"{first.get(field)!r} vs {record.get(field)!r}" + ) + medians = [float(record["sm_clock_mhz"]["median"]) for record in records] + lowest = min(float(record["sm_clock_mhz"]["min"]) for record in records) + highest = max(float(record["sm_clock_mhz"]["max"]) for record in records) + median = statistics.median(medians) + throttle: set[str] = set() + for record in records: + throttle.update(_normalize_throttle(value) for value in record["throttle_reasons_active"]) + return { + "boot_id": first["boot_id"], + "clocks_applications_graphics_mhz": first["clocks_applications_graphics_mhz"], + "clocks_max_sm_mhz": first["clocks_max_sm_mhz"], + "driver_version": first["driver_version"], + "gpu_name": first["gpu_name"], + "idle_samples_excluded": sum( + int(record["idle_samples_excluded"]) for record in records + ), + "legs": len(records), + "persistence_mode": first["persistence_mode"], + "sm_clock_mhz": { + "max": highest, + "median": median, + "min": lowest, + "n": sum(int(record["sm_clock_mhz"]["n"]) for record in records), + "spread_pct": (highest - lowest) / median * 100.0, + }, + "throttle_reasons_active": sorted(throttle), + } + + +def validate_clock_record(record: Mapping[str, Any], *, label: str) -> None: + """Fail closed on every defect a clock record can carry.""" + + if not isinstance(record, Mapping): + raise HarnessError(f"{label} clock record is not an object") + for field in _REQUIRED_RECORD_FIELDS: + if field not in record: + raise HarnessError(f"{label} clock record omits {field}") + if not str(record["boot_id"]).strip(): + raise HarnessError(f"{label} clock record has an empty boot_id") + summary = record["sm_clock_mhz"] + if not isinstance(summary, Mapping): + raise HarnessError(f"{label} clock record sm_clock_mhz is not an object") + for field in _REQUIRED_SUMMARY_FIELDS: + if field not in summary: + raise HarnessError(f"{label} clock record sm_clock_mhz omits {field}") + for field in ("min", "median", "max"): + value = summary[field] + if isinstance(value, bool) or not isinstance(value, (int, float)): + raise HarnessError(f"{label} clock record sm_clock_mhz.{field} is not numeric") + if not math.isfinite(float(value)): + raise HarnessError(f"{label} clock record sm_clock_mhz.{field} is not finite") + if float(value) <= 0.0: + raise HarnessError( + f"{label} clock record sm_clock_mhz.{field} must be positive, got {value!r}" + ) + if not isinstance(summary["n"], int) or isinstance(summary["n"], bool) or summary["n"] < 1: + raise HarnessError(f"{label} clock record sm_clock_mhz.n must be a positive count") + idle = record["idle_samples_excluded"] + if not isinstance(idle, int) or isinstance(idle, bool) or idle < 0: + raise HarnessError( + f"{label} clock record idle_samples_excluded must be a non-negative count" + ) + if float(summary["min"]) > float(summary["max"]): + raise HarnessError(f"{label} clock record sm_clock_mhz min exceeds max") + reasons = record["throttle_reasons_active"] + if not isinstance(reasons, (list, tuple)) or not reasons: + raise HarnessError(f"{label} clock record throttle_reasons_active is empty") + for value in reasons: + _normalize_throttle(value) + + +def _throttle_offenders(values: Iterable[str]) -> list[str]: + offenders: list[str] = [] + for value in values: + bits = int(_normalize_throttle(value), 16) & ~BENIGN_THROTTLE_MASK + if not bits: + continue + names = [ + name for bit, name in sorted(THROTTLE_BIT_NAMES.items()) if bits & bit + ] or [f"0x{bits:x}"] + offenders.extend(names) + return sorted(set(offenders)) + + +def clock_reasons(record: Mapping[str, Any], *, label: str) -> list[str]: + """Return the reasons this arm's clock state does not establish a number. + + An empty list means established. Every entry names its arm, so a reader of + the summary can tell which side voided the ratio without opening evidence. + """ + + try: + validate_clock_record(record, label=label) + except HarnessError as error: + return [f"clock: {error}"] + reasons: list[str] = [] + # The coverage floors come FIRST because they qualify everything below them: + # a spread computed over one retained sample is 0.00% and says nothing, and + # a median computed over 1% of the window describes 1% of the window. + busy = int(record["sm_clock_mhz"]["n"]) + idle = int(record["idle_samples_excluded"]) + if busy < MIN_BUSY_SAMPLES: + reasons.append( + f"clock: {label} retained only {busy} busy SM-clock sample(s) over the " + f"measured window, below the {MIN_BUSY_SAMPLES} floor; a window this " + "short cannot establish a spread (over n == 1 the spread is " + "definitionally 0.00%, the best score the gate awards)" + ) + observed = busy + idle + busy_fraction = busy / observed if observed else 0.0 + if busy_fraction < MIN_BUSY_FRACTION: + reasons.append( + f"clock: {label} was idle for {idle} of {observed} SM-clock samples " + f"({busy_fraction * 100.0:.2f}% busy, below the " + f"{MIN_BUSY_FRACTION * 100.0:.0f}% floor); the retained window does not " + "describe the measured work" + ) + spread = float(record["sm_clock_mhz"]["spread_pct"]) + if spread > MAX_WITHIN_RUN_SPREAD_PCT + _THRESHOLD_EPSILON: + reasons.append( + f"clock: {label} SM-clock spread over the measured window is " + f"{spread:.2f}%, above the {MAX_WITHIN_RUN_SPREAD_PCT}% ceiling; " + "the number is NOT ESTABLISHED" + ) + offenders = _throttle_offenders(record["throttle_reasons_active"]) + if offenders: + reasons.append( + f"clock: {label} was throttled during the measured window " + f"({', '.join(offenders)}); the number is NOT ESTABLISHED" + ) + if str(record["persistence_mode"]) != "Enabled": + reasons.append( + f"clock: {label} ran with persistence mode " + f"{record['persistence_mode']!r}, not Enabled" + ) + return reasons + + +def compare_clock_records( + ours: Mapping[str, Any], + theirs: Mapping[str, Any], + *, + ours_label: str = "ours", + theirs_label: str = "vllm", + allow_cross_boot: bool = False, +) -> dict[str, Any]: + """Compare two arms' clock state and size the clock against the effect. + + The returned block is meant to sit NEXT TO the ratio it qualifies: both + medians, both spreads, the signed offset, and the estimated share of the + ratio the clock alone explains. + + `allow_cross_boot` waives ONE FIELD, `boot_id`, and nothing else. It exists + because #545 makes same-boot capture of a four-leg chain unreliable and a + gate nobody can satisfy is a gate everybody routes around; it converts that + one refusal into a recorded caveat, and every other rule still applies. + + Because #545 makes the override the NORMAL path, the hardware the two arms + ran on is asserted here explicitly rather than left to same-boot equality as + an implicit proxy. Without that, waiving the boot silently waived "same + machine" too: a GB10 at 3003 MHz max against an H100 at 1980 compared clean, + with a caveat that said only "different boots". + """ + + reasons = [ + *clock_reasons(ours, label=ours_label), + *clock_reasons(theirs, label=theirs_label), + ] + # STATIC_FIELDS is enforced within a window (`build_clock_record`) and + # between one arm's legs (`merge_clock_records`); this is the third edge, and + # the only one the override can reach. It is UNCONDITIONAL: two arms that + # disagree on the GPU, the driver, the maximum SM clock, the applications + # clock, or persistence mode are not two arms of one comparison, and no + # override makes them so. + for field in STATIC_FIELDS: + ours_value = ours.get(field) + theirs_value = theirs.get(field) + if ours_value != theirs_value: + reasons.append( + f"clock: {ours_label} and {theirs_label} report a different {field} " + f"({ours_value!r} vs {theirs_value!r}); these are not two arms of " + "one comparison" + ) + caveats: list[str] = [] + ours_boot = str(ours.get("boot_id", "")) + theirs_boot = str(theirs.get("boot_id", "")) + same_boot = bool(ours_boot) and ours_boot == theirs_boot + cross_boot_override = bool(allow_cross_boot) and not same_boot + if not same_boot: + message = ( + f"clock: {ours_label} and {theirs_label} ran on DIFFERENT boots " + f"({ours_boot or ''} vs {theirs_boot or ''}); " + "cross-boot comparison is what produced the retracted #543 findings" + ) + (caveats if cross_boot_override else reasons).append( + message + " -- ACCEPTED under an explicit override" if cross_boot_override + else message + ) + + ours_median = _median_or_none(ours) + theirs_median = _median_or_none(theirs) + offset_pct: float | None = None + effect_pct: float | None = None + if ours_median is not None and theirs_median is not None and theirs_median > 0.0: + offset_pct = (ours_median / theirs_median - 1.0) * 100.0 + effect_pct = offset_pct * CLOCK_TIME_TRANSFER + if abs(offset_pct) > MAX_CROSS_ARM_OFFSET_PCT + _THRESHOLD_EPSILON: + reasons.append( + f"clock: {ours_label} and {theirs_label} median SM-clock offset is " + f"{offset_pct:+.2f}% (>{MAX_CROSS_ARM_OFFSET_PCT}%), estimated to move " + f"kernel time by {effect_pct:+.2f}%; the ratio is NOT ESTABLISHED" + ) + return { + "allow_cross_boot": bool(allow_cross_boot), + "caveats": caveats, + "cross_boot_override": cross_boot_override, + "estimated_effect_pct": effect_pct, + "estimated_effect_basis": ( + f"{CLOCK_TIME_TRANSFER:.4f} points of kernel time per point of clock, " + "measured ONCE (marlin::Marlin 45.2845 -> 49.6544 ms/step over a " + "12.79% clock offset, #543); reported, never gated on" + ), + "median_offset_pct": offset_pct, + f"{ours_label}_boot_id": ours_boot, + # How much of the window each side actually observed. Without these two + # pairs a reader cannot tell a window the sampler watched from one it + # barely touched, and the latter scores a perfect 0.00% spread. + f"{ours_label}_busy_samples": _busy_or_none(ours), + f"{ours_label}_idle_samples_excluded": _idle_or_none(ours), + f"{ours_label}_median_sm_mhz": ours_median, + f"{ours_label}_spread_pct": _spread_or_none(ours), + "reasons": reasons, + "same_boot": same_boot, + f"{theirs_label}_boot_id": theirs_boot, + f"{theirs_label}_busy_samples": _busy_or_none(theirs), + f"{theirs_label}_idle_samples_excluded": _idle_or_none(theirs), + f"{theirs_label}_median_sm_mhz": theirs_median, + f"{theirs_label}_spread_pct": _spread_or_none(theirs), + } + + +def _summary_field(record: Mapping[str, Any], field: str) -> float | None: + summary = record.get("sm_clock_mhz") + if not isinstance(summary, Mapping): + return None + value = summary.get(field) + if isinstance(value, bool) or not isinstance(value, (int, float)): + return None + number = float(value) + return number if math.isfinite(number) else None + + +def _median_or_none(record: Mapping[str, Any]) -> float | None: + return _summary_field(record, "median") + + +def _spread_or_none(record: Mapping[str, Any]) -> float | None: + return _summary_field(record, "spread_pct") + + +def _busy_or_none(record: Mapping[str, Any]) -> int | None: + summary = record.get("sm_clock_mhz") + if not isinstance(summary, Mapping): + return None + value = summary.get("n") + if isinstance(value, bool) or not isinstance(value, int): + return None + return value + + +def _idle_or_none(record: Mapping[str, Any]) -> int | None: + value = record.get("idle_samples_excluded") + if isinstance(value, bool) or not isinstance(value, int): + return None + return value + + +# -------------------------------------------------------------------------- +# The sampler. Same shape as tools/bench/sample_process_memory.py: a background +# process for the length of the measured window, one artifact of raw samples +# and one summary, and a stop condition the caller already owns. +# -------------------------------------------------------------------------- + + +class _Stop: + def __init__(self) -> None: + self.requested = False + + def __call__(self, signum: int, frame: FrameType | None) -> None: + self.requested = True + + +def run_sampler( + *, + samples_output: pathlib.Path, + summary_output: pathlib.Path, + interval_s: float = 1.0, + max_duration_s: float | None = None, + smi: str = NVIDIA_SMI, + boot_id_path: pathlib.Path = BOOT_ID_PATH, +) -> dict[str, Any]: + if interval_s <= 0.0: + raise HarnessError("clock sampling interval must be positive") + if max_duration_s is not None and max_duration_s <= 0.0: + raise HarnessError("clock sampling max duration must be positive") + for path in (samples_output, summary_output): + if path.exists(): + raise HarnessError(f"refusing to overwrite clock evidence: {path}") + boot_id = read_boot_id(boot_id_path) + stop = _Stop() + for signum in (signal.SIGINT, signal.SIGTERM): + signal.signal(signum, stop) + samples_output.parent.mkdir(parents=True, exist_ok=True) + start = time.monotonic() + collected: list[dict[str, Any]] = [] + with samples_output.open("w", encoding="utf-8", newline="\n") as sink: + while True: + sample = query_once(smi=smi) + sample["elapsed_s"] = time.monotonic() - start + sample["timestamp_utc"] = dt.datetime.now(dt.timezone.utc).isoformat() + sink.write(canonical_json(sample) + "\n") + sink.flush() + collected.append(sample) + if stop.requested: + break + if max_duration_s is not None and time.monotonic() - start >= max_duration_s: + break + time.sleep(interval_s) + if stop.requested: + break + record = build_clock_record(collected, boot_id=boot_id) + write_json_atomic(summary_output, record) + return record + + +def main(argv: Sequence[str] | None = None) -> int: + parser = argparse.ArgumentParser(description=__doc__) + subparsers = parser.add_subparsers(dest="command", required=True) + + sample = subparsers.add_parser( + "sample", help="sample the SM clock across a measured window" + ) + sample.add_argument("--output", type=pathlib.Path, required=True) + sample.add_argument("--summary", type=pathlib.Path, required=True) + sample.add_argument("--interval", type=float, default=1.0) + sample.add_argument("--max-duration", type=float) + + check = subparsers.add_parser( + "compare", help="compare two recorded arms and print the clock block" + ) + check.add_argument("--ours", type=pathlib.Path, required=True) + check.add_argument("--vllm", type=pathlib.Path, required=True) + check.add_argument( + "--allow-cross-boot", + action="store_true", + help="waive boot IDENTITY (never state); records a caveat, not silence", + ) + + args = parser.parse_args(argv) + if args.command == "sample": + record = run_sampler( + samples_output=args.output, + summary_output=args.summary, + interval_s=args.interval, + max_duration_s=args.max_duration, + ) + print(canonical_json(record)) + return 0 + + import json as _json + + comparison = compare_clock_records( + _json.loads(args.ours.read_text(encoding="utf-8")), + _json.loads(args.vllm.read_text(encoding="utf-8")), + allow_cross_boot=args.allow_cross_boot, + ) + print(canonical_json(comparison)) + return 0 if not comparison["reasons"] else 1 + + +if __name__ == "__main__": + try: + raise SystemExit(main()) + except HarnessError as error: + print(f"gpu-clock-state: {error}", file=sys.stderr) + raise SystemExit(2) from error diff --git a/tools/bench/online_gate_summary.py b/tools/bench/online_gate_summary.py index 757e14a7f..a7652ce12 100755 --- a/tools/bench/online_gate_summary.py +++ b/tools/bench/online_gate_summary.py @@ -44,6 +44,11 @@ validate_raw_result, _fingerprint_tree, ) +from tools.bench.gpu_clock_state import ( + clock_reasons, + compare_clock_records, + merge_clock_records, +) from tools.bench.serve_low_common import ( HarnessError, VLLM_COMMIT, @@ -113,6 +118,103 @@ def _run_metrics(record: Mapping[str, Any]) -> dict[str, float]: return metrics +def _clock_for_leg( + evidence_root: pathlib.Path, + model: str, + engine: str, + repetition: int, +) -> tuple[dict[str, Any] | None, list[str]]: + """Read one leg's SM-clock record, or say why the leg is not established. + + Same shape and same seam as ``_memory_for_leg``: a defect becomes a reason, + and a reason clears ``binding_eligible``. A leg with no clock record is not + a leg with a default clock -- it is a number nobody can attribute to a box + state, which is the whole of #543. + """ + + base = evidence_root / "clocks" / model / engine + summary_path = base / f"r{repetition}.summary.json" + samples_path = base / f"r{repetition}.samples.jsonl" + label = f"{engine} r{repetition}" + try: + record = _load_json(summary_path) + except HarnessError as error: + return None, [f"clock: {error}"] + reasons = list(clock_reasons(record, label=label)) + try: + samples = list(read_jsonl(samples_path)) + except (HarnessError, FileNotFoundError, OSError) as error: + samples = [] + reasons.append(f"clock: {label} SM-clock samples are missing or invalid: {error}") + summary = record.get("sm_clock_mhz") + counted: int | None = None + if isinstance(summary, Mapping) and isinstance(summary.get("n"), int): + excluded = record.get("idle_samples_excluded") + if isinstance(excluded, int) and not isinstance(excluded, bool): + counted = summary["n"] + excluded + if not samples: + reasons.append(f"clock: {label} SM-clock sample stream is empty") + elif counted != len(samples): + reasons.append( + f"clock: {label} summary accounts for {counted} samples; " + f"the stream holds {len(samples)}" + ) + return record, reasons + + +def _clock_for_arm( + legs: Sequence[dict[str, Any] | None], *, engine: str +) -> tuple[dict[str, Any] | None, list[str]]: + """Fold an arm's legs into the record the ratio is qualified by.""" + + if any(record is None for record in legs): + return None, [] + try: + return merge_clock_records([record for record in legs if record is not None]), [] + except HarnessError as error: + return None, [f"clock: {engine} {error}"] + + +def _clock_comparison( + ours: Mapping[str, Any] | None, + floor: Mapping[str, Any] | None, + *, + allow_cross_boot: bool, +) -> dict[str, Any]: + """The clock block that sits next to every ratio.""" + + missing = [ + engine + for engine, record in (("ours", ours), ("vllm", floor)) + if record is None + ] + if missing: + return { + "allow_cross_boot": bool(allow_cross_boot), + "caveats": [], + "cross_boot_override": False, + "estimated_effect_pct": None, + "median_offset_pct": None, + "ours_boot_id": None if ours is None else ours.get("boot_id"), + "ours_busy_samples": None, + "ours_idle_samples_excluded": None, + "ours_median_sm_mhz": None, + "ours_spread_pct": None, + "reasons": [ + f"clock: the {engine} arm has no usable SM-clock record, so the " + "ratio cannot be attributed to a box state (#543)" + for engine in missing + ], + "same_boot": False, + "vllm_boot_id": None if floor is None else floor.get("boot_id"), + "vllm_busy_samples": None, + "vllm_idle_samples_excluded": None, + "vllm_median_sm_mhz": None, + "vllm_spread_pct": None, + } + return compare_clock_records(ours, floor, allow_cross_boot=allow_cross_boot) + + def _memory_for_leg( evidence_root: pathlib.Path, model: str, @@ -668,6 +770,7 @@ def summarize_evidence( evidence_root: pathlib.Path, *, models: Sequence[str] | None = None, + allow_cross_boot: bool = False, ) -> tuple[dict[str, Any], dict[str, Any]]: selected_models = _select_models(models) grouped: dict[tuple[str, str, int], list[tuple[int, dict[str, Any]]]] = defaultdict(list) @@ -825,6 +928,24 @@ def summarize_evidence( evidence_root, model, engine, repetition ) + leg_clock: dict[tuple[str, str, int], dict[str, Any] | None] = {} + clock_leg_reasons: dict[tuple[str, str, int], list[str]] = {} + arm_clock: dict[tuple[str, str], dict[str, Any] | None] = {} + arm_clock_reasons: dict[tuple[str, str], list[str]] = {} + for model in selected_models: + for engine in ENGINES: + for repetition in REPETITIONS: + key = (model, engine, repetition) + leg_clock[key], clock_leg_reasons[key] = _clock_for_leg( + evidence_root, model, engine, repetition + ) + arm_clock[(model, engine)], arm_clock_reasons[(model, engine)] = ( + _clock_for_arm( + [leg_clock[(model, engine, rep)] for rep in REPETITIONS], + engine=engine, + ) + ) + raw_runs: list[dict[str, Any]] = [] aggregates: list[dict[str, Any]] = [] aggregate_index: dict[tuple[str, str, int], dict[str, Any]] = {} @@ -845,7 +966,9 @@ def summarize_evidence( run["binding_eligible"] = not run["reasons"] reasons.extend(run["reasons"]) reasons.extend(leg_reasons[(key[0], key[1], run["repetition"])] ) + reasons.extend(clock_leg_reasons[(key[0], key[1], run["repetition"])]) raw_runs.append(run) + reasons.extend(arm_clock_reasons[(key[0], key[1])]) axes: dict[str, dict[str, float] | None] = {} for axis in (*HIGHER_AXES, *LOWER_AXES): values = [run["metrics"].get(axis) for run in runs] @@ -900,7 +1023,19 @@ def summarize_evidence( memory_index[(model, engine)] = aggregate ratios: list[dict[str, Any]] = [] + clock_comparisons: dict[str, dict[str, Any]] = {} for model in selected_models: + # ONE clock block per model, attached to every ratio it qualifies. A + # reader must be able to size the clock against the effect without + # leaving the row: a 12.79% offset moved a byte-identical kernel 9.65%, + # which is larger than most deficits this grid is used to rank (#543). + clock_comparisons[model] = _clock_comparison( + arm_clock[(model, "ours")], + arm_clock[(model, "vllm")], + allow_cross_boot=allow_cross_boot, + ) + clock = clock_comparisons[model] + clock_established = not clock["reasons"] for concurrency, _ in points_for(model): ours = aggregate_index[(model, "ours", concurrency)] floor = aggregate_index[(model, "vllm", concurrency)] @@ -922,7 +1057,9 @@ def summarize_evidence( ours["binding_eligible"] and floor["binding_eligible"] and normalized is not None + and clock_established ), + "clock": clock, "concurrency": concurrency, "direction": "higher" if higher else "lower", "model": model, @@ -951,7 +1088,9 @@ def summarize_evidence( ours_memory["binding_eligible"] and floor_memory["binding_eligible"] and normalized is not None + and clock_established ), + "clock": clock, "concurrency": None, "direction": "lower", "model": model, @@ -978,6 +1117,8 @@ def summarize_evidence( "raw_runs": raw_runs, } ratios_document = { + "allow_cross_boot": bool(allow_cross_boot), + "clocks": clock_comparisons, "gate_pass": gate_pass, "models": list(selected_models), "ratios": ratios, @@ -1005,6 +1146,44 @@ def _report(runs: Mapping[str, Any], ratios: Mapping[str, Any]) -> str: ] lines.append(f"Every-axis ratios failing or void: {len(failed)}/{len(ratios['ratios'])}.") lines.append("") + # The clock sits NEXT TO the verdict, not in an appendix: a ratio quoted + # without the clock it was measured at is what #543 retracted. + + def _sample_count(block: Mapping[str, Any], key: str) -> str: + value = block.get(key) + return "?" if value is None else str(value) + + for model, clock in sorted(ratios.get("clocks", {}).items()): + ours = clock.get("ours_median_sm_mhz") + floor = clock.get("vllm_median_sm_mhz") + offset = clock.get("median_offset_pct") + effect = clock.get("estimated_effect_pct") + if ours is None or floor is None or offset is None: + lines.append(f"- {model}: SM clock NOT RECORDED — the ratio is not attributable.") + else: + lines.append( + f"- {model}: SM clock ours {ours:.0f} MHz vs vLLM {floor:.0f} MHz " + f"({offset:+.2f}%, estimated {effect:+.2f}% of kernel time); " + f"boot {'SAME' if clock['same_boot'] else 'DIFFERS'}" + + (" (OVERRIDDEN)" if clock.get("cross_boot_override") else "") + ) + # How much of the window each arm was observed over. A +0.00% offset + # taken over one busy sample in three hundred is the cleanest line + # this report can print and the emptiest; the counts are what tell + # the two apart, so they are printed beside the offset, not filed in + # `r.summary.json` where nothing reads them. + lines.append( + " - observed: ours " + f"{_sample_count(clock, 'ours_busy_samples')} busy / " + f"{_sample_count(clock, 'ours_idle_samples_excluded')} idle, vLLM " + f"{_sample_count(clock, 'vllm_busy_samples')} busy / " + f"{_sample_count(clock, 'vllm_idle_samples_excluded')} idle" + ) + for reason in clock.get("reasons", []): + lines.append(f" - {reason}") + for caveat in clock.get("caveats", []): + lines.append(f" - CAVEAT: {caveat}") + lines.append("") return "\n".join(lines) @@ -1012,9 +1191,21 @@ def main() -> int: parser = argparse.ArgumentParser() parser.add_argument("--evidence", type=pathlib.Path, required=True) parser.add_argument("--model", choices=tuple(MODEL_REVISIONS)) + parser.add_argument( + "--allow-cross-boot", + action="store_true", + help=( + "waive the requirement that both arms ran on the SAME BOOT. It " + "waives identity, never state: the spread and offset rules still " + "apply, and the comparison is stamped with a recorded caveat " + "rather than passing silently (#543, #545)." + ), + ) args = parser.parse_args() models = (args.model,) if args.model is not None else None - runs, ratios = summarize_evidence(args.evidence, models=models) + runs, ratios = summarize_evidence( + args.evidence, models=models, allow_cross_boot=args.allow_cross_boot + ) output = args.evidence / (f"summary-{args.model}" if args.model else "summary") if output.exists() and any(output.iterdir()): raise HarnessError(f"refusing to overwrite summary evidence in {output}")