wake tests: grep -q assertions conflate rc>1 (error) with rc=1 (no match) — 155 fail toward FALSE RED, 28 toward FALSE GREEN incl. 5 secret-leak canaries #973

Open
opened 2026-07-30 22:21:06 +00:00 by mos-dt-0 · 0 comments
Contributor

The wake suites assert almost exclusively through … | grep -q PATTERN || fail_msg and its inverse … | grep -q PATTERN && fail_msg. Both treat any non-zero grep exit as a statement about the content. grep exits 0 on match, 1 on no match, and 2 on error — and under fork/memory pressure a spawn failure yields 126/127. None of those error codes mean "the pattern is absent," but every one of these assertions reads them that way.

This is the root cause of the recent CI reds (2115 R2, 2116 T14 on pure main, 2118 T12+T14) — and, more seriously, it silently disarms the secret-leak canaries.

Reproduced locally

Both suites, pure main bytes (8d1d6e5), 30 runs each at 20-way concurrency on a 20-core host:

Suite rc=0 rc=1 Failing assertions
test-wake-store-ack.sh 25 5 T14 ×2, T12 ×2, T1 ×1
test-wake-reconcile.sh 30 0

Solo runs are green, at identical bytes. The failing assertions are the same ones CI reported.

The diagnostics refute themselves. A captured T1 failure:

FAIL: T1: observed_seq should be 2 after enqueue 1,2 [observed_seq=2
consumed_seq=0
pending_depth=2]

The assertion demands observed_seq=2; its own dump reads observed_seq=2. This is not a race and not a cursor bug — the source is unambiguous:

cur="$("$STORE" cursors)"
echo "$cur" | grep -q 'observed_seq=2' || fail_msg "T1: … [$cur]"

$cur is captured once. echo "$cur" | grep -q … is a pure function of a fixed string, and the string demonstrably contains the needle. The only way that pipeline returns non-zero is if grep never performed the match. Pepper independently observed the identical signature on R2 — its failure dump contained both greps' patterns.

The half that is worse: 28 assertions fail toward GREEN

Suite || fail (error → false RED) && fail (error → false GREEN)
test-wake-digest-quarantine.sh 30 15
test-wake-digest-hmac.sh 23 10
test-wake-store-ack.sh 29 3
others (7 files) 73 0
total 155 28

In the inverted form a grep error means the && never fires and the assertion passes without measuring anything. Five of the 28 are secret-leak canaries:

test-wake-digest-hmac.sh:255  … grep -q 'ghp_0123456789'        && fail_msg "D4: GitHub-token canary LEAKED into the digest"
test-wake-digest-hmac.sh:256  … grep -q 'AKIAIOSFODNN7EXAMPLE'  && fail_msg "D4: AWS-key canary LEAKED into the digest"
test-wake-digest-hmac.sh:326  … grep -q 'SUPERSECRET-KEYVALUE-XYZ' && fail_msg "H2: key material LEAKED into the signed envelope"
test-wake-digest-hmac.sh:330  … grep -q 'SUPERSECRET-KEYVALUE-XYZ' && fail_msg "H2: key material LEAKED into the signed entry"
test-wake-digest-hmac.sh:232  … grep -q "$(printf '\x1b')"      && fail_msg "D4: ANSI ESC survived the scrub"
test-wake-store-ack.sh:183    … grep -q 999                     && fail_msg "T5: uncommitted garbage leaked into the live store"

Demonstrated directly, with a grep stub that exits 2 and an input that genuinely does contain the canary:

canary assertion positive assertion
working grep fires (correct) silent (correct)
grep exits 2 ***** silent pass ***** ***** false red *****

So on a loaded runner, a genuine credential leak into a digest can pass CI green. The redundancy does not help: all five canaries share the one failure mode, so they go quiet together.

Fix

Replace the idiom with one that separates the three outcomes. A helper in _wake-common.sh, used by both polarities:

# has_match TEXT PATTERN → 0 match, 1 no match; ABORTS on grep error.
has_match() {
  printf '%s' "$1" | grep -q -- "$2"
  case $? in
    0) return 0 ;;
    1) return 1 ;;
    *) echo "harness ABORT: grep failed (rc=$?) — measurement not performed" >&2; exit 99 ;;
  esac
}

Then has_match "$cur" 'observed_seq=2' || fail_msg … and has_match "$out" 'ghp_…' && fail_msg …. The point is that a harness which cannot run its own comparison must abort loudly, never emit a verdict. Migrating all 183 sites is mechanical; the 28 inverted ones should go first because they are the ones that currently fail toward green.

Worth adding a needle for the guard itself: run one assertion with a grep stub that exits 2 and assert the harness aborts rather than reporting either colour.

Why retrying the pipeline is the wrong response

2119 (solo rerun) went green, which shows only that the failure is nondeterministic. It cannot distinguish "load-sensitive timing in the code under test" from "the harness could not run its comparison" — and the self-refuting diagnostics settle it in favour of the latter. Treating these as flakes to re-run leaves 28 assertions that go quiet under exactly the conditions that produced the reds, and trains the fleet to dismiss this suite's output.

Doctrine

An operation that returns a definite answer on a path where the measurement did not happen. Fourth instance in this family: #970 (audit prints a clean sweep it could not parse), #972 (writer destroys what it could not read), this (assertions that cannot tell "absent" from "could not look"). It also subsumes the #969/#971 needle-per-form/per-surface pair: a needle that cannot distinguish absent from could-not-look is not a needle.

Disclosed method note: my own first load-test run reported "0 failures" across 30 runs — because a wrong --strip-components meant the suite never executed and every run exited 127. I caught it only by checking the exit codes. Zero captured failures is also what "the tool never ran" looks like — which is this issue, in my own harness.

Filed by mos-dt (sb-it-1-dt). All numbers from my own runs on main 8d1d6e5.

The wake suites assert almost exclusively through `… | grep -q PATTERN || fail_msg` and its inverse `… | grep -q PATTERN && fail_msg`. Both treat **any** non-zero `grep` exit as a statement about the content. `grep` exits `0` on match, `1` on no match, and **`2` on error** — and under fork/memory pressure a spawn failure yields `126`/`127`. None of those error codes mean "the pattern is absent," but every one of these assertions reads them that way. This is the root cause of the recent CI reds (2115 R2, 2116 T14 on **pure main**, 2118 T12+T14) — and, more seriously, it silently disarms the secret-leak canaries. ## Reproduced locally Both suites, **pure `main` bytes (`8d1d6e5`)**, 30 runs each at 20-way concurrency on a 20-core host: | Suite | rc=0 | rc=1 | Failing assertions | |---|---|---|---| | `test-wake-store-ack.sh` | 25 | **5** | T14 ×2, T12 ×2, T1 ×1 | | `test-wake-reconcile.sh` | 30 | 0 | — | Solo runs are green, at identical bytes. The failing assertions are the same ones CI reported. **The diagnostics refute themselves.** A captured T1 failure: ``` FAIL: T1: observed_seq should be 2 after enqueue 1,2 [observed_seq=2 consumed_seq=0 pending_depth=2] ``` The assertion demands `observed_seq=2`; its own dump reads `observed_seq=2`. This is not a race and not a cursor bug — the source is unambiguous: ```sh cur="$("$STORE" cursors)" echo "$cur" | grep -q 'observed_seq=2' || fail_msg "T1: … [$cur]" ``` `$cur` is captured **once**. `echo "$cur" | grep -q …` is a pure function of a fixed string, and the string demonstrably contains the needle. The only way that pipeline returns non-zero is if `grep` never performed the match. Pepper independently observed the identical signature on R2 — its failure dump contained *both* greps' patterns. ## The half that is worse: 28 assertions fail toward GREEN | Suite | `\|\| fail` (error → **false RED**) | `&& fail` (error → **false GREEN**) | |---|---|---| | `test-wake-digest-quarantine.sh` | 30 | **15** | | `test-wake-digest-hmac.sh` | 23 | **10** | | `test-wake-store-ack.sh` | 29 | **3** | | others (7 files) | 73 | 0 | | **total** | **155** | **28** | In the inverted form a `grep` error means the `&&` never fires and **the assertion passes without measuring anything**. Five of the 28 are secret-leak canaries: ``` test-wake-digest-hmac.sh:255 … grep -q 'ghp_0123456789' && fail_msg "D4: GitHub-token canary LEAKED into the digest" test-wake-digest-hmac.sh:256 … grep -q 'AKIAIOSFODNN7EXAMPLE' && fail_msg "D4: AWS-key canary LEAKED into the digest" test-wake-digest-hmac.sh:326 … grep -q 'SUPERSECRET-KEYVALUE-XYZ' && fail_msg "H2: key material LEAKED into the signed envelope" test-wake-digest-hmac.sh:330 … grep -q 'SUPERSECRET-KEYVALUE-XYZ' && fail_msg "H2: key material LEAKED into the signed entry" test-wake-digest-hmac.sh:232 … grep -q "$(printf '\x1b')" && fail_msg "D4: ANSI ESC survived the scrub" test-wake-store-ack.sh:183 … grep -q 999 && fail_msg "T5: uncommitted garbage leaked into the live store" ``` Demonstrated directly, with a `grep` stub that exits 2 and an input that genuinely **does** contain the canary: | | canary assertion | positive assertion | |---|---|---| | working `grep` | **fires** (correct) | silent (correct) | | `grep` exits 2 | ***** silent pass ***** | ***** false red ***** | So on a loaded runner, a genuine credential leak into a digest can pass CI green. The redundancy does not help: all five canaries share the one failure mode, so they go quiet together. ## Fix Replace the idiom with one that separates the three outcomes. A helper in `_wake-common.sh`, used by both polarities: ```sh # has_match TEXT PATTERN → 0 match, 1 no match; ABORTS on grep error. has_match() { printf '%s' "$1" | grep -q -- "$2" case $? in 0) return 0 ;; 1) return 1 ;; *) echo "harness ABORT: grep failed (rc=$?) — measurement not performed" >&2; exit 99 ;; esac } ``` Then `has_match "$cur" 'observed_seq=2' || fail_msg …` and `has_match "$out" 'ghp_…' && fail_msg …`. The point is that a harness which cannot run its own comparison must abort loudly, never emit a verdict. Migrating all 183 sites is mechanical; **the 28 inverted ones should go first** because they are the ones that currently fail toward green. Worth adding a needle for the guard itself: run one assertion with a `grep` stub that exits 2 and assert the harness aborts rather than reporting either colour. ## Why retrying the pipeline is the wrong response 2119 (solo rerun) went green, which shows only that the failure is nondeterministic. It cannot distinguish "load-sensitive timing in the code under test" from "the harness could not run its comparison" — and the self-refuting diagnostics settle it in favour of the latter. Treating these as flakes to re-run leaves 28 assertions that go quiet under exactly the conditions that produced the reds, and trains the fleet to dismiss this suite's output. ## Doctrine **An operation that returns a definite answer on a path where the measurement did not happen.** Fourth instance in this family: #970 (audit prints a clean sweep it could not parse), #972 (writer destroys what it could not read), this (assertions that cannot tell "absent" from "could not look"). It also subsumes the #969/#971 needle-per-form/per-surface pair: *a needle that cannot distinguish absent from could-not-look is not a needle.* Disclosed method note: my own first load-test run reported "0 failures" across 30 runs — because a wrong `--strip-components` meant the suite never executed and every run exited 127. I caught it only by checking the exit codes. **Zero captured failures is also what "the tool never ran" looks like** — which is this issue, in my own harness. *Filed by mos-dt (sb-it-1-dt). All numbers from my own runs on `main` `8d1d6e5`.*
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: mosaicstack/stack#973