Skip to content

fix(recorder): survive SQLite writer contention in the video writer - #116

Merged
abrichr merged 5 commits into
mainfrom
fix/windows-video-writer-startup
Aug 28, 2026
Merged

fix(recorder): survive SQLite writer contention in the video writer#116
abrichr merged 5 commits into
mainfrom
fix/windows-video-writer-startup

Conversation

@abrichr

@abrichr abrichr commented Aug 28, 2026

Copy link
Copy Markdown
Member

What broke

The video_writer child process exited 1 during startup on hosted Windows, and the recorder reported only this:

ERROR ... _wait_for_tasks_started:593 - Recording tasks exited before readiness: ['video_writer']
RuntimeError: Recording child process failed: mem_writer (exit code -15), screen_event_writer (exit code -15), video_writer (exit code 1)

Digging the child's traceback out of the captured stderr of run 33186627127 gives the actual cause:

File ".../openadapt_capture/recorder.py", line 1272, in video_pre_callback
  crud.update_video_start_time(db, recording, video_start_timestamp)
File ".../openadapt_capture/db/crud.py", line 352, in update_video_start_time
  session.commit()
sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked
[SQL: UPDATE recording SET video_start_time=? WHERE recording.id = ?]

The video writer is the last writer a recording starts, and persisting the video start time is the first thing it does. By then the screen, action, performance and memory writers are all committing to the same per-capture SQLite file, and they share one write lock. Every other writer waits and retries for it (#106). This statement did not. It took the connection's five-second wait, and an expiry raised straight out of the startup callback and killed the process.

Nothing about the wheel, the drive letter, or the resolved dependency versions is involved. It is contention, and it shows up on hosted Windows because that runner is slow enough to lose the race.

What changed

The fix. The insert retry becomes one write-transaction helper, and the video start time update goes through it. It is now a single UPDATE reporting a missing row by affected row count, rather than a read into a session the retry would have to unwind. Each attempt logs how long it waited, since that wait is the only measure of how close a capture came to losing the race.

Diagnostics. WrapStdout writes a child's formatted traceback to a synchronous queue before the child exits. The readiness wait logs it, and _raise_for_failed_processes attaches it to the error it raises. The next Windows-only startup failure reads from the parent's log without anyone reconstructing it from captured stderr.

Orphan cleanup. record() force-stops surviving children and releases its queues in a finally, and Recorder does the same after joining, in case record() raised first. Both failing runs sat until the 35-minute job timeout after the assertion had already failed: a live child keeps the inherited stdout open, and multiprocessing joins live children at interpreter exit with no timeout, so one leaked writer hangs the program that ran the recording. A queue feeder thread whose reader has died blocks the same way.

Evidence

The qualification lane reproduces this only under load. Dispatched back to back on a quiet runner, it went green on both the fixed branch (33192963705) and unfixed main (33192946319), with zero lock warnings in either. So the green run is necessary but not sufficient, and the contract is pinned where it is deterministic instead.

test_the_real_video_writer_starts_through_a_writer_lock drives the production write_events body with the production video_pre_callback against a database whose write lock another connection holds. Against the code before this PR it fails with the video writer never announced readiness, which is the symptom the recorder reported in runs 33186627127 and 33189604580. It passes here. Encoding a frame would need a real FFmpeg process, so it supplies a preflighted provision and stops at the startup callback, which is where the writer died.

Three more tests cover the retry and fail-loud behaviour of the update, and six cover the child traceback, the reaping, and the queue release.

The lane

hosted-live-recorder-windows returns from live-qualification.yml to the required matrix in production-qualification.yml, and check_release_ci.py requires Hosted live recorder qualification (windows-latest) again. The two files are back to their state before #115, except the twelve-minute bound on the trial step, which stays.

One caveat worth stating: because the lane never went red on a quiet runner, its return to the gate rests on the deterministic test, not on a red-to-green CI transition. If a different contention shows up later, the new wait timings and child tracebacks will name it instead of leaving an exit code.

abrichr and others added 5 commits August 28, 2026 13:03
The video writer process is the last writer a recording starts, and the
first thing it does is persist the video start time to the per-capture
database. By then the screen, action, performance and memory writers are
already committing to that same file, and SQLite gives them one write lock
between them. Every other writer waits and retries for that lock. This one
statement did not: it took the connection's bounded wait, and an expiry
raised straight out of the writer's startup callback and killed the process.

Recording then failed with "Recording tasks exited before readiness", the
reason stayed in the dead child, and the parent reported an exit code.

Three changes:

Generalize the existing insert retry into one write-transaction helper and
route the video start time update through it, so this path recovers from
contention like the inserts do and still fails loud when the lock does not
clear. Write it as a single UPDATE and report a missing row by the affected
row count, rather than reading the row into a session the retry must unwind.
Each attempt logs how long it waited, because that wait is the only measure
of how close a capture came to losing the race.

Carry a child's traceback back to its parent. WrapStdout now writes the
formatted traceback to a synchronous queue before the child exits, and both
the readiness wait and the child-failure error quote it. A child that dies
during startup is now readable from the parent's log alone.

Reap what a recording starts. record() force-stops surviving children and
releases its queues in a finally, and Recorder does the same after joining,
in case record() raised before its own teardown. A surviving child keeps the
inherited standard output open and stops the parent's interpreter exiting at
all, because multiprocessing joins live children at exit with no timeout; a
queue feeder thread whose reader is gone blocks the same way. A failed
recording must report the failure, not hang the program that ran it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The Windows qualification lane reproduces this failure only under load: it
went green on both the fixed and the unfixed code in back-to-back dispatches
on a quiet runner. Pin the contract where it is deterministic instead.

This runs the production write_events body with the production
video_pre_callback against a database whose write lock another connection
holds, and asserts the writer announces readiness. Against the unfixed code
it fails with "the video writer never announced readiness", which is the
symptom the recorder reported in runs 33186627127 and 33189604580.

Encoding a frame would need a real FFmpeg process, so the test supplies a
preflighted provision and stops at the startup callback, which is where the
writer died.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The lane moved to live-qualification.yml on 2026-08-28 because the
video_writer child died during startup and blocked every release while it
was open. That defect is fixed, so hosted Windows rejoins the required
matrix beside hosted macOS and check_release_ci.py requires its job again.

Keep the twelve-minute bound on the trial step. It is cheap, and a step that
stops making progress should report in twelve minutes rather than hold a
runner for the job's full thirty-five.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
BaseException.add_note arrived in Python 3.11 and this package supports
3.10, where a note is attached to nothing and printed nowhere. The child
traceback belonged in the error message all along, since that is what a log,
a test report, and a stack trace all show.

Caught by the 3.10 leg of tests/test_child_process_failure_reporting.py.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@abrichr
abrichr merged commit 1695be7 into main Aug 28, 2026
14 checks passed
@abrichr
abrichr deleted the fix/windows-video-writer-startup branch August 28, 2026 17:24
abrichr added a commit that referenced this pull request Aug 28, 2026
Six feat commits landed since v1.2.2, so the repository's own parser
policy (minor_tags = ["feat"]) makes this a minor release, not a patch.
Publishing it as 1.2.3 would claim a patch while shipping six features
and two new entry points.

Among them, `capture status` and `capture stop` have been documented for
some time but were absent from the 1.2.2 wheel. They arrived in #79 and
ship here for the first time.

Also refresh the section to cover the work that landed after the earlier
candidate was prepared: #111, #114, #115 and #116.

Nothing pins openadapt-capture by exact version. Flow requires
openadapt-capture>=1.2.0, which 1.3.0 satisfies.

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
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