fix(db): bound the SQLite write-lock wait by time, not by attempts - #122
Merged
Conversation
Two hosted Windows lanes failed on 0d14af1 for one reason. A writer's write transaction starved for about twenty-two seconds and the retry policy ran out of attempts while it was still starving. In the qualification lane video_writer spent 22.8s on three attempts at its video start-time update, never announced readiness, and failed the thirty-second startup deadline. In the tests lane mem_writer spent 21.9s on three attempts while the screen writer drained its screenshot backlog, exhausted them, and exited 1. Readiness had already succeeded there: the contention is not confined to startup, it is whenever one writer holds the file. The policy was a count of attempts with an inherited per-attempt wait, and a count of attempts bounds nothing. The runners measured one attempt at about seven seconds against a nominal five-second busy timeout, so three attempts cost twenty-two seconds -- too long to fit the readiness deadline, and only three samples of a lock that was busy nearly all the time. Spend a declared time budget instead. _write_with_lock_retry now runs against a clock: it re-enters the race for as long as SQLITE_WRITE_LOCK_BUDGET_SECONDS allows and stops as soon as too little budget remains to finish another attempt, so the total wait is never more than the budget whatever one attempt costs underneath. The busy timeout drops to 0.5s, which turns the same budget into tens of chances at the lock rather than three. recorder.py refuses to import if the budget cannot fit inside its readiness deadline. Reduce the contention as well as bound it. A live capture now keeps a write-ahead log. Under the default rollback journal every commit creates, syncs and deletes a journal file beside the capture; on Windows that churn is scanned by the filesystem filter driver, one screenshot row costs about half a second, and a writer draining a backlog holds the single write lock at nearly full duty cycle. A write log appends instead, and readers stop blocking writers. Measured here on six concurrent writers, it cut median commit latency from 0.72ms to 0.13ms and the worst wait from 2.3s to 0.57s. The write log is a property of a live capture, not of every database this package creates: create_db takes the journal mode as an argument, and only the recorder passes it. A fixture built by scripts/generate_synthetic_captures.py has one writer and its bytes are unchanged. finalize_capture_database folds the log back into the file before a capture is verified and sealed. build_artifact_manifest inventories every regular file under the capture directory, and the shared-memory file is created and removed by whoever opens the database next, so a capture sealed with its sidecars present would fail its own validation later. It fails loud rather than sealing one. record() also now closes the two sessions it opened and never closed, which otherwise held the file open past the end of the recording. tests/test_db_lock_retry.py gains the shape that was missing. The earlier regression test drove one writer against a lock held by one other connection, which passes against the defect. The new test starts the real memory, performance-stats and video writer bodies together against one database whose lock is already held, which is what production does, and it fails against the replaced policy because three attempts is three chances. Two more tests measure rather than assert the bound: one times a real attempt against the declared attempt ceiling, the other times the whole helper against the declared budget and fails both when it overruns and when it gives up early. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This was referenced Aug 28, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What failed
Two hosted Windows lanes failed on
0d14af17, and it is one defect, not two.33197564607TimeoutError: ... within 30.0s; unresolved readiness: video_writer33197547877attempt 1RuntimeError: Recording child process failed: mem_writer (exit code 1)/sqlite3.OperationalError: database is lockedBoth logs carry the same lines. A writer's write transaction starved for about 22 seconds and the retry policy ran out of attempts while it was still starving:
One detail worth correcting: the tests-lane failure is not a startup failure. Readiness succeeded at 18:08:49.
mem_writerdied 25 seconds later, whilescreen_event_writerspent 24.6 seconds draining its screenshot backlog. The contention is whenever one writer holds the file, not only when they all start.mem_writerdoes go through the retry helper — its traceback runsinsert_memory_stat→_insert→_execute_insert_with_lock_retry. It exhausted the retries rather than missing them.Why the policy could not work
The policy was a count of attempts with an inherited per-attempt wait. A count of attempts bounds nothing: the cost of an attempt is whatever SQLite's busy handler decides. The runners measured ~7s per attempt against a nominal 5s busy timeout, so three attempts cost ~22s — both too long to fit a 30s readiness deadline, and only three samples of a lock that was busy nearly all the time.
The fix
Bound the wait by time.
_write_with_lock_retryruns against a clock: it re-enters the race for as long asSQLITE_WRITE_LOCK_BUDGET_SECONDS(20s) allows, and refuses to begin an attempt unlessSQLITE_LOCK_ATTEMPT_CEILING_SECONDS(2s) remains. The total wait is therefore never more than the budget, whatever one attempt costs. The busy timeout drops 5.0s → 0.5s, turning the same budget into tens of chances rather than three.recorder.pyrefuses to import if the budget cannot fit its readiness deadline.Reduce the contention as well as bound it. A live capture now keeps a write-ahead log. Under the default rollback journal every commit creates, syncs and deletes a journal file beside the capture; on Windows that churn is scanned by the filesystem filter driver, one screenshot row costs ~0.5s, and a draining writer holds the lock at nearly full duty cycle. Measured here on six concurrent writers:
synchronous=NORMALThe write log belongs to a live capture, not to every database this package creates:
create_dbtakes the journal mode as an argument and only the recorder passes it, soscripts/generate_synthetic_captures.pyfixtures keep their exact committed bytes.finalize_capture_databasefolds the log back in before a capture is verified and sealed —build_artifact_manifestinventories every regular file under the capture directory, and the-shmfile is created and removed by whoever opens the database next, so a capture sealed with sidecars present would fail its own validation later. It fails loud rather than sealing one.record()also now closes the two sessions it opened and never closed.Tests
The earlier regression test drove one writer against a lock held by one other connection. That passes against the defect. Verified: with only the old retry policy restored, 13 of 15 tests in this file still pass — including that one.
The new
test_concurrent_writers_all_survive_a_busy_write_lockstarts the realmemory_writer,performance_stats_writerand videowrite_eventsbodies together against one database whose lock is already held. It fails against the replaced policy, because three attempts is three chances.Two more measure rather than assert the bound:
test_one_locked_attempt_costs_less_than_the_declared_ceilingtimes a real attempt with the production busy timeout against the declared ceiling.test_the_total_wait_never_runs_past_the_declared_budgettimes the whole helper against the declared budget, and fails both when it overruns and when it gives up early.test_a_write_logged_capture_verifies_and_sealscovers the seal path without a display or input permissions.Full suite: 721 passed, 33 skipped.
ruffclean.Note for the reviewer
test-windowsskips on PRs and runs only on push tomain, so this PR going green says nothing about Windows. The Windows evidence is the post-merge run plus the three-trial qualification gate.Separately: run
33197547877now readssuccessbecause attempt 2 re-ran the failed job on the same commit with no code change.triggering_actorisabrichr, and this repo has no automatic re-run in any workflow — so a person or a peer session did it. Any green ontest-windowsat or before0d14af17is worthless.