3.x.x: flaky test: a_relaunched_frontend_recovers_one_row_at_the_same_statement_cost_at_both_cardinalities counts one extra candidate-poll transaction (65 vs 61 statements) #729

Activity

1. kiwidream commented on Oct 22, 2026

   

   kiwidream

   on Oct 22, 2026

   Member

   More actions

   Another occurrence on #777 (lockfile-only change), run 39806884637, shard 2: 65 vs 72 statements. This time the extra transaction is the metrics collector's (metrics/collectors.rs:56), not a candidate poll. The storm run's diff from the baseline is exactly these 7 statements:

   BEGIN
   SET TRANSACTION ISOLATION LEVEL REPEATABLE READ READ ONLY
   SELECT set_config('statement_timeout','2000',true),set_config('lock_timeout','500',true)
   SELECT count(*), COALESCE(GREATEST(0,extract(epoch FROM transaction_timestamp()-min(created_at))),0)::double precis…
   SELECT max(upper_seq)-qbit_prism_share_next_seq() FROM qbit_prism_share_partitions WHERE state='attached'
   SELECT block_hash FROM qbit_block_candidate_outbox WHERE block_hash=ANY($1::text[]) AND state='orphaned'
   COMMIT
   

   So the comparison picks up any periodic background transaction that falls inside the recovery window, not just the candidate poll. A fix should exclude, or attribute, the background tasks' transactions (the metrics collector's ten-second tick included) rather than special-case one of them.
2. kiwidream commented on Oct 27, 2026

   

   kiwidream

   on Oct 27, 2026

   Last edited by kiwidream

   Member

   More actions

   Four more occurrences since the comment above. Each has the metrics-collector signature: one cardinality counts 7 extra statements.

   Run	What ran	Statements (baseline vs storm)
   40359403717	#780 (no-op test PR), Oct 26	72 vs 65
   40391226379	3.x.x push at 59194d03, Oct 26	72 vs 65
   40523580929	#788, Oct 27	72 vs 65
   40535982684	#788 again (closed and reopened, same head), Oct 27	72 vs 65

   Since Oct 22, PostgreSQL shard 2 has failed in 5 of 23 completed CI runs. Every one of those failures was this test, and one of them was a 3.x.x push.

   Why the idle windows can never learn this transaction. The collector's snapshot (metrics/collectors.rs) runs its orphan-evidence lookup (… WHERE block_hash=ANY($1::text[]) AND state='orphaned') only when revision_work_terminal_probe() returns hashes. It returns hashes only once the process has registered a block in its landing metrics. coordinator.rs registers one on three events:

   • a definitive submitblock acceptance;
   • an active-chain candidate observation;
   • a reconciled landed block.

   A registered block closes when it is proven orphaned, or when the revision work for its landing reaches a miner's socket. No miner connects in this test, so after the first registration the lookup runs on every 10 s tick.

   In this test, the relaunched child registers nothing during its two idle windows, so the lookup's text never enters the background set. In the measured window, the child offers the siblings it claims ahead of the recovered row, and the node accepts them. From then on, any collector tick that overlaps the recovered row's marked span contains one statement that was never seen while idle, so foreground counts the whole 7-statement run.

   So this is not an idle window that settled too early. It is a background statement that only exists after an acceptance. How likely a measurement is to hit it depends on how long the recovered row's span lasts compared with the 10 s tick.

   Fix direction (test-only). Learn the background set in the state the measured window runs in. For example, let the relaunched child offer and land one sibling before the idle windows. Then every background statement that depends on an accepted or landed block, this lookup included, is seen while idle. That covers the class rather than special-casing the collector.

   🤖 Generated with Claude Code
3. kiwidream commented on Oct 27, 2026

   

   kiwidream

   on Oct 27, 2026

   Member

   More actions

   Fix in #792. Two corrections to my comment above, from the deterministic reproductions made for it:

   • The 72 vs 65 lookup: it isn't switched on by siblings accepted ahead of the recovered row. Since 3.x.x: database clock steps stretch outbox retries and claim leases; a PostgreSQL outage holds only one alert rule #581, the first claim poll after the release takes the recovered row over, ahead of every sibling, and the recovered row's own active observation (Metrics::accepted_block) registers the block that switches on the collector's orphan lookup.
   • The original Oct 6 failure (61 vs 65): it wasn't an extra transaction. The 99-row run lost four statements of the recovered row's own claim transaction. That poll sent BEGIN and the fence before the measured window's mark, so runs() split the transaction.

   #792 also handles a third case found while testing it: a bare ROLLBACK that SQLx sends when the job/blob pruner's COMMIT outlasts its 5 s deadline on a slow disk.

   🤖 Generated with Claude Code
4. kiwidream

   added 2 commits that reference this issue on Oct 27, 2026

   3.x.x: learn the restart test's background statements after a landing…

   ...

   06a7832

   3.x.x: learn the restart test's background statements after a landing…

   ...

   2e11f1b
5. kiwidream commented on Oct 27, 2026

   

   kiwidream

   on Oct 27, 2026

   Member

   More actions

   Fixed by #792, merged into 3.x.x as 2e11f1bf (its "Fixes #729" does not fire on a non-default branch). It fixes all three causes in candidate_storm_restart.rs. (1) The metrics collector's orphan lookup, which starts only after the recovered row's own accepted block and was counted as foreground: a sibling now lands before the idle windows, and the measured executions come from the verification window. (2) The claim transaction straddled the mark (the Oct 6 65-vs-61 variant): it is now kept whole. (3) The job/blob pruner's bare ROLLBACK after a slow COMMIT: transaction control is now neutral in the foreground count. Shard 2 passed on both CI heads of #792 (runs 40565379439 and 40569032223). A failure of this test on a tree that contains 2e11f1bf is a new finding.
6. kiwidream

   closed this as completedon Oct 27, 2026