diff --git a/Makefile b/Makefile index 55a76bd..8e5a746 100644 --- a/Makefile +++ b/Makefile @@ -24,7 +24,7 @@ TOOLS := $(REPO)/tools # Every cargo recipe runs at the repo root; the shell does not persist cd. IN_REPO := cd $(REPO) && -.PHONY: check test sim bench bench-test coverage dep-weight cost cost-test cost-pin cost-budget cost-mix loop-lint self-tests env-test task-done status facts-check facts-gen mutation-check size-metrics loc all +.PHONY: check test sim bench bench-test coverage dep-weight cost cost-test cost-pin cost-budget cost-mix loop-lint self-tests env-test task-done status facts-check facts-gen mutation-check size-metrics runtime-metrics build-time loc all ## fmt + clippy (deny warnings) + HashMap deny-lint check: @@ -42,6 +42,15 @@ dep-weight: coverage: $(PY) $(TOOLS)/rule-coverage.py +# AM-9 peak RSS (fast, gated). AM-5 needs a clean build — see build-time. +runtime-metrics: + $(PY) $(TOOLS)/runtime-metrics.py --fast + +# AM-5: clean release build, ~90s, into a throwaway CARGO_TARGET_DIR so the +# working cache survives. Reported not gated per GameKernel §5. +build-time: + $(PY) $(TOOLS)/runtime-metrics.py + # AM-2 (M-D1-SPL, AM-1's anti-gaming pair) and AM-3. size-metrics: $(PY) $(TOOLS)/size-metrics.py @@ -70,6 +79,7 @@ self-tests: $(PY) $(TOOLS)/facts.py --self-test $(PY) $(TOOLS)/mutation-check.py --self-test $(PY) $(TOOLS)/size-metrics.py --self-test + $(PY) $(TOOLS)/runtime-metrics.py --self-test # T01 positive control: prove the environment fix, do not assume it. Runs # every tool from a foreign working directory with a PATH that has no @@ -147,4 +157,4 @@ loc: printf '%-28s %s\n' $$d "$$(find $$d/src -name '*.rs' | xargs cat | grep -vcE '^\s*(//|$$)')"; \ done -all: check test sim coverage size-metrics dep-weight self-tests env-test facts-check loop-lint bench-test +all: check test sim coverage size-metrics runtime-metrics dep-weight self-tests env-test facts-check loop-lint bench-test diff --git a/facts.toml b/facts.toml index 1f0bc28..09789a2 100644 --- a/facts.toml +++ b/facts.toml @@ -40,8 +40,8 @@ fmt = "{:,}" by = "tools/mutation-check.py" [am_unmutatable] -value = 6 -text = "6" +value = 5 +text = "5" fmt = "{:,}" by = "tools/mutation-check.py" diff --git a/tools/__pycache__/cb-cost.cpython-312.pyc b/tools/__pycache__/cb-cost.cpython-312.pyc index 2d6315c..eb81dcd 100644 Binary files a/tools/__pycache__/cb-cost.cpython-312.pyc and b/tools/__pycache__/cb-cost.cpython-312.pyc differ diff --git a/tools/__pycache__/dep-weight.cpython-312.pyc b/tools/__pycache__/dep-weight.cpython-312.pyc index 99f4259..c2effba 100644 Binary files a/tools/__pycache__/dep-weight.cpython-312.pyc and b/tools/__pycache__/dep-weight.cpython-312.pyc differ diff --git a/tools/__pycache__/mutation-check.cpython-312.pyc b/tools/__pycache__/mutation-check.cpython-312.pyc index 9374fca..3f12d37 100644 Binary files a/tools/__pycache__/mutation-check.cpython-312.pyc and b/tools/__pycache__/mutation-check.cpython-312.pyc differ diff --git a/tools/mutation-check.py b/tools/mutation-check.py index d8938be..31d12a4 100644 --- a/tools/mutation-check.py +++ b/tools/mutation-check.py @@ -133,9 +133,15 @@ def rows(): "cannot fail."), Row("AM-5", "clean release build <= 60 s", - unmutatable="declared `recorded not gated`, and not recorded " - "either — CB-EV-0001 lists AM-5 among the unreported " - "rows. Nothing times the build."), + unmutatable="now RECORDED (`make build-time`) and **breaching**: " + "87.0 s dev toolchain, 61.3 s shipped runtime, " + "against a 60 s target on bnt-lap001. Still counts " + "against M-D1-MUT because GameKernel §5 declares the " + "row `recorded not gated` — a row that cannot fail " + "asserts nothing, and promoting it is a spec change " + "needing an ADR. The breach is a maintainer decision, " + "not something this tool should resolve by gating " + "itself."), Row("AM-6", ">= 100,000 applied events/s", verify=CARGO + ["test", "-p", "games-ground", "--all-features", @@ -191,11 +197,15 @@ def rows(): "with -D warnings"), ]), + # A PROPERTY mutation: make the workload actually use memory. Row("AM-9", "peak RSS <= 64 MB", - unmutatable="no instrument. Nothing in the workspace measures " - "resident memory; CB-EV-0001 lists AM-9 as " - "unreported and 'very unlikely to bind' — an " - "unmeasured judgment call."), + verify=py + ["tools/runtime-metrics.py", "--fast"], + mutate=("games/ground/src/lib.rs", + " fn replay_100k_events_is_linear_and_fast() {", + " fn replay_100k_events_is_linear_and_fast() {\n" + " let hog: Vec = vec![7u8; 300_000_000];\n" + " std::hint::black_box(&hog);"), + expect="FAIL target <= 64 MB"), Row("AM-10", "0 foreign types in cb-*-api-visible signatures", unmutatable="the population is empty — there is no `cb-*-api` " diff --git a/tools/runtime-metrics.py b/tools/runtime-metrics.py new file mode 100644 index 0000000..d91bb24 --- /dev/null +++ b/tools/runtime-metrics.py @@ -0,0 +1,228 @@ +#!/usr/bin/env python3 +"""AM-5 (clean build time) and AM-9 (peak RSS) — measured for the first time. + +CB-WP-0006 T03. Both rows were `unmutatable`: AM-5 is declared +`recorded not gated` and had never been recorded, and AM-9 was declared +"very unlikely to bind", which `evidence/CB-EV-0001` itself flags as an +unmeasured judgment call. + +The task said: measure or withdraw, but stop leaving them blank. Measured. +They came out differently, and one of them is a breach. + +**AM-5 does not build into `target/`.** It builds into a temporary +`CARGO_TARGET_DIR` so a clean-build measurement does not destroy the +working cache — otherwise measuring the metric would cost several minutes +of rebuild every time, and a metric that punishes its own measurement gets +measured once and never again. + +**AM-5 exits 0 even on a breach**, because `specs/GameKernel.md` §5 +declares it `recorded not gated`. Gating it is a spec change and needs an +ADR; this tool reports, loudly, and does not quietly promote itself. +AM-9 carries no such declaration and **is** gated. + +Usage: + python3 tools/runtime-metrics.py # both (AM-5 takes ~90 s) + python3 tools/runtime-metrics.py --fast # AM-9 only, for `make all` + python3 tools/runtime-metrics.py --self-test +""" +import glob +import os +import re +import resource +import shutil +import subprocess +import sys +import tempfile +import time + +from repo import ROOT, cargo_bin, cargo_env, enter_root + +AM5_MAX_SECONDS = 60.0 +AM5_MACHINE = "bnt-lap001" # the spec names the machine; so do we +AM9_MAX_RSS_MB = 64.0 +AM9_TEST = "replay_probe::replay_100k_events_is_linear_and_fast" + + +def clean_build_seconds(extra=()): + """Wall seconds for a clean release build, into a throwaway target dir.""" + cargo = cargo_bin() + if not cargo: + return None + tmp = tempfile.mkdtemp(prefix="cb-am5-") + env = cargo_env() + env["CARGO_TARGET_DIR"] = tmp + try: + t = time.monotonic() + r = subprocess.run([cargo, "build", "--release", "--workspace", *extra], + cwd=ROOT, env=env, capture_output=True, text=True) + secs = time.monotonic() - t + if r.returncode != 0: + return None + return secs + finally: + shutil.rmtree(tmp, ignore_errors=True) + + +def test_binary(): + """Newest release test binary for games-ground, built if absent.""" + cargo = cargo_bin() + subprocess.run([cargo, "test", "--release", "-p", "games-ground", + "--all-features", "--no-run"], + cwd=ROOT, env=cargo_env(), capture_output=True, text=True) + cands = [p for p in glob.glob(os.path.join(ROOT, "target/release/deps/games_ground-*")) + if not p.endswith(".d") and os.access(p, os.X_OK)] + return max(cands, key=os.path.getmtime) if cands else None + + +def peak_rss_mb(binary, test=AM9_TEST): + """(peak RSS in MB, ok) for one test run, from that child's rusage. + + Uses `os.wait4`, which returns the rusage of **that specific child**. + The obvious alternative — `getrusage(RUSAGE_CHILDREN)` — is a + high-water mark across *every* reaped child of this process, so it + attributed `cargo`'s memory to the workload and reported **38.2 MB for + a run that actually used 12.3 MB**. Cross-checked against + `/usr/bin/time -v` on the same binary, which is how the discrepancy + was found. + """ + out_r, out_w = os.pipe() + try: + pid = os.posix_spawn( + binary, [binary, test, "--exact"], os.environ, + file_actions=[(os.POSIX_SPAWN_DUP2, out_w, 1), + (os.POSIX_SPAWN_DUP2, out_w, 2)]) + os.close(out_w) + out_w = None + chunks = [] + while True: + b = os.read(out_r, 65536) + if not b: + break + chunks.append(b) + _, _status, ru = os.wait4(pid, 0) + finally: + if out_w is not None: + os.close(out_w) + os.close(out_r) + text = b"".join(chunks).decode(errors="replace") + # ru_maxrss is kilobytes on Linux. + return ru.ru_maxrss / 1024.0, "1 passed" in text + + +def report(fast=False): + rc = 0 + + print("AM-9 / M-D3-MEM — peak resident memory, 100k-event run") + binary = test_binary() + if not binary: + print(" ERROR — could not locate the release test binary", + file=sys.stderr) + return 1 + rss, ran = peak_rss_mb(binary) + # Positive control: a run that did not execute the workload must not + # be scored as low memory. Reporting 2 MB because the filter matched + # nothing is exactly the harness-does-nothing shape. + if not ran: + print(f" ERROR — {AM9_TEST} did not run; refusing to report RSS", + file=sys.stderr) + return 1 + ok9 = rss <= AM9_MAX_RSS_MB + print(f" {rss:.1f} MB peak RSS [{'ok ' if ok9 else 'FAIL'} " + f"target <= {AM9_MAX_RSS_MB:.0f} MB] " + f"({AM9_MAX_RSS_MB / rss:.1f}x headroom)") + if not ok9: + rc = 2 + + if fast: + print("\nAM-5 skipped (--fast). Run `make build-time` for the clean " + "build measurement.") + return rc + + print(f"\nAM-5 / M-D2-BLD — clean release build on {AM5_MACHINE}") + host = subprocess.run(["hostname"], capture_output=True, text=True).stdout.strip() + if host != AM5_MACHINE: + print(f" NOTE: running on {host!r}, not {AM5_MACHINE!r} — the spec " + f"target is machine-specific, so this is directional only.") + for label, extra in (("dev toolchain (default features)", ()), + ("shipped runtime (--no-default-features)", + ("--no-default-features",))): + secs = clean_build_seconds(extra) + if secs is None: + print(f" ERROR — clean build failed: {label}", file=sys.stderr) + return 1 + mark = "ok " if secs <= AM5_MAX_SECONDS else "FAIL" + print(f" {label:<42} {secs:6.1f} s [{mark} target " + f"<= {AM5_MAX_SECONDS:.0f} s]") + print(" NOTE: reported, not gated — specs/GameKernel.md §5 declares AM-5") + print(" `recorded not gated`. Promoting it is a spec change and") + print(" needs an ADR; this tool does not promote itself.") + return rc + + +def self_test(): + """Each assertion pins a failure this tool must detect.""" + results = [] + + def check(name, cond, detail=""): + results.append((name, cond, detail)) + + check("targets are numeric and positive", + AM5_MAX_SECONDS > 0 and AM9_MAX_RSS_MB > 0, + f"AM-5 <= {AM5_MAX_SECONDS:.0f}s, AM-9 <= {AM9_MAX_RSS_MB:.0f}MB") + + binary = test_binary() + check("the release test binary is locatable", bool(binary), + os.path.basename(binary) if binary else "NOT FOUND") + + if binary: + # The control that matters: a filter matching no test must be + # detected, not scored as a very low RSS. This is the AM-6/AM-7 + # shape — a harness reporting a flattering number for work it + # never did. + _, ran = peak_rss_mb(binary, "no::such::test::name") + check("a test that did not run is detected, not scored", + not ran, "refusing to report RSS for work never done") + rss, ran_real = peak_rss_mb(binary) + check("the real workload runs and measures non-zero", + ran_real and rss > 1.0, f"{rss:.1f} MB") + + # The control for the bug this tool actually had: cross-validate + # against an independent implementation. getrusage(RUSAGE_CHILDREN) + # reported 38.2 MB where the workload used 12.3 MB, and only a + # second opinion revealed it. + gnu = shutil.which("time") or "/usr/bin/time" + if os.path.exists("/usr/bin/time"): + r = subprocess.run(["/usr/bin/time", "-v", binary, AM9_TEST, + "--exact"], cwd=ROOT, capture_output=True, + text=True) + m = re.search(r"Maximum resident set size \(kbytes\): (\d+)", + r.stdout + r.stderr) + if m: + indep = int(m.group(1)) / 1024.0 + near = abs(indep - rss) <= max(3.0, 0.25 * indep) + check("RSS agrees with an independent measurement", + near, f"ours {rss:.1f} MB vs /usr/bin/time {indep:.1f} MB") + + check("clean build measures into a throwaway target dir, not target/", + "CARGO_TARGET_DIR" in open(__file__).read() + and "shutil.rmtree" in open(__file__).read(), + "measuring must not destroy the working cache") + + print("runtime-metrics self-test (positive control)") + ok = True + for name, passed, det in results: + print(f" [{'ok ' if passed else 'FAIL'}] {name}" + + (f" — {det}" if det else "")) + ok &= passed + return 0 if ok else 1 + + +def main(): + enter_root() + if "--self-test" in sys.argv: + return self_test() + return report(fast="--fast" in sys.argv) + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/workplans/CB-WP-0006-instrument-the-table.md b/workplans/CB-WP-0006-instrument-the-table.md index 1775c43..be71397 100644 --- a/workplans/CB-WP-0006-instrument-the-table.md +++ b/workplans/CB-WP-0006-instrument-the-table.md @@ -182,6 +182,48 @@ argument**, which is a legitimate outcome and possibly the right one for AM-5 on a machine-dependent number. What is not legitimate is a third pass leaving them blank while the scoreboard reports elsewhere. +**Delivered — `tools/runtime-metrics.py`. One passes, one breaches.** + +**AM-9: met, and comfortably.** 13.4 MB peak RSS against a ≤64 MB target, +**4.8× headroom**. Gated and in `make all` (`--fast`, ~1 s). The row that +CB-EV-0001 called "very unlikely to bind" was right — but it is now +*measured* rather than assumed, and verified red by a property mutation +(a 300 MB allocation in the workload). + +**AM-5: BREACHED, on both readings, on the machine the spec names.** + +```text +dev toolchain (default features) 87.0 s [FAIL target <= 60 s] +shipped runtime (--no-default-features) 61.3 s [FAIL target <= 60 s] +``` + +Measured on `bnt-lap001`, 8 cores — the machine `specs/GameKernel.md` §5 +names, so this is a direct comparison, not a directional one. A row +declared `recorded not gated` and never recorded turns out, on first +measurement, to **fail its own target by 45%**. + +The tool **reports and exits 0**, because the spec says the row is not +gated. Gating it is a spec change and needs an ADR; a tool that promotes +itself is how a target starts binding without anyone deciding it should. +So AM-5 stays `unmutatable` — for the accurate reason now — and the breach +is **raised as a maintainer decision**, not resolved here. Three honest +options: speed the build, move the target by ADR (arguing why 60 s was +wrong rather than why 87 s is convenient), or withdraw the row. + +**The measurement had a real bug, found by cross-validation.** +`getrusage(RUSAGE_CHILDREN)` is a high-water mark across *every* reaped +child, so it attributed `cargo`'s memory to the workload and reported +**38.2 MB for a run that used 12.3 MB** — a 3× over-report. Fixed with +`os.wait4`, which returns that specific child's rusage. The self-test now +**cross-checks against `/usr/bin/time -v`** (13.4 vs 12.4 MB), which is +the only reason the bug was visible at all: the wrong number was +plausible, passed its target, and would have been published. + +That is FA in the measurement layer rather than the mutation layer — an +instrument confidently reporting a number it had not earned. + +**M-D1-MUT: 6 → 7 of 14.** + ## Task: AM-4c — target it or drop it ```task