fix(test): close the store pool before salvaging its database #423

Merged
KofTwentyTwo merged 1 commits from fix/recovery-salvage-flake into dev 2026-08-15 01:13:29 +00:00
KofTwentyTwo commented 2026-08-15 01:06:13 +00:00 (Migrated from github.com)

Root-causes the recovery::tests::test_stage_2_backup_creation_and_stage_3_table_salvage flake. Closes #422.

The actual error

Recovered from the CI log for run 31382964981 (2026-08-10, ubuntu-latest) — nobody had seen this before:

salvage succeeds: Query(Database(SqliteError { code: 522, message: "disk I/O error" }))

522 is SQLITE_IOERR_SHORT_READ (10 | 2<<8). The Query variant places it inside connect_file → migrate(), i.e. step 4 of salvage.

Root cause

The fixture built its engine in a bare block and let it drop instead of calling close(). Dropping an sqlx::Pool does not close its connections synchronously — teardown is spawned onto the runtime. Salvage then unlinks target_db_path plus its -wal/-shm and creates a fresh database at that same path. SQLite's close-time WAL handling operates on -wal/-shm by path, so the deferred teardown can land after the unlink and interact with the new database's companions, leaving the fresh empty main file paired with a -wal describing the old one. Replaying it reads past EOF → SQLITE_IOERR_SHORT_READ.

This is a fixture defect, not a production defect: DatabaseEngine::close_and_salvage already does engine.close().await + a 50 ms settle before calling salvage, the other branch reaching salvage never had a pool, and the sibling stage-1 test already closed its engine. This test was the sole caller violating the contract. DatabaseEngine::close()'s own doc comment already describes this hazard class.

Changes

  • Test closes the engine before the fixture block ends. close() awaits pool.close(), so the window ceases to exist rather than narrowing — no sleep, no retry, no weakened assertion.
  • SqliteRecoveryEngine::salvage now documents the precondition so the next caller does not repeat it.

Honest caveat

I could not reproduce this locally (macOS/APFS; CI is ubuntu-latest) across ~800 attempts — 300 sequential in-process iterations, 480 across 8 concurrent tasks on a 4-worker runtime, 15 with a 4 MB WAL to stretch the close-time checkpoint, and a hand-built deterministic unlink/recreate probe. So there is no regression test that fails without this fix: the failure is a genuine OS-timing race, and a probabilistic regression test would be worse than none. The diagnosis rests on the recovered CI error plus error-path enumeration (only three ? sites exist in salvage, and only connect_file can yield Query). Full ruled-out list is in #422.

Gate

cargo fmt --all -- --check, cargo check-all, cargo test-all all green, plus RUST_TEST_THREADS=2 cargo test-all three times with zero FAILED lines.

Root-causes the `recovery::tests::test_stage_2_backup_creation_and_stage_3_table_salvage` flake. Closes #422. ## The actual error Recovered from the CI log for run `31382964981` (2026-08-10, `ubuntu-latest`) — nobody had seen this before: ``` salvage succeeds: Query(Database(SqliteError { code: 522, message: "disk I/O error" })) ``` `522` is `SQLITE_IOERR_SHORT_READ` (`10 | 2<<8`). The `Query` variant places it inside `connect_file` → `migrate()`, i.e. step 4 of salvage. ## Root cause The fixture built its engine in a bare block and let it **drop** instead of calling `close()`. Dropping an `sqlx::Pool` does not close its connections synchronously — teardown is spawned onto the runtime. Salvage then unlinks `target_db_path` plus its `-wal`/`-shm` and creates a fresh database at that same path. SQLite's close-time WAL handling operates on `-wal`/`-shm` **by path**, so the deferred teardown can land after the unlink and interact with the *new* database's companions, leaving the fresh empty main file paired with a `-wal` describing the old one. Replaying it reads past EOF → `SQLITE_IOERR_SHORT_READ`. This is a **fixture defect, not a production defect**: `DatabaseEngine::close_and_salvage` already does `engine.close().await` + a 50 ms settle before calling salvage, the other branch reaching salvage never had a pool, and the sibling stage-1 test already closed its engine. This test was the sole caller violating the contract. `DatabaseEngine::close()`'s own doc comment already describes this hazard class. ## Changes - Test closes the engine before the fixture block ends. `close()` awaits `pool.close()`, so the window ceases to exist rather than narrowing — **no sleep, no retry, no weakened assertion**. - `SqliteRecoveryEngine::salvage` now documents the precondition so the next caller does not repeat it. ## Honest caveat I could not reproduce this locally (macOS/APFS; CI is `ubuntu-latest`) across ~800 attempts — 300 sequential in-process iterations, 480 across 8 concurrent tasks on a 4-worker runtime, 15 with a 4 MB WAL to stretch the close-time checkpoint, and a hand-built deterministic unlink/recreate probe. So there is **no regression test that fails without this fix**: the failure is a genuine OS-timing race, and a probabilistic regression test would be worse than none. The diagnosis rests on the recovered CI error plus error-path enumeration (only three `?` sites exist in `salvage`, and only `connect_file` can yield `Query`). Full ruled-out list is in #422. ## Gate `cargo fmt --all -- --check`, `cargo check-all`, `cargo test-all` all green, plus `RUST_TEST_THREADS=2 cargo test-all` three times with zero `FAILED` lines.
Sign in to join this conversation.