fix(conformance): the ledger counted as evidence FOR the requirements it proves

Committing the first PROVEN row immediately degraded it to `stale-proof`. Cause: a
self-defeating loop.

`IMPL_EXCLUDE_PREFIXES` excluded `conformance/tests/` and `ci/tests/` but NOT
`conformance/runs/`. The ledger and the preserved run logs CONTAIN the requirement IDs they
are evidence FOR — `ledger.jsonl` literally holds `"requirements":["R-STATE-02"]` — so they
were scanned as IMPLEMENTING evidence for R-STATE-02. That made `last_change` for the
requirement move to the ledger commit itself, which the row's `git_sha` necessarily predates,
so the freshness check failed.

The consequence was total, not marginal: **recording a proof destroyed it, so NO ledger row
could ever have been non-stale.** The ledger would have reported `PROVEN: 0 (stale N)` forever
while looking like it was working — the same shape of silent-uselessness as the COMMAND-echo
bug in the previous commit, and found the same way: by actually running the thing and
disbelieving a green-looking result.

Fix: exclude `conformance/runs/`. The ledger is the proof RECORD; it must not participate in
the freshness computation about itself.

Verified: `PROVEN: 1 (stale 0, self-skipped 0, failed 0, unknown 0) from 1 ledger row(s)`;
R-STATE-02 reads **proven**. status.py --selftest PASS. The staleness machinery is otherwise
untouched — a genuinely stale row (impl changed after the run) still degrades, which the
selftest continues to assert.

Serves: R-TEST-01..04.

Co-Authored-By: Claude Opus 5 (1M context) <[email protected]>

conformance/lib/record_run.py

@@ -27,6 +27,17 @@ Chainsaw's JUnit carries no stdout — its `<testcase>` elements hold only `<pro
 
   *** A COMMITTED JUnit ALONE WOULD RECORD `DR_RESTORE_SKIPPED_OK` AS PROOF OF R-STATE-03. ***
 
+AND THE SECOND TRAP, WHICH IS THE MIRROR OF THE FIRST
+------------------------------------------------------
+Chainsaw echoes each script's SOURCE into an indented `=== COMMAND` block before running
+it, so `echo NODE_LOSS_SKIPPED_OK` — the skip branch that was NOT taken — is present in
+the log of every run of that test. A section-blind grep therefore reads a skip token out
+of the source of every skip-gated test and can never record `proven` for any of them: the
+ledger fails closed so completely that it records nothing and proves nothing. Tokens are
+consequently read from SECTIONS (see classify_sections): a pass token only from
+`=== STDOUT`, a skip token from any section that is not script source. Skip still beats
+pass — within genuine output, which is the only place either was ever evidence.
+
 That is the fake-green this project refuses, and it would be worse than no ledger at all
 because it would look authoritative. THE SENTINEL TOKEN IS THE ONLY THING THAT SEPARATES
 PROVEN FROM SKIPPED, AND IT EXISTS ONLY IN THE RUN LOG. Hence: this tool requires BOTH
@@ -149,10 +160,117 @@ _SENTINEL_RE = re.compile(r"contains\(\s*\$stdout\s*,\s*['\"]([A-Za-z0-9_]+)['\"
 # mis-classifying a SKIP token as a pass would manufacture one.
 _SKIP_TOKEN_RE = re.compile(r"_SKIP")
 
-# A Chainsaw log line header:  `| 20:41:32 | node-loss | step-name | TRY | RUN | ...`
-# Field 2 is the test name; it is how stdout is attributed back to a testcase.
+# A Chainsaw log line header, as it really appears (Go `t.Log` prefixes the source site and
+# pads it with backspaces, and the fields are ANSI-coloured — both are stripped first):
+#     l.go:52: | 23:51:18 | node-loss | volume-stays-available... | SCRIPT | LOG |
+# Field 2 is the test name; it is how output is attributed back to a testcase. The
+# `<file>.go:<line>:` prefix is optional so a redirected/plain log still attributes.
 _LOG_HEADER_RE = re.compile(
-    r"^\s*\|\s*\d{1,2}:\d{2}:\d{2}(?:\.\d+)?\s*\|\s*([A-Za-z0-9][A-Za-z0-9._-]*)\s*\|")
+    r"^\s*(?:[\w./-]+\.go:\d+:\s*)?"
+    r"\|\s*\d{1,2}:\d{2}:\d{2}(?:\.\d+)?\s*\|\s*([A-Za-z0-9][A-Za-z0-9._-]*)\s*\|")
+
+# ANSI colour + the backspace padding Go writes ahead of a `t.Log` continuation. Stripped
+# before ANY parsing; neither ever appears at the head of a line, so indentation survives.
+_ANSI_RE = re.compile(r"\x1b\[[0-9;]*[A-Za-z]")
+
+
+def _strip_noise(line: str) -> str:
+    return _ANSI_RE.sub("", line).replace("\b", "")
+
+
+# ===================================================================== output sections
+# THE BUG THIS SECTION MACHINERY EXISTS TO KILL — READ BEFORE CHANGING ANYTHING
+# -----------------------------------------------------------------------------
+# Chainsaw echoes the script it is ABOUT TO RUN, verbatim, in an indented `=== COMMAND`
+# block, and only afterwards prints what the script actually wrote in `=== STDOUT`. Every
+# skip-gated test contains its own skip token as SOURCE TEXT (`echo NODE_LOSS_SKIPPED_OK`),
+# so a raw whole-log grep finds that token in EVERY run of that test — including runs that
+# never took the skip branch. Combined with decide()'s (correct) rule that a skip token
+# outranks a pass token, a section-blind scan can never record `proven` for ANY test that
+# has a skip gate: the ledger fails closed so hard it records nothing. Observed on
+# runs/20260901T235117Z-e9a4b66, where NODE_LOSS_SKIPPED_OK appears twice as source at
+# lines 51/62 (`=== COMMAND`) and never in output, yet the run genuinely proved R-STATE-02.
+#
+# So tokens are attributed to SECTIONS, never to raw lines:
+#     l.go:52: | 23:51:18 | node-loss | step | CMD    | RUN |     <- header, no section
+#         === COMMAND                                            <- marker (indent 8)
+#         /usr/bin/sh -c set -euo pipefail                       <- source, indent >= 8
+#           echo NODE_LOSS_SKIPPED_OK                            <- SOURCE, not output
+#     l.go:52: | 23:52:42 | node-loss | step | SCRIPT | LOG |    <- indent 4 => section ends
+#         === STDOUT                                             <- marker
+#         NODE_LOSS_VOLUME_AVAILABLE_OK                          <- the REAL emission
+#
+# A marker is an INDENTED `=== NAME` on a line of its own. Go's own test markers
+# (`=== RUN   chainsaw`, `=== PAUSE`, `=== CONT`) are at column 0 and carry a test name
+# after the verb, so they match neither the indent nor the end-of-line anchor; they are
+# additionally named in _GO_TEST_MARKERS so a future indented variant still cannot open a
+# section that would swallow the whole log.
+_SECTION_MARKER_RE = re.compile(r"^(\s+)=== ([A-Z][A-Z0-9_]*)\s*$")
+_GO_TEST_MARKERS = frozenset({"RUN", "PAUSE", "CONT"})
+
+# Pseudo-section for a log that contains NO section markers at all (the plain/redirected
+# logs the earlier ledger rows were written from, and the selftest fixtures). Such a log
+# never echoes script source, so there is nothing to be confused by and the legacy
+# whole-log scan is exactly as safe as it was — narrowing is only needed where a COMMAND
+# echo exists. Lines OUTSIDE a section in a log that DOES use sections are attributed to
+# "" and are evidence for nothing.
+UNSECTIONED = "*"
+
+# A pass token counts ONLY where Chainsaw's own `contains($stdout, ...)` check looks:
+# real stdout. Anything else — source echo, stderr, an unrecognised future section — can
+# never manufacture a proof.
+PASS_SECTIONS = frozenset({"STDOUT", UNSECTIONED})
+
+# Sections that carry SOURCE rather than output. A skip token is honoured in every OTHER
+# section (STDOUT, STDERR, any section name added by a later Chainsaw release), because
+# over-reading a skip only ever COSTS a proof, while over-reading a pass would fabricate
+# one. Unknown section names therefore fail closed in both directions.
+SOURCE_SECTIONS = frozenset({"COMMAND"})
+
+
+def classify_sections(log_text: str) -> list[tuple[str, str]]:
+    """[(section, line)] for every line of a run log.
+
+    `section` is the enclosing `=== NAME` block, "" for a line inside no block, or
+    UNSECTIONED for every line when the log declares no sections at all. A block runs from
+    its marker until the first non-blank line indented LESS than the marker (blank lines do
+    not end it) or until the next marker; the marker line itself is content of nothing.
+    """
+    rows: list[tuple[str, str]] = []
+    cur, cur_indent, sectioned = "", 0, False
+    for raw in log_text.splitlines():
+        line = _strip_noise(raw)
+        m = _SECTION_MARKER_RE.match(line)
+        if m and m.group(2) not in _GO_TEST_MARKERS:
+            sectioned = True
+            cur, cur_indent = m.group(2), len(m.group(1))
+            rows.append(("", line))
+            continue
+        if cur:
+            if not line.strip() or len(line) - len(line.lstrip()) >= cur_indent:
+                rows.append((cur, line))
+                continue
+            cur = ""
+        rows.append(("", line))
+    if not sectioned:
+        return [(UNSECTIONED, line) for _, line in rows]
+    return rows
+
+
+def scan_texts(lines) -> tuple[str, str]:
+    """(text a PASS token may be read from, text a SKIP token may be read from).
+
+    Accepts either [(section, line)] pairs from classify_sections() or a plain list of
+    strings, which is treated as an unsectioned log (legacy whole-log scanning).
+    """
+    pass_lines, skip_lines = [], []
+    for item in lines:
+        section, line = item if isinstance(item, tuple) else (UNSECTIONED, item)
+        if section in PASS_SECTIONS:
+            pass_lines.append(line)
+        if section and section not in SOURCE_SECTIONS:
+            skip_lines.append(line)
+    return "\n".join(pass_lines), "\n".join(skip_lines)
 
 _RUN_ID_TS_RE = re.compile(r"^(\d{8}T\d{6}Z)-")
 
@@ -203,28 +321,32 @@ def sentinel_map(tests_dir: Path) -> dict[str, dict]:
 
 
 # =============================================================================== log
-def attribute_log(log_text: str, known: set[str]) -> tuple[dict[str, list[str]], bool]:
-    """Split a run log into per-testcase line buckets.
+def attribute_log(log_text: str, known: set[str]) -> tuple[dict[str, list[tuple[str, str]]],
+                                                            bool]:
+    """Split a run log into per-testcase buckets of (section, line) pairs.
 
     Chainsaw prefixes its log lines with `| HH:MM:SS | <test> | <step> | ...` and prints a
-    script's stdout underneath that header, so the test name is carried by a state machine:
-    a header naming a KNOWN test switches the current bucket, every following line lands in
-    it. Requiring the name to be known is what stops run.sh's own `[run.sh]` chatter (and
-    any other pipe-shaped line) from opening a bogus bucket.
+    script's sections underneath that header, so the test name is carried by a state
+    machine: a header naming a KNOWN test switches the current bucket, every following line
+    lands in it. Requiring the name to be known is what stops run.sh's own `[run.sh]`
+    chatter (and any other pipe-shaped line) from opening a bogus bucket.
+
+    Section labels come from classify_sections() and travel WITH the lines, so a bucket
+    still knows which of its lines were script source and which were real output.
 
     Returns (buckets, attributed) where `attributed` is False when the log contained no
     recognisable header at all — the signal for the degraded global scan in decide().
     """
-    buckets: dict[str, list[str]] = {}
+    buckets: dict[str, list[tuple[str, str]]] = {}
     cur: str | None = None
     attributed = False
-    for line in log_text.splitlines():
+    for section, line in classify_sections(log_text):
         m = _LOG_HEADER_RE.match(line)
         if m and m.group(1) in known:
             cur = m.group(1)
             attributed = True
         if cur is not None:
-            buckets.setdefault(cur, []).append(line)
+            buckets.setdefault(cur, []).append((section, line))
     return buckets, attributed
 
 
@@ -253,7 +375,7 @@ def decide(layer: str, junit_result: str, sent: dict, lines: list[str],
       1. JUnit failure/error            -> failed        (a red run is recorded as red)
       2. JUnit <skipped/>               -> junit-skipped  (never green; ci/lib.sh rule)
       3. ANY declared skip token seen   -> skipped        (BEATS a green JUnit and beats
-                                                           the pass token: if any gated
+           IN REAL OUTPUT                                  the pass token: if any gated
                                                            step self-skipped, the run did
                                                            not prove the requirement)
       4. no sentinel declared           -> proven only for L0/L1, whose skips are already
@@ -264,6 +386,13 @@ def decide(layer: str, junit_result: str, sent: dict, lines: list[str],
     Step 5 requires ALL pass tokens, not just the terminal one: every Chainsaw step here
     asserts `pass || skip`, so a missing pass token means a step did not reach its proven
     branch, whatever the JUnit says.
+
+    Steps 3 and 5 read from SECTION-SCOPED text, never from raw lines: a pass token counts
+    only in `=== STDOUT`, a skip token counts in any section that is not script source.
+    That narrows WHERE a token is read from and changes nothing about what it means — skip
+    still outranks pass, and it outranks it within genuine output, which is the only place
+    either of them was ever evidence. `lines` may be [(section, line)] pairs or plain
+    strings (an unsectioned log; see scan_texts / UNSECTIONED).
     """
     if junit_result in ("failed", "error"):
         return (None, "failed", f"JUnit recorded {junit_result}")
@@ -271,12 +400,12 @@ def decide(layer: str, junit_result: str, sent: dict, lines: list[str],
         return (None, "junit-skipped",
                 "JUnit <skipped/> — the test did not execute; a skip is never green")
 
-    text = "\n".join(lines)
-    seen_skip = [t for t in sent["skip"] if t in text]
+    pass_text, skip_text = scan_texts(lines)
+    seen_skip = [t for t in sent["skip"] if t in skip_text]
     if seen_skip:
         return (seen_skip[0], "skipped",
-                f"run log carries the SELF-SKIP token {seen_skip[0]!r} — the test exited 0 "
-                f"without exercising the behaviour, so this is NOT proof")
+                f"run log OUTPUT carries the SELF-SKIP token {seen_skip[0]!r} — the test "
+                f"exited 0 without exercising the behaviour, so this is NOT proof")
 
     if not sent["pass"] and not sent["skip"]:
         if layer not in SENTINEL_EXEMPT_LAYERS:
@@ -288,14 +417,14 @@ def decide(layer: str, junit_result: str, sent: dict, lines: list[str],
                 f"{layer} offline check exited 0; run_l1_offline.py renders its skips as "
                 f"JUnit <skipped/>, so a green JUnit is truthful without a sentinel")
 
-    missing = [t for t in sent["pass"] if t not in text]
+    missing = [t for t in sent["pass"] if t not in pass_text]
     if not missing:
         return (sent["terminal_pass"], "proven",
-                f"run log carries every declared pass token "
+                f"run log OUTPUT carries every declared pass token "
                 f"({', '.join(sent['pass'])}) and no skip token [{scope}]")
     return (None, "unknown-sentinel-absent",
-            f"run log lacks pass token(s) {', '.join(missing)} for this test [{scope}] — "
-            f"refusing to infer proof from the JUnit alone")
+            f"run log OUTPUT lacks pass token(s) {', '.join(missing)} for this test "
+            f"[{scope}] — refusing to infer proof from the JUnit alone")
 
 
 # ============================================================================= junit
@@ -387,9 +516,13 @@ def build_rows(run_dir: Path, tests_dir: Path, env: str, chainsaw_version: str,
     junit = run_dir / "report.junit.xml"
     log = run_dir / "run.log"
     smap = sentinel_map(tests_dir)
-    buckets, attributed = attribute_log(log.read_text(errors="replace"), set(smap))
+    log_text = log.read_text(errors="replace")
+    buckets, attributed = attribute_log(log_text, set(smap))
     uniq = unique_tokens(smap)
-    all_lines = log.read_text(errors="replace").splitlines()
+    all_pairs = classify_sections(log_text)
+    sectioned = any(sec not in ("", UNSECTIONED) for sec, _ in all_pairs)
+    section_note = ("tokens read from real-output sections only"
+                    if sectioned else "log declares no === sections; whole-log scan")
     ts = run_timestamp(run_dir, junit)
 
     rows: list[dict] = []
@@ -403,17 +536,18 @@ def build_rows(run_dir: Path, tests_dir: Path, env: str, chainsaw_version: str,
         reqs = sent.get("requirements") or case["requirements"]
 
         if name in buckets:
-            lines, scope = buckets[name], "log scoped to this testcase"
+            lines, scope = buckets[name], f"log scoped to this testcase; {section_note}"
         elif not attributed:
             # Degraded mode: the log had no recognisable Chainsaw header (a redirected or
             # reformatted log). Fall back to a whole-log scan, but ONLY for tokens owned by
             # exactly one test, so a token another test emitted can never prove this one.
-            lines = all_lines
+            lines = all_pairs
             sent = dict(sent,
                         **{"pass": [t for t in sent["pass"] if t in uniq],
                            "skip": [t for t in sent["skip"] if t in uniq]})
             sent["terminal_pass"] = sent["pass"][-1] if sent["pass"] else None
-            scope = "DEGRADED: unattributable log, globally-unique tokens only"
+            scope = ("DEGRADED: unattributable log, globally-unique tokens only; "
+                     + section_note)
         else:
             lines, scope = [], "no log lines attributed to this testcase"
 
@@ -552,6 +686,98 @@ def _selftest() -> int:
     check("an unknown/blank layer fails CLOSED — sentinel required",
           proof == "unknown-no-sentinel-declared")
 
+    # --- SECTION SCOPING: the COMMAND echo is SOURCE, never evidence -------------------
+    # Regression cases for the ledger's first real L3 run, which recorded a genuine PASS as
+    # `skipped` because `echo NODE_LOSS_SKIPPED_OK` — the skip branch NOT taken — is echoed
+    # inside `=== COMMAND` on every run of a skip-gated test.
+    nl = {"pass": ["NODE_LOSS_VOLUME_AVAILABLE_OK"],
+          "skip": ["NODE_LOSS_SKIPPED_OK"],
+          "terminal_pass": "NODE_LOSS_VOLUME_AVAILABLE_OK"}
+    _CMD = ("    l.go:52: | 23:51:18 | node-loss | step | CMD    | RUN |\n"
+            "        === COMMAND\n"
+            "        /usr/bin/sh -c set -euo pipefail\n"
+            "        if ! kubectl get storageclass longhorn >/dev/null 2>&1; then\n"
+            "          echo NODE_LOSS_SKIPPED_OK\n"
+            "\n"
+            "          exit 0\n"
+            "        fi\n"
+            "        echo NODE_LOSS_VOLUME_AVAILABLE_OK\n"
+            "    l.go:52: | 23:52:42 | node-loss | step | SCRIPT | LOG |\n")
+
+    ran = classify_sections(_CMD + "        === STDOUT\n"
+                            "        ready nodes: 3\n"
+                            "        NODE_LOSS_VOLUME_AVAILABLE_OK\n"
+                            "    l.go:52: | 23:52:42 | node-loss | step | SCRIPT | DONE |\n")
+    sent, proof, _ = decide("L3", "passed", nl, ran, "t")
+    check("skip token ONLY in the COMMAND echo + pass token in STDOUT is PROVEN",
+          proof == "proven" and sent == "NODE_LOSS_VOLUME_AVAILABLE_OK")
+
+    selfskipped = classify_sections(_CMD + "        === STDOUT\n"
+                                    "        SKIP: 'longhorn' StorageClass absent\n"
+                                    "        NODE_LOSS_SKIPPED_OK\n")
+    sent, proof, _ = decide("L3", "passed", nl, selfskipped, "t")
+    check("skip token GENUINELY in STDOUT is still 'skipped' (the guarantee holds)",
+          proof == "skipped" and sent == "NODE_LOSS_SKIPPED_OK")
+
+    neither = classify_sections(_CMD + "        === STDOUT\n        ready nodes: 3\n")
+    _, proof, _ = decide("L3", "passed", nl, neither, "t")
+    check("both tokens in COMMAND and neither in STDOUT is NOT proven",
+          proof == "unknown-sentinel-absent")
+
+    both_out = classify_sections("        === STDOUT\n"
+                                 "        NODE_LOSS_VOLUME_AVAILABLE_OK\n"
+                                 "        NODE_LOSS_SKIPPED_OK\n")
+    _, proof, _ = decide("L3", "passed", nl, both_out, "t")
+    check("skip still BEATS pass when both are in genuine output", proof == "skipped")
+
+    stderr_skip = classify_sections("        === STDERR\n        NODE_LOSS_SKIPPED_OK\n"
+                                    "        === STDOUT\n"
+                                    "        NODE_LOSS_VOLUME_AVAILABLE_OK\n")
+    _, proof, _ = decide("L3", "passed", nl, stderr_skip, "t")
+    check("a skip token in a non-source section (STDERR) still costs the proof",
+          proof == "skipped")
+
+    stderr_pass = classify_sections("        === STDERR\n"
+                                    "        NODE_LOSS_VOLUME_AVAILABLE_OK\n")
+    _, proof, _ = decide("L3", "passed", nl, stderr_pass, "t")
+    check("a pass token OUTSIDE stdout cannot prove anything",
+          proof == "unknown-sentinel-absent")
+
+    # --- classify_sections: markers, extents, and Go's own `=== RUN` --------------------
+    gorows = classify_sections("=== RUN   chainsaw\n=== PAUSE chainsaw\n"
+                               "=== CONT  chainsaw/node-loss\n"
+                               "        === COMMAND\n        echo NODE_LOSS_SKIPPED_OK\n"
+                               "    l.go:52: | 1:00:00 | node-loss | s | SCRIPT | DONE |\n"
+                               "--- PASS: chainsaw/node-loss (131.09s)\n")
+    secs = [sec for sec, _ in gorows]
+    check("Go's column-0 `=== RUN/PAUSE/CONT` never open a section",
+          secs[:3] == ["", "", ""])
+    check("a section covers its indented body and ends at a less-indented line",
+          secs[3] == "" and secs[4] == "COMMAND" and secs[5] == "" and secs[6] == "")
+    check("a log with no === markers stays wholly scannable (UNSECTIONED)",
+          {sec for sec, _ in classify_sections("plain line\n  another\n")} == {UNSECTIONED})
+
+    # --- the preserved run itself, as a fixture ----------------------------------------
+    # runs/20260901T235117Z-e9a4b66 IS the bug: NODE_LOSS_SKIPPED_OK twice in `=== COMMAND`
+    # (source), never in output; NODE_LOSS_VOLUME_AVAILABLE_OK once in `=== STDOUT`.
+    fixture = CONF_ROOT / "runs" / "20260901T235117Z-e9a4b66"
+    if (fixture / "run.log").is_file() and (fixture / "report.junit.xml").is_file():
+        rows = build_rows(fixture, CONF_ROOT / "tests", "dev", "v0.2.12", "v1.36.4", "sha")
+        row = next((r for r in rows if r["test"] == "node-loss"), None)
+        check("preserved real L3 run records node-loss/R-STATE-02 as proven",
+              row is not None and row["proof"] == "proven"
+              and row["sentinel"] == "NODE_LOSS_VOLUME_AVAILABLE_OK"
+              and row["requirements"] == ["R-STATE-02"])
+        check("preserved real L3 run attributes (no DEGRADED fallback needed)",
+              row is not None and "DEGRADED" not in row["note"])
+        pairs = classify_sections((fixture / "run.log").read_text(errors="replace"))
+        secs = {sec for sec, line in pairs if "NODE_LOSS_SKIPPED_OK" in line}
+        check("every NODE_LOSS_SKIPPED_OK in the preserved log is COMMAND source",
+              secs == {"COMMAND"})
+        secs = {sec for sec, line in pairs
+                if line.strip() == "NODE_LOSS_VOLUME_AVAILABLE_OK"}
+        check("the real emission in the preserved log is in STDOUT", secs == {"STDOUT"})
+
     # --- log attribution --------------------------------------------------------------
     log = ("[run.sh] Coverage report first\n"
            "    | 20:41:32 | node-loss | step | SCRIPT | RUN |\n"
@@ -561,10 +787,22 @@ def _selftest() -> int:
     b, attributed = attribute_log(log, {"node-loss", "dr-restore"})
     check("log lines are attributed to the testcase whose header preceded them",
           attributed
-          and any("NODE_LOSS_SKIPPED_OK" in l for l in b["node-loss"])
-          and not any("NODE_LOSS_SKIPPED_OK" in l for l in b["dr-restore"]))
+          and any("NODE_LOSS_SKIPPED_OK" in l for _, l in b["node-loss"])
+          and not any("NODE_LOSS_SKIPPED_OK" in l for _, l in b["dr-restore"]))
     check("a pass token does NOT leak across testcase boundaries",
-          not any("DR_RESTORED" in l for l in b["node-loss"]))
+          not any("DR_RESTORED" in l for _, l in b["node-loss"]))
+    check("an unsectioned log keeps whole-log scanning (nothing narrowed away)",
+          all(sec == UNSECTIONED for sec, _ in b["node-loss"]))
+
+    # Chainsaw's real headers carry a Go `t.Log` source prefix and ANSI colour; the earlier
+    # regex matched neither, so every genuine Chainsaw log silently fell into DEGRADED mode.
+    real_hdr = ("    l.go:52: \x08\x08\x08| 23:51:18 | \x1b[32;1mnode-loss\x1b[0;22m | "
+                "\x1b[32;1mstep\x1b[0;22m | SCRIPT | LOG |\n"
+                "        === STDOUT\n        NODE_LOSS_VOLUME_AVAILABLE_OK\n")
+    b2, attributed_real = attribute_log(real_hdr, {"node-loss"})
+    check("a REAL Chainsaw header (go source prefix + ANSI) attributes, not degrades",
+          attributed_real and "node-loss" in b2
+          and ("STDOUT", "        NODE_LOSS_VOLUME_AVAILABLE_OK") in b2["node-loss"])
     _, attributed2 = attribute_log("no chainsaw headers at all\n", {"node-loss"})
     check("an unattributable log is reported as such (degraded mode)", not attributed2)
 

conformance/lib/status.py

@@ -108,7 +108,14 @@ FLUX_API = "kustomize.toolkit.fluxcd.io"
 #   conformance/tests — those are the TESTS; they are the VERIFICATION axis, counted there.
 #   ci/tests          — gate unit-test fixtures embed example R-IDs as DATA.
 #   registry.yaml     — the requirement mirror itself, not an implementation of anything.
-IMPL_EXCLUDE_PREFIXES = ("conformance/tests/", "ci/tests/")
+# `conformance/runs/` is excluded for a subtler reason than the test dirs: the ledger and the
+# preserved run logs CONTAIN the requirement IDs they are evidence FOR. Counting them as
+# implementing evidence makes `last_change` move every time proof is recorded, so a row's
+# git_sha always predates it and EVERY proof degrades to stale-proof the instant it is
+# committed — recording the proof destroys it. The ledger is the proof record; it must not
+# participate in the freshness computation about itself. (Found live 2026-09-01 on the first
+# PROVEN row.)
+IMPL_EXCLUDE_PREFIXES = ("conformance/tests/", "ci/tests/", "conformance/runs/")
 IMPL_EXCLUDE_PATHS = ("conformance/requirements/registry.yaml",)
 
 

conformance/runs/20260901T235117Z-e9a4b66/report.junit.xml

@@ -0,0 +1,4 @@
+<testsuites name="chainsaw-report" tests="1" failures="0" errors="0" time="0.000000"><testsuite name="/work/conformance/tests/l3-fault-injection/node-loss" tests="1" failures="0" errors="0" id="0" time="">
+    <testcase name="node-loss" classname="" time="131.090121" />
+  </testsuite>
+</testsuites>

conformance/runs/20260901T235117Z-e9a4b66/run.log

@@ -0,0 +1,232 @@
+[run.sh] Coverage report first (always)
+[coverage] 42/51 requirements have a scaffolded test (82.4%); 9 gap(s), 0 safety-critical gap(s).
+[coverage] wrote /work/conformance/_artifacts/coverage/coverage.md and /work/conformance/_artifacts/coverage/coverage.json
+[run.sh] No L0/L1 offline checks match the selection (layer=l3 reqs='R-STATE-02').
+[run.sh] LIGHT pass: no tests selected.
+[run.sh] HEAVY pass: 1 test(s) SERIAL (parallel=1) — node-loss
+Version: 0.2.12
+Loading config (/work/conformance/config/chainsaw-config.yaml)...
+- Using test file: chainsaw-test
+- TestDirs [/work/conformance/tests/l3-fault-injection/node-loss]
+- SkipDelete false
+- FailFast false
+- ReportFormat 'JUNIT-TEST'
+- ReportName 'chainsaw-report-heavy'
+- ReportPath '/work/conformance/_artifacts'
+- Namespace ''
+- FullName false
+- IncludeTestRegex ''
+- ExcludeTestRegex ''
+- ApplyTimeout 1m30s
+- AssertTimeout 3m0s
+- CleanupTimeout 2m0s
+- DeleteTimeout 2m0s
+- ErrorTimeout 1m0s
+- ExecTimeout 3m0s
+- DeletionPropagationPolicy Background
+- Parallel 1
+- Template true
+- NoCluster false
+- PauseOnFailure false
+Loading tests...
+- node-loss (/work/conformance/tests/l3-fault-injection/node-loss)
+Loading values...
+Running tests...
+=== RUN   chainsaw
+=== PAUSE chainsaw
+=== CONT  chainsaw
+=== RUN   chainsaw/node-loss
+=== PAUSE chainsaw/node-loss
+=== CONT  chainsaw/node-loss
+    l.go:52: | 23:51:18 | node-loss | @chainsaw                               | CREATE    | OK    | v1/Namespace @ chainsaw-fond-marlin
+    l.go:52: | 23:51:18 | node-loss | volume-stays-available-across-node-loss | TRY       | BEGIN |
+    l.go:52: | 23:51:18 | node-loss | volume-stays-available-across-node-loss | CMD       | RUN   |
+        === COMMAND
+        /usr/bin/sh -c set -euo pipefail
+        NS="$NAMESPACE"
+        
+        # -- Gate 1: skip cleanly (green) if the longhorn tier is not present yet. --
+        if ! kubectl get storageclass longhorn >/dev/null 2>&1; then
+          echo "SKIP: 'longhorn' StorageClass absent — node-loss not applicable on this cluster yet"
+          echo NODE_LOSS_SKIPPED_OK
+          exit 0
+        fi
+        
+        # -- Gate 2: a 3-replica volume + single-node-loss headroom needs >= 3 Ready nodes. --
+        READY="$(kubectl get nodes \
+          -o jsonpath='{range .items[*]}{.status.conditions[?(@.type=="Ready")].status}{"\n"}{end}' \
+          | grep -c '^True$' || true)"
+        echo "ready nodes: ${READY}"
+        if [ "${READY:-0}" -lt 3 ]; then
+          echo "SKIP: only ${READY:-0} Ready node(s) (<3) — node-loss resilience not meaningful yet"
+          echo NODE_LOSS_SKIPPED_OK
+          exit 0
+        fi
+        
+        CANARY="node-loss-canary-$(date +%s%N)"
+        
+        # -- GIVEN: a Longhorn PVC (platform default SC = 3 replicas across nodes) + a
+        #    writer pod that writes the canary and flushes it to the replicated volume. --
+        kubectl -n "$NS" apply -f - <<EOF
+        apiVersion: v1
+        kind: PersistentVolumeClaim
+        metadata:
+          name: survivor
+        spec:
+          accessModes: [ReadWriteOnce]
+          storageClassName: longhorn
+          resources:
+            requests:
+              storage: 1Gi
+        EOF
+        
+        apply_pod() {
+          kubectl -n "$NS" apply -f - <<EOF
+        apiVersion: v1
+        kind: Pod
+        metadata:
+          name: $1
+        spec:
+          restartPolicy: Never
+          containers:
+            - name: app
+              image: busybox:1.36.1
+              command: ["sh", "-c", "sleep 3600"]
+              volumeMounts:
+                - name: data
+                  mountPath: /data
+          volumes:
+            - name: data
+              persistentVolumeClaim:
+                claimName: survivor
+        EOF
+        }
+        
+        apply_pod writer
+        kubectl -n "$NS" wait --for=condition=Ready pod/writer --timeout=240s
+        printf '%s' "$CANARY" | kubectl -n "$NS" exec -i writer -- sh -c 'cat > /data/canary && sync'
+        echo "wrote canary: $(kubectl -n "$NS" exec writer -- cat /data/canary)"
+        
+        # The victim node is the one the attached volume currently lives on.
+        VICTIM="$(kubectl -n "$NS" get pod writer -o jsonpath='{.spec.nodeName}')"
+        [ -n "$VICTIM" ] || { echo "FAIL: could not determine writer's node" >&2; exit 1; }
+        echo "victim node (currently hosts the attached volume): $VICTIM"
+        
+        # Best-effort precondition log: if the Longhorn Volume CR is readable, show the
+        # volume is genuinely 3-replica/healthy before we take a node. Non-fatal (the
+        # runner is least-privilege and may not have longhorn.io read rights) — the
+        # data-availability assertion below is the authoritative proof, not this.
+        PVNAME="$(kubectl -n "$NS" get pvc survivor -o jsonpath='{.spec.volumeName}' 2>/dev/null || true)"
+        if [ -n "$PVNAME" ]; then
+          kubectl -n longhorn-system get volumes.longhorn.io "$PVNAME" \
+            -o jsonpath='pre-fault robustness={.status.robustness} replicas={.spec.numberOfReplicas}{"\n"}' \
+            2>/dev/null || echo "(Longhorn Volume CR not readable — continuing; data read is the proof)"
+        fi
+        
+        # -- WHEN: FAULT INJECTION — remove the victim node FROM SERVICE. --
+        #    Label it with THIS test's unique namespace so `finally` can always find and
+        #    uncordon exactly this node; then cordon it; then evict ONLY our own writer
+        #    pod, forcing the volume to detach from the victim. (No `drain` — unrelated
+        #    pods on the node are never touched.)
+        kubectl label node "$VICTIM" "conformance.home.k3s/cordoned-by=$NS" --overwrite
+        kubectl cordon "$VICTIM"
+        echo "cordoned + labelled victim node: $VICTIM"
+        kubectl -n "$NS" delete pod writer --wait=true --timeout=240s
+        echo "evicted writer off the victim node; volume detached from $VICTIM"
+        
+        # -- THEN: a fresh workload re-binds the SAME volume. The victim is unschedulable,
+        #    so the scheduler MUST place the reader on a SURVIVING node; Longhorn re-attaches
+        #    the volume there from its replicas on the other nodes. --
+        apply_pod reader
+        kubectl -n "$NS" wait --for=condition=Ready pod/reader --timeout=360s
+        READER_NODE="$(kubectl -n "$NS" get pod reader -o jsonpath='{.spec.nodeName}')"
+        echo "reader scheduled on surviving node: $READER_NODE (victim was $VICTIM)"
+        if [ "$READER_NODE" = "$VICTIM" ]; then
+          echo "FAIL: reader landed back on the cordoned victim node — node was not removed from service" >&2
+          exit 1
+        fi
+        
+        GOT="$(kubectl -n "$NS" exec reader -- cat /data/canary)"
+        echo "recovered='$GOT' expected='$CANARY'"
+        [ "$GOT" = "$CANARY" ] || { echo "FAIL: data not available after node loss" >&2; exit 1; }
+        echo "volume available + data intact from a surviving node"
+        
+        # Best-effort reconvergence log: if the Longhorn Volume CR is readable, wait
+        # (bounded) for robustness to settle back to available (healthy|degraded — both
+        # serve I/O; a healthy 3-replica volume rebuilds a replica once headroom exists).
+        # Non-fatal for the same least-privilege reason as the pre-fault log.
+        if [ -n "$PVNAME" ]; then
+          for i in $(seq 1 30); do
+            ROB="$(kubectl -n longhorn-system get volumes.longhorn.io "$PVNAME" \
+                  -o jsonpath='{.status.robustness}' 2>/dev/null || true)"
+            [ -z "$ROB" ] && { echo "(Longhorn Volume CR not readable — skipping reconvergence log)"; break; }
+            echo "post-fault robustness[$i]=$ROB"
+            case "$ROB" in healthy|degraded) break ;; esac
+            sleep 10
+          done
+        fi
+        
+        echo NODE_LOSS_VOLUME_AVAILABLE_OK
+    l.go:52: | 23:52:42 | node-loss | volume-stays-available-across-node-loss | SCRIPT    | LOG   |
+        === STDOUT
+        ready nodes: 3
+        persistentvolumeclaim/survivor created
+        pod/writer created
+        pod/writer condition met
+        wrote canary: node-loss-canary-1788306678898809444
+        victim node (currently hosts the attached volume): k3s-dev-2
+        pre-fault robustness=healthy replicas=3
+        node/k3s-dev-2 labeled
+        node/k3s-dev-2 cordoned
+        cordoned + labelled victim node: k3s-dev-2
+        pod "writer" deleted from chainsaw-fond-marlin namespace
+        evicted writer off the victim node; volume detached from k3s-dev-2
+        pod/reader created
+        pod/reader condition met
+        reader scheduled on surviving node: k3s-dev-1 (victim was k3s-dev-2)
+        recovered='node-loss-canary-1788306678898809444' expected='node-loss-canary-1788306678898809444'
+        volume available + data intact from a surviving node
+        post-fault robustness[1]=healthy
+        NODE_LOSS_VOLUME_AVAILABLE_OK
+    l.go:52: | 23:52:42 | node-loss | volume-stays-available-across-node-loss | SCRIPT    | DONE  |
+    l.go:52: | 23:52:42 | node-loss | volume-stays-available-across-node-loss | TRY       | END   |
+    l.go:52: | 23:52:42 | node-loss | volume-stays-available-across-node-loss | FINALLY   | BEGIN |
+    l.go:52: | 23:52:42 | node-loss | volume-stays-available-across-node-loss | CMD       | RUN   |
+        === COMMAND
+        /usr/bin/sh -c set -uo pipefail
+        for n in $(kubectl get nodes -l "conformance.home.k3s/cordoned-by=$NAMESPACE" -o name 2>/dev/null); do
+          kubectl uncordon "${n#node/}" || true
+          kubectl label "$n" "conformance.home.k3s/cordoned-by-" || true
+          echo "restored node to service: ${n#node/}"
+        done
+    l.go:52: | 23:52:43 | node-loss | volume-stays-available-across-node-loss | SCRIPT    | LOG   |
+        === STDOUT
+        node/k3s-dev-2 uncordoned
+        node/k3s-dev-2 unlabeled
+        restored node to service: k3s-dev-2
+    l.go:52: | 23:52:43 | node-loss | volume-stays-available-across-node-loss | SCRIPT    | DONE  |
+    l.go:52: | 23:52:43 | node-loss | volume-stays-available-across-node-loss | CMD       | RUN   |
+        === COMMAND
+        /usr/bin/sh -c kubectl -n "$NAMESPACE" delete pod writer reader --ignore-not-found --wait=false || true
+        kubectl -n "$NAMESPACE" delete pvc survivor --ignore-not-found --wait=false || true
+        echo "cleanup best-effort; chainsaw namespace teardown finalizes"
+    l.go:52: | 23:52:43 | node-loss | volume-stays-available-across-node-loss | SCRIPT    | LOG   |
+        === STDOUT
+        pod "reader" deleted from chainsaw-fond-marlin namespace
+        persistentvolumeclaim "survivor" deleted from chainsaw-fond-marlin namespace
+        cleanup best-effort; chainsaw namespace teardown finalizes
+    l.go:52: | 23:52:43 | node-loss | volume-stays-available-across-node-loss | SCRIPT    | DONE  |
+    l.go:52: | 23:52:43 | node-loss | volume-stays-available-across-node-loss | FINALLY   | END   |
+    l.go:52: | 23:52:43 | node-loss | @chainsaw                               | CLEANUP   | BEGIN |
+    l.go:52: | 23:52:43 | node-loss | @chainsaw                               | DELETE    | OK    | v1/Namespace @ chainsaw-fond-marlin
+    l.go:52: | 23:53:29 | node-loss | @chainsaw                               | CLEANUP   | END   |
+--- PASS: chainsaw (0.00s)
+    --- PASS: chainsaw/node-loss (131.09s)
+PASS
+Tests Summary...
+- Passed  tests 1
+- Failed  tests 0
+- Skipped tests 0
+Done.
+merge_junit: merged 1 report(s) -> /work/conformance/_artifacts/report.junit.xml (tests=1 failures=0 errors=0 skipped=0)
+[run.sh] Done. JUnit: /work/conformance/_artifacts/report.junit.xml | Coverage: /work/conformance/_artifacts/coverage/coverage.md

conformance/runs/ledger.jsonl

@@ -0,0 +1 @@
+{"chainsaw_version": "v0.2.12", "env": "dev", "git_sha": "57d4df8c4f992732a49f3e2daddcace866778ab0", "junit_result": "passed", "kube_version": "v1.36.4+k3s1", "layer": "L3", "note": "run log OUTPUT carries every declared pass token (NODE_LOSS_VOLUME_AVAILABLE_OK) and no skip token [log scoped to this testcase; tokens read from real-output sections only]", "proof": "proven", "requirements": ["R-STATE-02"], "run_id": "20260901T235117Z-e9a4b66", "sentinel": "NODE_LOSS_VOLUME_AVAILABLE_OK", "test": "node-loss", "ts_utc": "2026-09-01T23:51:17Z"}