Engineering Journal

← all posts

Four tests failed before the fix, all on the same line

Testing & QAProcess

Red then green is the standard proof that a regression test is real: run it against the broken code, watch it fail, apply the fix, watch it pass. On July 31 that ritual ran cleanly on four tests and proved almost nothing. All four failed on one assertion inside our own test scaffolding, and not one of them ever reached the check it was written to make. A fix that repaired the wrong half of the bug would have turned every one of them green.


The bug the tests were for

One of our generative patterns, Layer Engine, owns no pixel math. It loads a compiled .so built from the same portable C++ core the pole firmware runs, and asks it for frames. The Python file is a host: it commits geometry, a palette, and a 64-byte genome to the core, then calls eng_render.

The pattern loader execs that file into a fresh globals dict for every live source, so each source got its own Python dictionary remembering what it had committed. Underneath, dlopen on the same path returns the same library, and every commit call addresses instance 0, which is process-global. Two sources are live during a crossfade between patterns, which is a normal state, not a corner case.

So: source A commits genome 0. Source B commits genome 4 on top of it. Source A renders its next frame, consults its own cache, sees "genome 0 is already committed", skips the re-commit, and renders genome 4. No error, no log line. Right in the browser visualizer, wrong on the pole.

The repair is one commit record per process instead of one per source, re-committing whenever the key differs. Measured on the Pi against the real .so, not estimated: eng_render is 328 µs per frame and the extra commit costs 92 µs, so the two-source worst case is 420 µs of a 16,667 µs frame budget. Those are single figures from one Pi rather than a distribution; the margin is wide enough that I did not go chase the spread. With one live source nothing changes and nothing is paid.

The evidence that looked like proof

Four tests covered this. Extract the pre-fix file read-only with git show, point the suite at it, run:

FAIL test_two_sources_alternating_render_their_own_genome: palette generation went backward
FAIL test_same_params_do_not_recommit: palette generation went backward
FAIL test_library_opened_once_per_process: palette generation went backward
FAIL test_palette_generation_monotonic_across_sources: palette generation went backward

Four red, then four green after the fix. Now read the message on each line.

The suite fakes the C core, because the real artifact is an ARM build that a Mac cannot load. The fake's eng_commitPalette carried the spec's rule that the palette generation counter only ever increases, and it carried it as an assertion:

assert gen > self.last_palgen

Pre-fix, each source counts its generations privately, so source B's first commit arrives as generation 1 after source A has already committed generation 1. That assertion fires on B's first commit, which happens inside the first render of the second source, before any test has compared a frame, counted a CDLL call, or looked at a genome. Every one of the four died there.

Not one of them ever reported a wrong genome. The test named two_sources_alternating_render_their_own_genome never rendered a second source's frame at all. If someone had fixed only the generation counter and left the shared-state bug fully intact, all four would have gone green and the commit message would have said the tests prove it.

What the fix to the tests was

Make the fake record the generation instead of asserting on it, and give exactly one test ownership of the monotonicity rule. Nothing about the code under test changed. Same pre-fix file, same four tests:

FAIL test_two_sources_alternating_render_their_own_genome: source A rendered someone else's commit on frame 1
FAIL test_same_params_do_not_recommit: {'geometry': 2, 'palette': 2, 'genome': 2}
FAIL test_library_opened_once_per_process: CDLL called 2 times
FAIL test_palette_generation_monotonic_across_sources: {'geometry': 2, 'palette': 2, 'genome': 2}

Four different assertions on four different lines. Two of them print the same commit-count dictionary, but one is asserting the genome was committed once and the other that the palette was committed six times, and they are checking different claims. The first line is the one that matters most: it is a rendered frame compared against a reference recomputed from that source's own genome bytes and color without going through the host at all, and pre-fix it disagrees on frame 1. That reference is independent of the code under test, not of the fake, whose pixel formula it reproduces. What it proves is which genome and palette the host committed, not that any pixel is right.

The comment that now sits where that assertion used to be puts it more bluntly than a commit message would: a fake that asserts is a fake that hides.

Attribution got the same treatment. Two fixes landed in the same commit (the other one makes the loader verify the .so's ABI version and source hash against a sidecar file before trusting it, which it had never done). Apply only the shared-instance fix, with the provenance check spliced back out, and exactly the three provenance tests fail while the other seven pass. Ten tests, two fixes, no overlap.

The same day, a test that never went red at all

The other half of this lesson came from a different bug on the same day. The full-save path serialized live shared lists with no lock and a shallow copy, so a config file could be written from a structure another thread was mutating.

The first stress test written to prove the fix hammered mutating threads against a save loop and asserted on list lengths and duplicate entries. It passed five times out of five against the known-broken code. The test was measuring something real. It was just not measuring the failure mode: the list it watched rotates, one append and one delete per pass, so a torn read tears into a skipped entry. The length stays at 60 and no duplicate appears.

The rewrite pins two nested values that a mutator always writes together under the lock, and places them at opposite ends of the sorted document so the encoder reads one early and one late. Pre-fix, those two values disagreed in 60 of 60 writes, reproduced on three separate runs. That is a config.json that never corresponded to any state the app was ever in.

Same shape as the first story. Red-then-green would have been satisfied by the first version of that test if the bug had happened to be a little different. Green-then-green was the only reason anyone looked at what it was actually watching.

The rule we are keeping

Red then green tells you the test noticed something changed between two versions of the code. It does not tell you the test is watching the thing you think it is watching.

So read the failure messages, not the count of failures. The rule is not that N tests must always fail for N distinct reasons. Tests that deliberately reproduce one defect across parameters or layers are supposed to fail alike, and that redundancy is worth having. The rule is narrower: when each test claims to check a different thing and they all fail identically, none of them has reached its claim yet. That is one piece of evidence wearing four hats, and a shared assertion inside test scaffolding is a single point of failure for the entire argument.

The scaffolding deserves the suspicion more than the tests do. A fake, a fixture, or a harness that enforces an invariant will happily enforce it before your test gets to do its job, and the failure it produces looks exactly like success. The invariant itself was never the problem and did not have to go: ours moved into a test that owns it. What had to stop was it firing from underneath the observation.

What is still unproven

The ten tests run on a Mac and fake the C core. What they establish is that the host logic commits and re-commits correctly, and refuses a .so it cannot verify. What has not been done is the hardware leg: a crossfade between two layer-engine patterns on a real pole, with the real .so, both ends visually correct. The bug file stays open until that runs.

From pfx-app@192dc73 (tests/test_layer_engine_host.py, 10 tests, now in the pre-push gate) and pfx-app@78caeeb (tests/test_save_worker.py). The two blocks of test output above were re-run against the pre-fix file while writing this, once with the asserting fake restored and once without, rather than quoted from the original session. The save-worker figures are from that bug's own record.