From 00afae3c426c6cd891145e7c897868f822491579 Mon Sep 17 00:00:00 2001 From: Ettore Di Giacinto Date: Wed, 12 Aug 2026 23:48:57 +0000 Subject: [PATCH 1/4] spec(BENCH-ASSERT-CLOCK-STATE): the SM clock differs between boots and no manifest records it (#543) FOLLOWING_AGENTS_PROTOCOL On dgx.casa, driver 580.159.03, persistence Enabled and clocks_throttle_reasons.active = 0x0 on both sides, one boot ran the timed window at a median 2470 MHz and the next at a flat 2190. That is a 12.79% delta, and it repriced a byte-identical marlin::Marlin -- 129 calls/step, same invocation, NO source change between a170c81c and 4064558d0 -- from 45.2845 to 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 +6.28%), so both are NOT ESTABLISHED. The same effect explains a same-binary same-arm swing of 382.60 -> 357.59 us/call across a reboot, and two probes disagreeing ~6% uniformly eight minutes apart inside ONE boot. Nothing in the tree records it. `grep -rn 'clocks\.' tools/ scripts/` returns one hit, in prose. The three harness scripts that touch nvidia-smi write -q -d PERFORMANCE,TEMPERATURE,POWER into a text blob no summary reads. No manifest carries a clock, a boot id, or a throttle state, so no ratio in this repository can be attributed to the clock it was measured at. Same class as #375 and #520: an environment variable nobody wrote down, silently repricing every number. The spec argues both thresholds from the data rather than from taste. Within-run spread 5.0%: it must ACCEPT the only clean window we have, (2489-2398)/2470 = 3.68%, and REJECT the within-boot disagreement at ~26%. Cross-arm median offset 1.0%: at the measured transfer of 0.754 points of kernel time per point of clock that estimates to ~0.75%, under the 2.97% smallest deficit anyone ranks. The transfer is n = 1, is reported and never gated on, and is recorded as owed. No measurement is taken here and none is restated. #545 is linked because the box's MTBF is now shorter than one four-leg chain, which is why a cross-boot override exists at all -- it waives identity, never state. Following-Agents-Protocol: true AI-Assisted: true Assisted-by: Claude:claude-opus-5 [ClaudeCode] --- .agents/roadmap_v1.md | 2 + .agents/specs/bench-assert-clock-state.md | 256 ++++++++++++++++++++++ 2 files changed, 258 insertions(+) create mode 100644 .agents/specs/bench-assert-clock-state.md 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..7d6de3176 --- /dev/null +++ b/.agents/specs/bench-assert-clock-state.md @@ -0,0 +1,256 @@ +# 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 — the same shape as the + memory sampler that already runs there, written to + `clocks///r.{samples.jsonl,summary.json}` beside + `memory/…`. +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 | +| within-run spread | `≤ 5.0%` | see below | +| cross-arm median offset | `≤ 1.0%` | 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. + +**Cross-arm median offset, 1.0%.** 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.754** 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 is recorded as such — it is used only to *report* an estimated +effect, never as a gate term. At a 1.0% offset the estimate is ≈0.75% of kernel +time, comfortably 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 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). The spread and +offset assertions still apply — the override waives *identity*, not *state*. + +### 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. + +## 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 +- 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 + +Regression surface: `tests/tools` in full — **233** tests on the base SHA +`8b00f79f2`, **295** here; 0 removed, proven by a sorted test-name diff. A +changed count is RED even when it prints `OK`. + +Twelve mutations, applied one at a time with `count == 1` anchors and restored +byte-for-byte by sha256: the cross-boot refusal, each threshold widened to +1000%, the throttle mask opened to every bit, idle samples counted as busy, the +straddled-boot fold, leg reasons and arm reasons dropped from the aggregate, +each of the two ratio-level `clock_established` terms, the missing-record +reason, and the stream/summary reconciliation. **Three survived the 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 now 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, which is the only thing +the reader has. Twelve of twelve 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. +- The `0.754` transfer coefficient is `n = 1`. A second cross-boot pair, once + #545 allows one, either confirms it or replaces it. + +## 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. From 46d75eb49496ffa2825358858a0dd118ec68b5e6 Mon Sep 17 00:00:00 2001 From: Ettore Di Giacinto Date: Wed, 12 Aug 2026 23:51:08 +0000 Subject: [PATCH 2/4] feat(bench): record the SM clock a measurement ran at, and refuse a cross-boot ratio (#543) FOLLOWING_AGENTS_PROTOCOL One helper, tools/bench/gpu_clock_state.py, does the sampling, the folding and the assertions; other harnesses import it. Standard library only, like serve_low_common, so every assertion runs in CPU CI with no GPU and no nvidia-smi -- the 50 helper cases use synthetic manifests and a stub probe. RECORDED per leg, beside memory/, by a background sampler across the timed bench loop: the SM clock over the window (min/median/max and 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 -- a clock read while the GPU does nothing priced no work, and the window necessarily contains the harness's own gaps between concurrency points. An entirely idle window has nothing to attribute and is refused. ASSERTED in online_gate_summary through the existing `reasons` seam, which is this harness's spelling of NOT ESTABLISHED, so nothing new is invented and no gate is weakened: a cross-boot pair is refused; a within-run spread above 5.0% or a cross-arm median offset above 1.0% voids the ratio; a non-benign throttle bit or persistence-off voids the leg; an arm whose three legs straddle two boots will not fold. Every ratio carries a clock block with both medians, both spreads, the signed offset and the estimated effect, and the report prints it next to the verdict, so a reader can size the clock against the effect without leaving the row. --allow-cross-boot waives IDENTITY, never STATE. 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; the spread and offset rules still apply and the comparison is stamped with a recorded caveat rather than passing silently. 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 next commit adds a note instead of editing any recorded number. 233 -> 295 tests, 0 removed, proven by a sorted test-name diff. Twelve mutations with count == 1 anchors, restored byte-for-byte by sha256. THREE SURVIVED the first round: both ratio-level clock terms and the missing-record reason. #520's lesson repeating -- the leg-level reason already voided every gate assertion, so each ratio-level site was dominated, and a single gate_pass assertion let the throughput and memory ratio families mask each other's removal. Two cases now assert the two families' binding_eligible SEPARATELY on a pair whose arms are individually clean, and a third pins the text that names the offending arm, which is the only thing the reader has. Twelve of twelve RED. The trace/per-kernel harnesses are NOT wired yet and are recorded as owed in the spec. That is the path #543's retracted findings came from, so it matters that it is named rather than assumed covered. Following-Agents-Protocol: true AI-Assisted: true Assisted-by: Claude:claude-opus-5 [ClaudeCode] --- scripts/dgx-online-serving.sh | 34 +- tests/tools/test_gpu_clock_state.py | 513 ++++++++++++++++++ tests/tools/test_online_gate_summary.py | 265 +++++++++- tools/bench/gpu_clock_state.py | 660 ++++++++++++++++++++++++ tools/bench/online_gate_summary.py | 172 +++++- 5 files changed, 1639 insertions(+), 5 deletions(-) create mode 100644 tests/tools/test_gpu_clock_state.py create mode 100644 tools/bench/gpu_clock_state.py diff --git a/scripts/dgx-online-serving.sh b/scripts/dgx-online-serving.sh index 0fe4033b0..c2acefaf8 100755 --- a/scripts/dgx-online-serving.sh +++ b/scripts/dgx-online-serving.sh @@ -553,18 +553,31 @@ run_startup_leg() { echo "startup ${model}/${engine}/r${repetition}: ${elapsed}s" >&2 } +# 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. +stop_clock_sampler() { + local pid=$1 + [[ -n ${pid} ]] || return 0 + kill -TERM "${pid}" 2>/dev/null || true + wait "${pid}" +} + run_leg() { local engine=$1 repetition=$2 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" + local clock_pid="" 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 +597,24 @@ 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. + 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 & + 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 "${clock_pid}" || true return 1 } python3 "${repo_root}/tools/bench/online_gate.py" bench \ @@ -600,6 +627,11 @@ run_leg() { --concurrency "${concurrency}" \ --repetition "${repetition}" done + stop_clock_sampler "${clock_pid}" || { + 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..f7dde655e --- /dev/null +++ b/tests/tools/test_gpu_clock_state.py @@ -0,0 +1,513 @@ +"""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, + 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 _record(values, *, boot_id=BOOT_GOOD, **kwargs): + return build_clock_record(_samples(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_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_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_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"], 9) + 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") + record = 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, + ) + stream = [ + json.loads(line) + for line in (directory / "r1.samples.jsonl").read_text().splitlines() + if line.strip() + ] + 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_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) + + +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..5563b1529 100644 --- a/tests/tools/test_online_gate_summary.py +++ b/tests/tools/test_online_gate_summary.py @@ -28,9 +28,45 @@ VLLM_GENERATION_WINDOW_CONTRACTS, _fingerprint_tree, ) -from tools.bench.online_gate_summary import summarize_evidence +from tools.bench.gpu_clock_state import 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 _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(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 +398,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 +442,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 +452,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 +673,225 @@ 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_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..29f6fb126 --- /dev/null +++ b/tools/bench/gpu_clock_state.py @@ -0,0 +1,660 @@ +#!/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. Both 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. +MAX_WITHIN_RUN_SPREAD_PCT = 5.0 +# +# Cross-arm median offset, 1.0%. At the measured transfer below a 1.0% offset +# estimates to ~0.75% of kernel time, comfortably 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. +MAX_CROSS_ARM_OFFSET_PCT = 1.0 +# +# 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 used only to REPORT an estimated effect and is never a gate term. +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") + 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] = [] + 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 IDENTITY, never STATE. 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 the refusal into a + recorded caveat, and the spread and offset rules still apply. + """ + + reasons = [ + *clock_reasons(ours, label=ours_label), + *clock_reasons(theirs, label=theirs_label), + ] + 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, + 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}_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") + + +# -------------------------------------------------------------------------- +# 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..6f69fd606 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,99 @@ 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_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_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 +766,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 +924,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 +962,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 +1019,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 +1053,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 +1084,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 +1113,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 +1142,27 @@ 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. + 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 "") + ) + 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 +1170,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}") From 3e0f2b2d362e8369eabae4d02b20fa4b1b55af84 Mon Sep 17 00:00:00 2001 From: Ettore Di Giacinto Date: Wed, 12 Aug 2026 23:53:09 +0000 Subject: [PATCH 3/4] docs(BENCH-ASSERT-CLOCK-STATE): pin the clocks under the lock, and say which numbers predate the assertion (#543) FOLLOWING_AGENTS_PROTOCOL benchmarking.md gains the method: what a leg records, why two arms on different boots are not comparable, and the operational fix. Clocks can be pinned with `sudo nvidia-smi -lgc ` and released with `-rgc` -- passwordless sudo is available on dgx and -lgc is supported there. Pinning is a SHARED-HOST MUTATION and must not be done while another session holds $HOME/gpu.lock: it would silently reprice their in-flight measurement, which is exactly the defect the section exists for. It is recommended as a pre-measurement step UNDER the lock, not as a standing configuration -- leaving the box pinned makes every later run inherit a state nobody recorded, which is where this started. NO RECORDED NUMBER IS EDITED. AGENTS.md: never delete evidence. Instead each surface that cites the old figures says they predate clock assertion -- BENCHMARKS.md as an at-a-glance row (the prose there is at its paragraph and cell budget, so the note goes where a result belongs, in a table row), and STATUS.md next to the parity-pin note that already explains a different attribution defect on the same runs. Neither withdraws nor restates anything: these numbers simply carry no clock, so a difference of a few percent between two of them is not established BY THEM ALONE. benchmark-record.md, which is the append-only log, carries the forensics: the two-boot table, the marlin control, the two findings it retracts (in_proj +2.97% and out_proj +6.28%, neither ever taken against a clock control), the thresholds and their derivation, and the live state at the time of writing. A read-only probe on 2026-08-12 returned a THIRD boot id, 13dc5579, at the degraded 2190 MHz with clocks.max.sm 3003 -- the defect is live, not historical. No clock was pinned and no GPU work was queued in this row: another session held the lock. Following-Agents-Protocol: true AI-Assisted: true Assisted-by: Claude:claude-opus-5 [ClaudeCode] --- .agents/benchmark-record.md | 63 +++++++++++++++++++++++++++++++++++++ .agents/benchmarking.md | 48 +++++++++++++++++++++++++++- docs/BENCHMARKS.md | 1 + docs/STATUS.md | 12 +++++++ 4 files changed, 123 insertions(+), 1 deletion(-) diff --git a/.agents/benchmark-record.md b/.agents/benchmark-record.md index 0d27114e0..93c503450 100644 --- a/.agents/benchmark-record.md +++ b/.agents/benchmark-record.md @@ -20353,3 +20353,66 @@ per stream), NOT as a perf fix; C_tmp size is ELIMINATED as an explanation of th 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` waives identity, never +state, and stamps a recorded caveat. + +Both thresholds are arguments from the table above and are derived in +`.agents/specs/bench-assert-clock-state.md`. The transfer used to report an +estimated effect — **0.754** 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. + +### 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. diff --git a/.agents/benchmarking.md b/.agents/benchmarking.md index 43e3c3db8..ed0722b04 100644 --- a/.agents/benchmarking.md +++ b/.agents/benchmarking.md @@ -30,6 +30,51 @@ 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. Every leg records +the SM clock across the measured window (min/median/max and n), `clocks.max.sm`, +`clocks.applications.graphics`, the active throttle reasons, persistence mode, +and the **boot id** — `tools/bench/gpu_clock_state.py` is the one helper that +samples, folds, and asserts it, and other harnesses import it rather than +rolling their own. + +Two arms on **different boots are not comparable**. The summary refuses that +pair outright; `--allow-cross-boot` waives *identity*, never *state*, and stamps +a recorded caveat rather than passing silently. Within a run the SM-clock spread +must stay at or below **5%**, and the two arms' medians within **1%** of each +other — the first accepts the one clean window we have (3.68%) and rejects the +within-boot disagreement, the second keeps the clock's estimated contribution +under the smallest deficit anyone ranks. The argument for both numbers 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 +105,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/docs/BENCHMARKS.md b/docs/BENCHMARKS.md index 71d3964d0..5820e8cfb 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 a byte-identical `marlin::Marlin` **+9.65%**, over the deficits it ranked | 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 86b20c444..f91a9eada 100644 --- a/docs/STATUS.md +++ b/docs/STATUS.md @@ -34,6 +34,18 @@ 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 an over-spread run +([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 From bfa607c3e0c86697b82b30216dea5424cc4e07f7 Mon Sep 17 00:00:00 2001 From: Ettore Di Giacinto Date: Thu, 13 Aug 2026 01:13:43 +0000 Subject: [PATCH 4/4] fix(bench): a clock window the sampler barely observed scored a perfect 0.00%, and the override waived the machine (#543, #545) Four review findings against row/BENCH-ASSERT-CLOCK-STATE. The design, seam, records discipline and the twelve original mutations stand; these are defects in what the assertions cover. F1. Idle dilution. `validate_clock_record` required only `n >= 1`, and `spread_pct` over `n == 1` is definitionally 0.00% -- the BEST score the gate can award -- so the window the sampler barely observed outscored the one it watched. Six legs each holding ONE busy sample and 300 idle gave `gate_pass: true`, `clock reasons: []` and a report line reading `+0.00%`. `idle_samples_excluded`, the one field that would have betrayed it, was written to `r.summary.json` and then never asserted, never folded into the ratio's `clock` block and never printed. `clock_reasons` now floors both the retained busy count (30) and the busy fraction (50%), and both counts are carried in the clock block and printed on the report's `observed:` line. The floors are derived from the sampling rate and the grid: at `--interval 1` a busy sample is a second of OBSERVED BUSY GPU, and the smallest configured leg (1920 sequential decode steps plus 48 prefills of 1024 tokens) would have to average under ~16 ms/step to finish inside 30 of them, against 82-88 ms/step measured on this box. 30 also sits 40% below the smaller of the two real #543 windows (n=61, n=50), so it accepts both. F2. `--allow-cross-boot` waived hardware identity as a side effect. `compare_clock_records` never compared `gpu_name`, `driver_version`, `clocks_max_sm_mhz`, `clocks_applications_graphics_mhz` or `persistence_mode` ACROSS the arms; `STATIC_FIELDS` was enforced only within a window and between one arm's legs. Same-boot equality was the implicit proxy for "same machine", and the override removed it with nothing in its place: an NVIDIA GB10 / 580.159.03 / max 3003 arm compared CLEAN against an NVIDIA H100 80GB HBM3 / 550.54.15 / max 1980 one, caveated only as "different boots". `STATIC_FIELDS` is now asserted across the arms unconditionally. #545 makes the override the normal path, so this was reachable, not theoretical. F3. The test named "the override does not waive state" was dominated. Rewriting `compare_clock_records` to `reasons = [] if allow_cross_boot else [...]` (R15) survived the full suite GREEN: one test asserts an OFFSET reason, appended outside the mutated expression, and the other writes an over-spread LEG already voided at leg level by `_clock_for_leg`. 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. A summary-level case now pins it: three individually-flat legs at 2470 / 2300 / 2190 on ONE boot under `allow_cross_boot=True`, with the vLLM arm at the merged median so the offset stays 0.00% and cannot mask the removal. R15 is now RED. F4. The sampler was orphaned on every abort path. `clock_pid` was `local` to `run_leg` and invisible to the EXIT trap, which reaps only `profiled_pid`, `spid` and `mpid`; under `set -euo pipefail` a failing `online_gate.py bench` exits without reaching `stop_clock_sampler`. The sampler had neither `--pid` nor `--max-duration`, so its only stop condition was a SIGTERM that path skips, and it went on polling `nvidia-smi` once a second forever on a box another session may hold `$HOME/gpu.lock` on. The spec claimed "the same shape as the memory sampler"; it was not, and it now is on BOTH counts -- `clock_pid` is a global reaped by `cleanup_server`, and the sampler is bounded by `--max-duration` (7200 s, 4x the driver's own readiness budget, a bound on an orphan and not a budget on a leg). F5. The two thresholds were argued to different standards. The 1.0% offset was derived forward through the n=1 transfer; the same criterion was never applied to spread, where 5.0 x 0.7548 = 3.77% exceeds the 2.97% smallest deficit ranked. Spread is NOT tightened -- the forward criterion would demand <=3.93%, which sits 0.25 points above our only clean capture (3.68%) and would void it on a noisier-but-healthy day -- so the reason it may exceed is stated instead: the offset bounds a SYSTEMATIC arm-to-arm difference that transfers whole into the ratio, while spread bounds DISPERSION inside one arm's window, most of which is common to both arms and whose residual is the difference of two medians that the offset rule already bounds. The residual is recorded: passing spread establishes that an arm was ONE state, not that a sub-4% deficit is established. The offset argument is also strengthened off the n=1 coefficient entirely: for any kernel whose time scales with clock the transfer is bounded above by 1.0, so a 1.0% offset implies at most a 1.0% effect on PHYSICS, still under 2.97%. The measured 0.7548 sits below that ceiling exactly as a partly memory-bound kernel should. The coefficient is not a gate TERM (proven by the mutation set) but it was a gate PREMISE; the physics bound retires it from that role. F6. `.agents/benchmarking.md` -- the file an agent reads before measuring -- claimed "Every leg records..." and "other harnesses import it..." in the present tense with no caveat. Only `dgx-online-serving.sh` records anything; `finalize_*_trace.py`, `summarize_torch_kernels.py` and `gdn_packed_component.py` are unwired, and that trace path is exactly where both retracted findings came from. The guide now says so, matching the spec's own Scope and Owed. Recorded, not fixed, in the spec's Owed: `all-runs.json` carries no clock block and no `allow_cross_boot` flag (report.md does print `(OVERRIDDEN)`/`CAVEAT:`, so it is not buried for a human, but the JSON a consumer parses is silent); `compare_clock_records` builds keys as `f"{ours_label}_boot_id"`, so identical labels would collapse one arm into the other, unreachable from current call sites; and the busy floors are derived but not yet measured against a real leg. Gates. `python3 -m unittest discover -s tests/tools -t .`: 295 -> 310, exit 0, 0 removed, proven by a sorted test-name diff. 24 mutations (the original 12 plus R13-R24), one at a time, `count == 1` anchors, restored byte-for-byte and verified by sha256: 24/24 RED. R17 survived the first pass and was a genuine gap in the new validation, not a dominated site, so two cases now pin it; M11 first read SURVIVED because the mutation itself was inert (`[] or [...]` is the non-empty list), which is why a byte-level sha256 proves the file changed and not that the behavior did. Both reviewer bypass probes re-run and now CAUGHT. `bash -n` and `shellcheck -S warning` clean on the driver. `scripts/agent-preflight.sh --staged` clean. No GPU work queued and no clock pinned: another session may hold `$HOME/gpu.lock`. FOLLOWING_AGENTS_PROTOCOL Following-Agents-Protocol: true AI-Assisted: true Assisted-by: Claude:claude-opus-5 [ClaudeCode] --- .agents/benchmark-record.md | 29 ++- .agents/benchmarking.md | 39 +++- .agents/specs/bench-assert-clock-state.md | 245 +++++++++++++++++++--- docs/BENCHMARKS.md | 2 +- docs/STATUS.md | 6 +- scripts/dgx-online-serving.sh | 49 +++-- tests/tools/test_gpu_clock_state.py | 219 ++++++++++++++++++- tests/tools/test_online_gate_summary.py | 116 +++++++++- tools/bench/gpu_clock_state.py | 149 ++++++++++++- tools/bench/online_gate_summary.py | 21 ++ 10 files changed, 792 insertions(+), 83 deletions(-) diff --git a/.agents/benchmark-record.md b/.agents/benchmark-record.md index 93c503450..973182ad3 100644 --- a/.agents/benchmark-record.md +++ b/.agents/benchmark-record.md @@ -20399,14 +20399,27 @@ 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` waives identity, never -state, and stamps a recorded caveat. - -Both thresholds are arguments from the table above and are derived in -`.agents/specs/bench-assert-clock-state.md`. The transfer used to report an -estimated effect — **0.754** 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. +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 diff --git a/.agents/benchmarking.md b/.agents/benchmarking.md index ed0722b04..8d3d957b2 100644 --- a/.agents/benchmarking.md +++ b/.agents/benchmarking.md @@ -40,20 +40,37 @@ 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. Every leg records -the SM clock across the measured window (min/median/max and n), `clocks.max.sm`, +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** — `tools/bench/gpu_clock_state.py` is the one helper that -samples, folds, and asserts it, and other harnesses import it rather than -rolling their own. +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 *identity*, never *state*, and stamps -a recorded caveat rather than passing silently. Within a run the SM-clock spread -must stay at or below **5%**, and the two arms' medians within **1%** of each -other — the first accepts the one clean window we have (3.68%) and rejects the -within-boot disagreement, the second keeps the clock's estimated contribution -under the smallest deficit anyone ranks. The argument for both numbers is in +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 diff --git a/.agents/specs/bench-assert-clock-state.md b/.agents/specs/bench-assert-clock-state.md index 7d6de3176..b6c5fabb1 100644 --- a/.agents/specs/bench-assert-clock-state.md +++ b/.agents/specs/bench-assert-clock-state.md @@ -51,10 +51,23 @@ attributed to the clock it was measured at. 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 — the same shape as the - memory sampler that already runs there, written to + 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 @@ -115,8 +128,11 @@ that is *entirely* idle has `n == 0` and fails validation. | 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 | @@ -129,22 +145,97 @@ 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. -**Cross-arm median offset, 1.0%.** 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.754** 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 is recorded as such — it is used only to *report* an estimated -effect, never as a gate term. At a 1.0% offset the estimate is ≈0.75% of kernel -time, comfortably 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. +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). The spread and -offset assertions still apply — the override waives *identity*, not *state*. +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 @@ -174,6 +265,16 @@ instead of a retroactive edit. 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 @@ -188,28 +289,92 @@ instead of a retroactive edit. - **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** here; 0 removed, proven by a sorted test-name diff. A -changed count is RED even when it prints `OK`. - -Twelve mutations, applied one at a time with `count == 1` anchors and restored -byte-for-byte by sha256: the cross-boot refusal, each threshold widened to -1000%, the throttle mask opened to every bit, idle samples counted as busy, the -straddled-boot fold, leg reasons and arm reasons dropped from the aggregate, -each of the two ratio-level `clock_established` terms, the missing-record -reason, and the stream/summary reconciliation. **Three survived the 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 now 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, which is the only thing -the reader has. Twelve of twelve RED. +`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 @@ -246,8 +411,26 @@ the reader has. Twelve of twelve RED. - 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. -- The `0.754` transfer coefficient is `n = 1`. A second cross-boot pair, once - #545 allows one, either confirms it or replaces it. + [`.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 diff --git a/docs/BENCHMARKS.md b/docs/BENCHMARKS.md index 5820e8cfb..0466c0999 100644 --- a/docs/BENCHMARKS.md +++ b/docs/BENCHMARKS.md @@ -15,7 +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 a byte-identical `marlin::Marlin` **+9.65%**, over the deficits it ranked | n/a, nothing withdrawn | +| **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 f91a9eada..25d01a7d9 100644 --- a/docs/STATUS.md +++ b/docs/STATUS.md @@ -40,7 +40,11 @@ is pending and blocked on [#522](https://github.com/mudler/vllm.cpp/issues/522). 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 an over-spread run +**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 diff --git a/scripts/dgx-online-serving.sh b/scripts/dgx-online-serving.sh index c2acefaf8..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 @@ -553,16 +576,6 @@ run_startup_leg() { echo "startup ${model}/${engine}/r${repetition}: ${elapsed}s" >&2 } -# 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. -stop_clock_sampler() { - local pid=$1 - [[ -n ${pid} ]] || return 0 - kill -TERM "${pid}" 2>/dev/null || true - wait "${pid}" -} - run_leg() { local engine=$1 repetition=$2 local baseline final idle_ok=0 @@ -574,7 +587,6 @@ run_leg() { 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" - local clock_pid="" mkdir -p \ "${memory_dir}" "${thermal_dir}" "${clock_dir}" "${return_dir}" "${cache_dir}" \ "${preflight_dir}" @@ -604,17 +616,26 @@ run_leg() { # 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 & + --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 "${clock_pid}" || true + stop_clock_sampler || true return 1 } python3 "${repo_root}/tools/bench/online_gate.py" bench \ @@ -627,7 +648,7 @@ run_leg() { --concurrency "${concurrency}" \ --repetition "${repetition}" done - stop_clock_sampler "${clock_pid}" || { + stop_clock_sampler || { echo "SM-clock sampler failed for ${model}/${engine}/r${repetition}" >&2 cleanup_server return 1 diff --git a/tests/tools/test_gpu_clock_state.py b/tests/tools/test_gpu_clock_state.py index f7dde655e..2b676e205 100644 --- a/tests/tools/test_gpu_clock_state.py +++ b/tests/tools/test_gpu_clock_state.py @@ -26,6 +26,8 @@ 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, @@ -67,8 +69,24 @@ def _samples(values, *, utilization=97, throttle="0x0000000000000000"): ] +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(values, **kwargs), boot_id=boot_id) + return build_clock_record(_samples(_window(values), **kwargs), boot_id=boot_id) class ParseTests(unittest.TestCase): @@ -208,6 +226,25 @@ def test_non_positive_clock_is_refused(self) -> None: 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"] = [] @@ -269,6 +306,69 @@ def test_persistence_off_is_not_established(self) -> None: 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") @@ -322,6 +422,67 @@ def test_the_override_does_not_waive_state_only_identity(self) -> None: 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( @@ -370,7 +531,7 @@ 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"], 9) + 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"), []) @@ -432,11 +593,16 @@ def test_a_window_becomes_a_stream_and_a_record(self) -> None: ) 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.01, - max_duration_s=0.05, + interval_s=0.001, + max_duration_s=1.0, smi=str(stub), boot_id_path=boot, ) @@ -445,6 +611,7 @@ def test_a_window_becomes_a_stream_and_a_record(self) -> None: 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) @@ -504,10 +671,54 @@ def test_the_offset_threshold_stays_under_the_smallest_ranked_deficit(self) -> N # 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 5563b1529..355f74dd3 100644 --- a/tests/tools/test_online_gate_summary.py +++ b/tests/tools/test_online_gate_summary.py @@ -28,7 +28,7 @@ VLLM_GENERATION_WINDOW_CONTRACTS, _fingerprint_tree, ) -from tools.bench.gpu_clock_state import build_clock_record +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 @@ -54,10 +54,23 @@ def _clock_samples(values, *, utilization=97, throttle="0x0000000000000000"): ] +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(values, **kwargs) + 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( @@ -790,6 +803,105 @@ def test_the_cross_boot_override_records_a_caveat_rather_than_silence(self) -> N 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) diff --git a/tools/bench/gpu_clock_state.py b/tools/bench/gpu_clock_state.py index 29f6fb126..c88ca348d 100644 --- a/tools/bench/gpu_clock_state.py +++ b/tools/bench/gpu_clock_state.py @@ -81,7 +81,7 @@ "persistence_mode", ) -# --- Thresholds. Both are arguments from the data above, not preferences. ----- +# --- 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 @@ -90,18 +90,74 @@ # 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%. At the measured transfer below a 1.0% offset -# estimates to ~0.75% of kernel time, comfortably 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. +# 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 used only to REPORT an estimated effect and is never a gate term. +# 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 @@ -400,6 +456,11 @@ def validate_clock_record(record: Mapping[str, Any], *, label: str) -> None: ) 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"] @@ -434,6 +495,27 @@ def clock_reasons(record: Mapping[str, Any], *, label: str) -> list[str]: 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( @@ -469,16 +551,37 @@ def compare_clock_records( medians, both spreads, the signed offset, and the estimated share of the ratio the clock alone explains. - `allow_cross_boot` waives IDENTITY, never STATE. 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 the refusal into a - recorded caveat, and the spread and offset rules still apply. + `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", "")) @@ -520,11 +623,18 @@ def compare_clock_records( ), "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), } @@ -549,6 +659,23 @@ 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 diff --git a/tools/bench/online_gate_summary.py b/tools/bench/online_gate_summary.py index 6f69fd606..a7652ce12 100755 --- a/tools/bench/online_gate_summary.py +++ b/tools/bench/online_gate_summary.py @@ -196,6 +196,8 @@ def _clock_comparison( "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": [ @@ -205,6 +207,8 @@ def _clock_comparison( ], "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, } @@ -1144,6 +1148,11 @@ def _report(runs: Mapping[str, Any], ratios: Mapping[str, Any]) -> str: 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") @@ -1158,6 +1167,18 @@ def _report(runs: Mapping[str, Any], ratios: Mapping[str, Any]) -> str: 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", []):