Skip to content

Fix the CI test flakes of K22 and the three of 2026-10-29 - #32

Merged
rorychatt merged 1 commit into
mainfrom
fix/ci-flakes
Oct 29, 2026
Merged

rorychatt merged 1 commit into
mainfrom
fix/ci-flakes

Conversation

@rorychatt

Copy link
Copy Markdown
Contributor

Product change (read this first)

crates/kernel/obop-storage/src/schema.rs and pg_hist.rs change product code. Release note: PostgreSQL: several server processes that start at the same time and first need the change-history tables no longer fail with a deadlock (SQLSTATE 40P01) while creating them.

Everything else in this PR is tests, test helpers and docs/ISSUES.md (K22).

The flakes: cause, fix, numbers

"Before" and "after" are the same test run N times from a saved binary of the old and the new code (debug build, PostgreSQL 17 in obop-pg and PostgreSQL 18 in a private container, --test-threads=1 per run, several runs side by side). "Load" means that many busy yes processes on the 32-thread machine.

# Test Product or test Cause Fix Before After
1 pg_hist_tests::processes_that_need_the_part_together_make_it_once (40P01) product schema::with_lock takes the schema advisory lock after BEGIN. A process that waited for it asked the catalogue (to_regclass, to_regprocedure) from negative cache entries older than the commit of the process before it (advisory locks do not refresh the catalogue cache), so the history part looked missing; it ran the whole DDL again. Its CREATE INDEX IF NOT EXISTS takes ShareLock on the history tables in the opposite order to obop_history_ensure_partition (the lock of a batch that writes history), and the two deadlock. Several server processes starting together can hit this on the first tracked write; install_on_demand then backs off and refuses the write. schema::take_lock: lock, then SELECT 1 FROM pg_catalog.pg_class LIMIT 0 so the check sees what the previous process made. pg_hist::Import::flush uses it too. New regression test a_process_that_waited_for_the_schema_lock_sees_what_the_one_before_it_made (the maker holds the lock while the waiter queues; fails 3 of 3 on the old code, passes on the new). PG17 24/200, PG18 10/200 PG17 0/200, PG18 0/200
2 backup_cli::a_key_in_the_environment_makes_the_backup_sealed_and_restore_needs_it test The canary ada (3 bytes) occurs by chance in the hex of the plain header (backup id, key id, nonce prefix, wrapped key). 16 random bytes per run (canary-<hex>); the control test with a plain backup uses the same canary and still fails the scan (200 of 200 runs). 4/200 0/200
3 pool::an_exhausted_pool_answers_503_with_retry_after_never_a_401_and_the_server_recovers (in_use 1 not 0) test The gauge is one instant and the server is never idle: the connectors worker takes a main-pool connection at uptime 5, 10, 15 s and after every create (idle server probed: in_use > 0 at 5.0x, 10.0x, 15.0x s; the CI failure was at uptime 10.5 s). metrics_when polls every 50 ms, at most 30 s, until in_use and waiting read 0, and shows the last metrics at the deadline. A leaked connection still fails. The in_use reading itself did not recur locally; the run showed a second flake in the same test: the /readyz bound of exactly 3 s is the product's own READY_TIMEOUT, and the answer came at 3.0016 s; the bound is now 10 s (a hanging probe still fails). 2/208 (the /readyz bound) 0/208
4 seams_tests::read_tx_takes_a_normal_connection_and_not_a_place_in_the_long_read_lane test The warm-up opened three connections inside the 500 ms acquire window the test claims not to measure. Bounded retry (time_budget(60)) until the three exist. 50/204 (load 48); 1/204 (load 28) 0/204 (load 48)
5 pg_pool_tests::the_lock_pool_does_not_take_interactive_capacity_and_the_other_way_round test The interactive connections were held by pg_sleep(2) and the test asserted 1 s and 2 s wall-clock bounds, an unbounded while in_use < 2. Holders hold until the test lets go (channels, also on unwind); wall-clock bounds removed (a get or lock that had to wait would be refused after the acquire timeout, so success is the proof). 51/204 (load 28) 1/204 and 0/204 (two runs, load 28)
6 pg_pool_tests::a_connection_killed_by_the_server_is_noticed_and_replaced (and only_a_statement_on_a_connection_that_broke_is_in_flight, same helper) test A fixed 200 ms after pg_terminate_backend; replacement of the dead connection inside the default 2 s acquire window. kill_sessions waits (bounded) until pg_stat_activity shows no session; acquire window 30 s in these tests. 1/204 (load 28) 0/204 (load 28)
7 multi_process::a_session_started_on_one_process_works_on_the_other_and_data_is_shared (401, once on CI) not reproduced, cause not proven Hypothesis that fits (token valid on A, unknown on B): the 8 tests of the binary run side by side and choose ports by bind-and-close, so two servers could be given one port; the later exits and the test talks to the other test's server (another database). free_port hands each port out once per binary (multi_process.rs, pool.rs); the start-up loop panics with the log if the server exited. 15 runs of the whole binary pass. not reproduced not reproduced

Method notes: flake 1 was reproduced first under unfixed code (12 % on PG17), and the mechanism was shown with a probe (BEGIN, wait for the lock while another session commits the DDL, then to_regclass is stale; with the pg_class read it is fresh). No fix is a longer sleep or a retry of the test.

Not fixed (and why)

  • Flake 7: see above. If the 401 recurs, read the session lookup in obop-auth before calling it a flake.
  • Flake 5 still failed once in 204 runs under 28 busy processes (a lock refused inside the 1.5 s acquire window that the test itself needs for the "ninth lock is refused" step); 0 of 204 in a second run. Not chased further.
  • Product, found while fixing 1 and not changed: a part that is genuinely partial (an operator dropped one object) is repaired by DDL that can still deadlock with obop_history_ensure_partition of another process; ensure_schema has no retry for 40P01 (a batch has one); require() checks a part outside the schema lock and can be briefly stale (it heals on the next call).

Gates (run on this head)

  • cargo fmt --check: clean.
  • cargo clippy --workspace --all-targets -- -D warnings: clean.
  • cargo test --workspace without PostgreSQL: 2081 passed, 0 failed, 6 ignored (68 test binaries).
  • cargo test --workspace with OBOP_TEST_POSTGRES_URL (PostgreSQL 18): 2081 passed, 0 failed, 6 ignored.

K22 in docs/ISSUES.md now says which are fixed (with cause) and what is left; no change to docs/DECISIONS.md.

🤖 Generated with Claude Code

Product (obop-storage, schema.rs and pg_hist.rs): a process that waited for
the schema advisory lock looked at a catalogue cache older than the commit
of the process before it, found the history part missing and ran its DDL
again, which could deadlock (40P01) with obop_history_ensure_partition.
schema::take_lock now reads pg_class once the lock is held.

Tests: random 16 byte canary in backup_cli; bounded wait for the pool gauges
and a 10 s bound for /readyz in pool.rs; bounded warm-up in the read-lane
test; connections held until released and no wall-clock bounds in the lock
pool test; kill_sessions waits for the server and a longer acquire window in
the connection kill tests; each test port handed out once per binary and a
server that exited is noticed in multi_process.rs and pool.rs.

K22 in docs/ISSUES.md says which are fixed and what is left.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>
@rorychatt
rorychatt merged commit 18e9c06 into main Oct 29, 2026
5 checks passed
@rorychatt
rorychatt deleted the fix/ci-flakes branch October 29, 2026 14:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant