Skip to content

TEST: Stop SQLite lock flakes on slow CI disks - #3527

Open
Richard Lundeen (richlundeen) wants to merge 1 commit into
microsoft:mainfrom
richlundeen:richlundeen-robust-flaky-test-fix
Open

Richard Lundeen (richlundeen) wants to merge 1 commit into
microsoft:mainfrom
richlundeen:richlundeen-robust-flaky-test-fix

Conversation

@richlundeen

Copy link
Copy Markdown
Contributor

Description

#3499 raised the file-backed SQLite busy timeout to 30 s, but Windows CI still fails with database is locked (failed job). The same flake also hit test_concurrent_orm_score_deletions_clean_final_observation.

Cause. Each SQLite commit calls fsync, and the writer keeps the write lock during fsync. On loaded CI disks, fsync can take seconds. In the failed run, one fixture took 196 s to create 53 tables, about 3.7 s for each commit. Ten concurrent writers at that speed need about 37 s, so one writer waits past the 30 s busy timeout. A longer timeout does not fix slow commits.

Changes. Only test code changes. Production code and settings do not change.

  • tests/unit/conftest.py sets PRAGMA synchronous=OFF when a unit test opens a SQLite connection. This removes fsync from file-backed test databases and makes their setup fast. Locking and transactions do not change. The PRAGMA must read the schema, so it runs with busy_timeout=0. If another connection holds an exclusive lock (the analytics lock tests do this on purpose), the new connection does not wait and keeps fsync.
  • A SQLITE_BUSY error gets a note with the time that SQLite waited for the lock, for example SQLite returned SQLITE_BUSY after 30.15 s. A wait near the busy timeout shows lock contention. A wait near 0 s shows that SQLite did not wait.
  • The two tests that failed in CI use the shared test watchdog (wait_for_completion_async) instead of 5–60 s wall-clock deadlines, as .github/instructions/test.instructions.md requires for correctness tests.

Other recent flakes have different causes and are not in this PR: short asyncio.wait_for deadlines on macOS (for example in test_fuzzer.py) and subprocess timeouts on Windows.

Tests and Documentation

New tests in tests/unit/memory/test_sqlite_fixtures.py:

  • File-backed sync and async connections of SQLiteMemory report synchronous=0.
  • A connection that opens during an exclusive lock of another connection does not wait, keeps its busy timeout, and keeps fsync.
  • A SQLITE_BUSY error has the lock-wait note.

With the hooks removed, the first and third tests fail. Updated doc/contributing/5_unit_tests.md.

Validation on Windows, Python 3.14.2:

Command Result
uv run --no-sync pre-commit run --all-files All 18 hooks passed, including ty
uv run --no-sync python -m pytest -n 4 --dist=loadfile tests/unit -q -p no:cacheprovider --timeout=600 --durations=25 (before rebase on 246b659e4) 31580 passed, 50 skipped; no file-backed SQLite test in the 25 slowest
uv run --no-sync python -m pytest -n 4 --dist=loadfile tests/unit/memory tests/unit/backend/test_operations.py tests/unit/backend/test_analytics_lifecycle.py tests/unit/backend/test_analytics_benchmark.py -q -p no:cacheprovider --timeout=600 (after rebase) 1986 passed, 1 skipped
uv run --no-sync python -m pytest -n 4 --dist=loadfile <17 test files changed on main since the branch point> -q -p no:cacheprovider --timeout=600 (after rebase) 539 passed
uv run --no-sync python -m pytest <3 file-backed concurrency tests> -q -p no:cacheprovider --timeout=300, 5 times in each of 6 parallel jobs 30 of 30 runs passed; the 10-writer test takes about 0.4 s (58 s before the CI failure)
File-backed test modules with -n 4 (conftest, branching, observations, analytics lock retry, activity operation IDs, SQLite memory, cancellation, migration, backend file-backed tests) 488 passed in 74.9 s before, 491 passed in 60.9 s after

Commit latency on a local NVMe disk: synchronous=FULL 3.0 ms (7.2 ms with background fsync load), OFF 1.2 ms (2.35 ms). CI disks gain more, because fsync is the slow part there.

JupyText: not run. This PR does not change notebooks, documentation code, or APIs.

PR microsoft#3499 raised the SQLite busy timeout to 30 s, but Windows CI still failed
with "database is locked". On loaded CI disks, each commit fsync can take
seconds (one fixture took 196 s for 53 DDL commits). Ten concurrent writers
then wait more than 30 s for the write lock.

- tests/unit/conftest.py turns off fsync (PRAGMA synchronous=OFF) when a
  unit test opens a SQLite connection. Locking and transactions do not
  change. The PRAGMA does not wait for an exclusive lock of another
  connection.
- SQLITE_BUSY errors get a note with the time that SQLite waited for the
  lock, to tell contention from an immediate conflict.
- The two flaky concurrency tests use the shared test watchdog instead of
  short wall-clock deadlines.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

This branch has not been deployed

No deployments
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