Skip to content

Commit 191a2c0

Browse files
committed
Stop the matrix reporting verdicts on guards it could not measure
Two defects, both of which let a run state a result it had not established. Outcomes were inferred rather than read. Only the `FAILED` lines were parsed and every other named test was recorded as passed, so a skipped test, a test whose fixture raised, a deselected test and a test pytest never mentioned were all indistinguishable from a passing one — the confusion `failing_tests` already refuses for a whole suite, left open for a single test. With `-rA` each test states an outcome; anything that is not plainly passed or failed is now unclear, an unclear baseline records `no baseline` rather than proceeding to measure against a precondition never met, and an unclear guard-off run records `no verdict` rather than `does not discriminate`. The test's name was taken from the wrong end of the line. A summary line is `FAILED <nodeid> - <message>`, the message in these suites is a slice of Warpgate's own log, and that log carries Rust module paths — so splitting on the last `::` returned `logging:` and `config:` instead of a test name, and the test was not recognised as having failed. Two guards were reported as failing to discriminate on exactly this; both do discriminate, in CI and locally. Also: the gateway binary is fingerprinted across the guard-off build, because an A/B whose halves ran the same binary is not an A/B and reads as a coverage hole. Verified: 53 of 53 guards discriminate, every guard measured, shards accounting for the whole table — https://github.com/janisdombr/warpgate/actions/runs/32802468772
1 parent 7d25fcb commit 191a2c0

1 file changed

Lines changed: 118 additions & 16 deletions

File tree

tests/mutation_matrix.py

Lines changed: 118 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,7 @@
4646

4747
import ast
4848
import atexit
49+
import hashlib
4950
import json
5051
import pathlib
5152
import signal
@@ -791,8 +792,54 @@ def run(command, **kwargs):
791792
return subprocess.run(command, cwd=REPO, capture_output=True, text=True, **kwargs)
792793

793794

794-
def run_named_only(tests: list[str], crates=None) -> tuple[set[str], set[str]]:
795-
"""Run only the given tests. Returns (passed, failed), by name.
795+
def _test_name_from_summary_line(line: str, head: str) -> str | None:
796+
"""The test named by one of pytest's short-summary lines.
797+
798+
Read `line.split("::")[-1].split()[0]` and it looks right until a test
799+
fails on an assertion whose message contains a Rust module path. A summary
800+
line is `FAILED <nodeid> - <message>`, the message here is a slice of
801+
Warpgate's own log, and the log is full of `warpgate_common_http::logging`.
802+
Splitting on the *last* `::` then returns a fragment of that message, the
803+
test is not recognised as having failed, and the run records it as passed —
804+
which is how four guards that discriminate were reported as guards that do
805+
not. The nodeid is what to read, and it ends at the first ` - `.
806+
"""
807+
nodeid = line[len(head):].strip().split(" - ", 1)[0].strip()
808+
if not nodeid:
809+
return None
810+
# `test_x[a b]` is one nodeid with a space in it; the parameters are not
811+
# part of the name a guard names.
812+
return nodeid.split("::")[-1].split("[", 1)[0].strip() or None
813+
814+
815+
def _gateway_fingerprint() -> str | None:
816+
"""Whether the binary the tests will run is the one just built.
817+
818+
An A/B where both halves ran the same binary is not an A/B, and it reports
819+
`does not discriminate` — the guard\'s own test passing with the guard off —
820+
which is indistinguishable from a real coverage hole. Two guards were
821+
reported that way by the first CI sweep while both discriminated locally,
822+
and nothing in the run recorded enough to tell the two explanations apart.
823+
"""
824+
binary = REPO / "target" / "debug" / "warpgate"
825+
if not binary.exists():
826+
return None
827+
digest = hashlib.sha256()
828+
with binary.open("rb") as f:
829+
for block in iter(lambda: f.read(1 << 20), b""):
830+
digest.update(block)
831+
return digest.hexdigest()[:16]
832+
833+
834+
def run_named_only(
835+
tests: list[str], crates=None
836+
) -> tuple[set[str], set[str], dict[str, str]]:
837+
"""Run only the given tests. Returns (passed, failed, unclear), by name.
838+
839+
`unclear` is the third answer this used to lack. A test can be skipped,
840+
error in a fixture, be deselected, or never be collected at all, and none
841+
of those is a pass — but all of them were recorded as one, because the
842+
only thing read was the list of failures.
796843
797844
The whole suite is not run. That is the point: `run_one` runs everything
798845
because it asks "which tests notice", and the answer to that question is
@@ -810,6 +857,7 @@ def run_named_only(tests: list[str], crates=None) -> tuple[set[str], set[str]]:
810857
"""
811858
passed: set[str] = set()
812859
failed: set[str] = set()
860+
unclear: dict[str, str] = {}
813861

814862
crates = crates or list(RUST_CRATES)
815863
rust = [t for t in tests if not t.startswith("test_") or _is_rust(t, crates)]
@@ -833,21 +881,39 @@ def run_named_only(tests: list[str], crates=None) -> tuple[set[str], set[str]]:
833881

834882
if python:
835883
result = subprocess.run(
836-
["poetry", "run", "pytest", *SUITES, "-q", "--tb=no", "-p", "no:randomly",
837-
"-k", " or ".join(python)],
884+
["poetry", "run", "pytest", *SUITES, "-q", "--tb=no", "-rA",
885+
"-p", "no:randomly", "-k", " or ".join(python)],
838886
cwd=REPO / "tests",
839887
capture_output=True,
840888
text=True,
841889
)
842-
reported = {
843-
line.split("::")[-1].split()[0]
844-
for line in result.stdout.splitlines()
845-
if line.startswith("FAILED")
846-
}
890+
# Classify explicitly. Reading only the `FAILED` lines and calling
891+
# everything else passed made a skipped, errored, deselected or
892+
# never-collected test indistinguishable from a passing one — the same
893+
# confusion `failing_tests` already refuses for a whole suite, left open
894+
# for a single test. `-rA` makes pytest state an outcome per test, and a
895+
# name pytest never mentions is recorded as unknown rather than passed.
896+
outcome = {}
897+
for line in result.stdout.splitlines():
898+
head = line.split(" ", 1)[0]
899+
if head in ("PASSED", "FAILED", "ERROR", "SKIPPED", "XFAIL", "XPASS"):
900+
name = _test_name_from_summary_line(line, head)
901+
if name:
902+
outcome[name] = head
847903
for name in python:
848-
(failed if name in reported else passed).add(name)
904+
verdict = outcome.get(name)
905+
if verdict == "FAILED":
906+
failed.add(name)
907+
elif verdict == "PASSED":
908+
passed.add(name)
909+
else:
910+
unclear[name] = verdict or "never reported by pytest"
911+
if unclear:
912+
# Kept because the reason a test did not report is in pytest's own
913+
# output, and every run so far has thrown that output away.
914+
unclear["pytest output"] = result.stdout[-1200:]
849915

850-
return passed, failed
916+
return passed, failed, unclear
851917

852918

853919
_RUST_TEST_CACHE: dict[str, dict[str, str]] = {}
@@ -985,14 +1051,26 @@ def record(result):
9851051
binary_is_mutated = False
9861052

9871053
print(f"[{index:>2}/{total}] baseline", flush=True)
988-
before_pass, before_fail = run_named_only(expected, nearest)
1054+
before_pass, before_fail, before_unclear = run_named_only(expected, nearest)
9891055
if before_fail:
9901056
record({
9911057
"guard": name,
9921058
"status": "already failing",
9931059
"tests": sorted(before_fail),
9941060
})
9951061
continue
1062+
# The precondition is that the named test *passes* before the mutation.
1063+
# A test that was skipped, errored or never collected has not met it,
1064+
# and measuring the other half of the A/B against it produces a verdict
1065+
# about nothing. This used to read as a clean baseline.
1066+
if before_unclear:
1067+
record({
1068+
"guard": name,
1069+
"status": "no baseline",
1070+
"expected": expected,
1071+
"unclear_at_baseline": before_unclear,
1072+
})
1073+
continue
9961074

9971075
source = REPO / path
9981076
original = source.read_text()
@@ -1001,26 +1079,46 @@ def record(result):
10011079
try:
10021080
if needs_binary:
10031081
print(f"[{index:>2}/{total}] building the gateway with the guard off", flush=True)
1082+
before_build = _gateway_fingerprint()
10041083
build = run(["cargo", "build", "--bin", "warpgate"])
10051084
binary_is_mutated = True
10061085
if build.returncode != 0:
10071086
record({"guard": name, "status": "did not compile"})
10081087
continue
1088+
after_build = _gateway_fingerprint()
1089+
if after_build is not None and after_build == before_build:
1090+
record({
1091+
"guard": name,
1092+
"status": "the mutation never reached the binary",
1093+
"expected": expected,
1094+
"fingerprint": after_build,
1095+
"build_output": build.stdout[-600:] + build.stderr[-600:],
1096+
})
1097+
continue
10091098
print(f"[{index:>2}/{total}] testing with the guard off", flush=True)
1010-
after_pass, after_fail = run_named_only(expected, nearest)
1099+
after_pass, after_fail, after_unclear = run_named_only(expected, nearest)
10111100
# `all`, per A2: every test the entry names has to notice.
10121101
status = (
10131102
"discriminates"
10141103
if set(expected) <= after_fail
1104+
else "no verdict"
1105+
if after_unclear
10151106
else "does not discriminate"
10161107
)
1017-
record({
1108+
entry = {
10181109
"guard": name,
10191110
"status": status,
10201111
"expected": expected,
10211112
"failed_with_guard_off": sorted(after_fail),
10221113
"passed_with_guard_off": sorted(after_pass),
1023-
})
1114+
}
1115+
# Only for the verdicts that need explaining. A guard that
1116+
# discriminated needs no forensics; one that did not is exactly
1117+
# where the run has been unable to say why.
1118+
if status != "discriminates":
1119+
entry["unclear_with_guard_off"] = after_unclear
1120+
entry["gateway_built_for_this_guard"] = bool(needs_binary)
1121+
record(entry)
10241122
finally:
10251123
source.write_text(original)
10261124
IN_FLIGHT.pop(str(source), None)
@@ -1059,9 +1157,13 @@ def failing_tests() -> tuple[set[str], str]:
10591157
if "no tests ran" in result.stdout or "collected 0 items" in result.stdout:
10601158
raise SystemExit(f"the suite collected nothing, so nothing was measured:\n{result.stdout[-500:]}")
10611159
failed = {
1062-
line.split("::")[-1].split()[0]
1160+
name
10631161
for line in result.stdout.splitlines()
10641162
if line.startswith("FAILED")
1163+
# Same reason as in `run_named_only`: the last `::` on a summary line
1164+
# belongs to whatever Rust module path the assertion message quoted.
1165+
for name in [_test_name_from_summary_line(line, "FAILED")]
1166+
if name
10651167
}
10661168
return failed, result.stdout[-400:]
10671169

0 commit comments

Comments
 (0)