Verification gate has grown to meet its own 90-minute timeout — required check now fails ~half the time

[avrabe]

The Verification gate (rivet-driven) is a required check whose runtime has converged on its own timeout-minutes: 90. It is now a coin flip.

Evidence

PR	branch	gate outcome
#344	feat/verification-weak-evidence-census	failure at 1h30m21s — i.e. killed at the 90-minute limit
#344	(earlier attempt)	cancelled
#344	(earlier attempt)	success
#342	fix/verification-gate-zero-match	failure ×2
#343	perf/verification-named-tests	success ×2
#340	feat/rel-p01-draft-then-finalize	success at ~1h3m

Same sweep (156 artifacts), durations from ~63 min to ≥90 min. The variance is wider than the headroom, so the outcome is decided by runner load rather than by whether anything is actually wrong.

Why this is worse than a slow gate

1. It is indistinguishable from a real failure at a glance. A timeout surfaces as fail; you have to read the duration to tell. That already cost a diagnosis cycle this week.
2. It trains re-running a red safety gate. The action that "works" is hitting re-run — precisely the reflex that gets a genuine failure clicked through.
3. It blocks the PRs trying to improve it. perf(verify): name the tests 5 falcon-core verification steps actually rely on #343 (which speeds the sweep up) and fix(ci): a Verify-Filter matching zero artifacts must not pass the gate #342 (which fixes a fail-open hole) both have to pass this gate to land.

Where the time goes — measured, partially

• cargo test -p falcon-core is 60 tests / 51s and was invoked 8× per sweep as a whole-crate step ≈ 408s. perf(verify): name the tests 5 falcon-core verification steps actually rely on #343 converts 5 of those (measured 306s → 31s).
• But the other top whole-crate crates are cheap: relay-mavlink 5s, relay-rate 1s, falcon-sitl-hover <1s. So step conversion alone will not close a 30-minute gap.
• Caveat: those were measured warm. The sweep spans 64 distinct crates under cargo test with 29 --release steps — two profile-wide compile sets. On a cold runner the dominant cost is almost certainly compilation, not test execution.

I have not measured the compile-vs-test split on the runner itself. That is the next measurement, and it should come before any fix is chosen.

Options, roughly in order of confidence

1. Raise timeout-minutes (e.g. 90 → 150). Cheapest, stops the false failures immediately, does not weaken the gate — it is being killed, not failing. Buys time to do the real work.
2. Measure compile vs test on the runner, then attack whichever dominates (cache warming, profile consolidation, or dropping the --release duplicates where they add nothing).
3. Continue whole-crate → named conversion (perf(verify): name the tests 5 falcon-core verification steps actually rely on #343, part of rivet hygiene: backfill release: fields + convert whole-crate verification steps to named tests #262) — right for traceability regardless, but on current evidence not the wall-clock fix.

Option 1 is a stopgap and should be labelled as one; shipping it without option 2 just moves the cliff.

Related: #262 (whole-crate steps), #345 (a separate unreproducible rivet validate failure in this same gate).

🤖 Generated with Claude Code

[avrabe]

Correction to the evidence table above — one of my three data points was wrong.

I listed "#342 — failed twice the same way" as evidence of timeout flakiness. That was a misattribution. #342's verification-gate failures were caused by invalid YAML I introduced in that PR, not by the timeout.

The zero-match guard I added used a backslash-continued string whose continuation lines started at column 0, which terminates the enclosing run: | block scalar and makes the whole workflow file unparseable.

The signature is unambiguous once you look for it:

run 31247534173:  created=08:02:50Z  updated=08:02:50Z  conclusion=failure  jobs=0

Zero jobs, and created == updated. GitHub created the run, failed it instantly, and dispatched nothing. A timeout looks completely different — it has a job, a duration, and dies at the limit.

Fixed in #342; the same branch now dispatches a real job.

What survives

The core finding stands, on the remaining evidence:

PR	outcome	is it timeout evidence?
#344	failure at 1h30m21s — killed at timeout-minutes: 90	yes
#344 (earlier)	cancelled	probably
#340	success at ~63m	yes — shows how little headroom is left
#342	failure ×2	no — invalid YAML, my error

So the gap between a passing sweep (~63m) and the ceiling (90m) is still smaller than the observed variance, and #344 was genuinely killed. The timeout raise to 150 (also in #342) is still justified — just on two data points rather than three.

The meta-point, which is the useful part

I verified that workflow file for the thing I was thinking about — no ${{ }} inside run: blocks, checked with a parser — and never checked whether it still parsed at all. A targeted check passed while the file was globally broken.

Both checks now run before I touch a workflow. Worth adopting generally: python3 -c "import yaml; yaml.safe_load(open(f))" is one line and would have caught this immediately.

🤖 Generated with Claude Code

[avrabe]

Third genuine data point, on the same day: #347 killed at 1h30m23s — matching #344's 1h30m21s almost exactly, which is what hitting a hard timeout-minutes: 90 looks like.

Revised evidence, all verified by shape (a real timeout has a job and a duration; the misattributed #342 had zero jobs and created == updated):

PR	outcome	timeout evidence
#344	killed at 1h30m21s	yes
#347	killed at 1h30m23s	yes
#340	success at ~63m	yes — shows the remaining headroom
#342	failure ×2	no — invalid YAML (mine), corrected above

So the case is stronger than when I walked one point back: two independent PRs killed at the ceiling within minutes of each other, and a passing sweep sitting only ~27 minutes below it.

Worth noting the second-order cost: both #344 and #347 are code-free PRs that touch only artifacts/, and both were blocked for 90 minutes each before failing. Any PR touching artifacts/, crates/, wit/ or Cargo.* pays this, which is nearly all of them.

Interim mitigation being used on both: a scoped Verify-Filter matching a real non-empty subset. That is a per-PR workaround, not a fix — and it only became safe to use once the zero-match guard (#342) exists, since before that a filter matching nothing passed the gate silently.

🤖 Generated with Claude Code