CB-WP-0006 T03: measure AM-5 and AM-9; AM-5 breaches

AM-9 is met and gated: 13.4 MB peak RSS against a 64 MB target, 4.8x
headroom, in `make all` via --fast. CB-EV-0001's "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 is BREACHED on both readings, on the machine the spec names:

  dev toolchain (default features)        87.0 s  [FAIL target <= 60 s]
  shipped runtime (--no-default-features) 61.3 s  [FAIL target <= 60 s]

bnt-lap001, 8 cores — a direct comparison, not a directional one. A row
declared "recorded not gated" and never recorded fails its own target by
45% on first measurement.

The tool reports and exits 0 because the spec says the row is ungated.
Gating it is a spec change needing 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: 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 itself had a real bug, found only 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 3x over-report that was plausible, passed its
target, and would have been published. Fixed with os.wait4, which returns
that specific child's rusage, and the self-test now cross-checks against
/usr/bin/time -v.

That is the false-accusation shape in the measurement layer rather than
the mutation layer: an instrument confidently reporting a number it had
not earned.

Also: the clean build measures into a throwaway CARGO_TARGET_DIR rather
than running `cargo clean`, so measuring the metric does not cost several
minutes of rebuild afterwards. A metric that punishes its own measurement
gets measured once and never again.

M-D1-MUT: 6 -> 7 of 14.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

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

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"
 

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<u8> = 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` "

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())

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