Skip to content

fix: stop racing on the WAL switch at worker startup - #10

Merged
msitarzewski merged 1 commit into
mainfrom
fix/sqlite-busy-timeout
Aug 28, 2026
Merged

msitarzewski merged 1 commit into
mainfrom
fix/sqlite-busy-timeout

Conversation

@msitarzewski

Copy link
Copy Markdown
Owner

Symptom

Every boot and deploy cost a full 900s aggregation cycle:

14:00:17  aggregate worker started interval=900s
14:00:18  aggregate cycle failed: OperationalError: database is locked

One second after start, every restart, because all four workers open the database in the same instant.

Why the obvious fix was wrong

I started with "raise busy_timeout" — and the evidence killed it. Python's sqlite3 already waits 5 seconds by default, and the failure came after one. Something was refusing to wait at all.

It was the journal-mode switch:

connection.execute("PRAGMA journal_mode=WAL")   # on every open

journal_mode is a persistent property of the database file, so re-issuing it every open was already pointless. And it isn't free: switching journal mode needs an exclusive lock, and SQLite answers SQLITE_BUSY for it immediately rather than honouring the busy handler. No timeout could ever have rescued it.

Four workers were racing on a no-op.

if connection.execute("PRAGMA journal_mode").fetchone()[0].lower() != "wal":
    connection.execute("PRAGMA journal_mode=WAL")

The busy timeout is raised to 30s as well — genuine defence in depth for the schema/migration block, which every open runs inside a write transaction. But it is not what fixes this.

Tests

Four, and I checked each against a negative control:

test guards
wal_switch_is_skipped_when_already_enabled the real cause — traces statements on a second open, asserts the switch is absent. Reverting the conditional fails it
busy_timeout_is_raised_above_the_python_default the raised timeout
wal_is_still_enabled that the conditional didn't break WAL
a_concurrent_open_waits_instead_of_raising behavioural only — and its docstring says so: a 0.4s hold passes under the old 5s default too

That last note matters. It was my first test, it passed before and after the fix, and I nearly shipped it as evidence. A test that looks like a guard without being one is worse than no test.

Why not MySQL

Raised, and worth recording: FinTick is deliberately standard-library-only (AGENTS.md), so MySQL means a driver dependency and a dependency step at deploy. Splitting engines dev/prod would also break the debugging playbook that found the untickered-instrument bug — pull the prod DB, replay locally. At ~3,900 posts and a 7.6MB file, SQLite is nowhere near its limits; this was four processes colliding in one second, not load.

Suite: 150 passed, 13 pre-existing macOS-only test_service_setup failures.

🤖 Generated with Claude Code

Every boot and deploy cost a full 900s aggregation cycle:

  14:00:17 aggregate worker started interval=900s
  14:00:18 aggregate cycle failed: OperationalError: database is locked

One second after start, on every restart, because all four workers open the
database in the same instant.

The obvious reading is lock contention, but it does not survive the evidence:
Python's sqlite3 already waits five seconds by default, and the failure came
after one. Something was refusing to wait at all.

It was the journal_mode switch. journal_mode is a PERSISTENT property of the
database file, so re-issuing it on every open was already pointless — and it
is not free: switching journal mode needs an exclusive lock, and SQLite
answers SQLITE_BUSY for it immediately rather than honouring the busy
handler. No timeout could ever have rescued it. The workers were racing on a
no-op. It now reads the current mode and writes only when it differs.

The busy timeout is raised to 30s as well. That is defence in depth for the
schema/migration block, which every open runs inside a write transaction, and
not the fix for this bug.

Four tests. The one that guards the real cause traces the statements issued
during a second open and asserts the WAL switch is not among them; reverting
the conditional fails it. The concurrency test is behavioural only and says
so — a 0.4s hold would pass under the old five-second default too, and
claiming otherwise would be a test that looks like a guard without being one.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@msitarzewski
msitarzewski merged commit d360dc5 into main Aug 28, 2026
12 checks passed
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