Adding a company answers 500 "database is locked" when the form is sent twice, though the company was saved #206

New issue

Closed

opened 2026-09-15 14:27:23 +00:00 by tiagoagueda · 0 comments

tiagoagueda commented

2026-09-15 14:27:23 +00:00

Owner

What happened

On ragnar (f99fb3138, 0.2.1-dev.f99fb31), adding France Travail as a company on Companies → New showed an error 500 page at 2026-09-15 16:23:16 (+0200).

The access log shows two POST /jobs/companies/new/ from the same browser in the same second:

[15/Sep/2026:16:23:16 +0200] "POST /jobs/companies/new/ HTTP/1.1" 302 0
[15/Sep/2026:16:23:16 +0200] "POST /jobs/companies/new/ HTTP/1.1" 500 1947

The first saved the company and redirected. The second failed about 100 ms later:

ERROR django.request: Internal Server Error: /jobs/companies/new/
  File "/app/src/postulo/jobs/views.py", line 268, in form_valid
    response = super().form_valid(form)
  File "/app/src/postulo/jobs/forms.py", line 207, in save
    company = super().save(commit=commit)
  ...
django.db.utils.OperationalError: database is locked

The company exists once (pk 15, France Travail, kind employment_service, created 14:23:16.291 UTC), so no data was lost or duplicated. But the browser shows the response to the last request, so the person sees a 500 for something that worked. That invites a retry, and a retry creates a duplicate.

Why

Three things together:

Nothing stops a form being sent twice. static/js/app.js has no submit guard, and the company form has none of its own. A double click, or Enter and then a click, sends two POSTs.
Three gunicorn workers write to one SQLite file (docker/Dockerfile: --workers 3), so the two POSTs really do run at the same time.
SQLite uses its defaults, and those fail instantly. DATABASES in config/settings/base.py sets no OPTIONS. On ragnar: journal_mode=delete, busy_timeout=5000, ATOMIC_REQUESTS=True, Django 6.1.1. Every request is a DEFERRED transaction. The second request starts it with a read (the form's validation), then tries to upgrade to a write while the first holds the write lock. SQLite refuses that upgrade with SQLITE_BUSY straight away and does not wait out the busy timeout, since waiting could deadlock. That is why it failed in 100 ms and not after 5 s.

Whatever takes the write lock early can hit this: a double submit, two tabs, or the browser extension capturing while someone edits. Companies are just where it showed first. LogoFormMixin also runs logos.from_url inside the request transaction, so a slow logo fetch holds the write lock for the whole network round trip and makes the window wider.

What would fix it

SQLite options in base.py whenever the engine is sqlite3. Django 5.1+ supports all of these:
- "transaction_mode": "IMMEDIATE": the write lock is taken when the transaction begins, so a second writer waits (the busy timeout then applies) and is not refused.
- "init_command": "PRAGMA journal_mode=WAL; PRAGMA synchronous=NORMAL;": readers stop blocking the writer and the writer stops blocking readers.
- An explicit "timeout" (for example 20 s) rather than relying on the 5 s default.
- Check that manage.py backup still produces a consistent copy under WAL (the -wal/-shm files), and that the image's data volume allows them.
A submit guard in app.js for every form[method=post]: disable the submitter after the first submit, and re-enable it on pageshow so the back button does not leave a dead form. It must still work with the script blocked, which today's forms already do.
Keep network I/O outside the write transaction where it can be: fetch the logo before the insert, or after commit (transaction.on_commit).

Tests

A test that DATABASES["default"]["OPTIONS"] gets transaction_mode=IMMEDIATE and WAL for a file database and leaves :memory: alone.
A threaded test against a file SQLite database: two concurrent company creations, both answer 302 or one answers a form error, never a 500.
An e2e test that double-clicking Save on the company form sends one POST.

## What happened On ragnar (`f99fb3138`, `0.2.1-dev.f99fb31`), adding **France Travail** as a company on *Companies → New* showed an error 500 page at 2026-09-15 16:23:16 (+0200). The access log shows **two** `POST /jobs/companies/new/` from the same browser in the same second: ``` [15/Sep/2026:16:23:16 +0200] "POST /jobs/companies/new/ HTTP/1.1" 302 0 [15/Sep/2026:16:23:16 +0200] "POST /jobs/companies/new/ HTTP/1.1" 500 1947 ``` The first saved the company and redirected. The second failed about 100 ms later: ``` ERROR django.request: Internal Server Error: /jobs/companies/new/ File "/app/src/postulo/jobs/views.py", line 268, in form_valid response = super().form_valid(form) File "/app/src/postulo/jobs/forms.py", line 207, in save company = super().save(commit=commit) ... django.db.utils.OperationalError: database is locked ``` The company exists **once** (`pk 15`, `France Travail`, kind `employment_service`, created `14:23:16.291 UTC`), so no data was lost or duplicated. But the browser shows the response to the last request, so the person sees a 500 for something that worked. That invites a retry, and a retry creates a duplicate. ## Why Three things together: 1. **Nothing stops a form being sent twice.** `static/js/app.js` has no submit guard, and the company form has none of its own. A double click, or Enter and then a click, sends two POSTs. 2. **Three gunicorn workers write to one SQLite file** (`docker/Dockerfile`: `--workers 3`), so the two POSTs really do run at the same time. 3. **SQLite uses its defaults, and those fail instantly.** `DATABASES` in `config/settings/base.py` sets no `OPTIONS`. On ragnar: `journal_mode=delete`, `busy_timeout=5000`, `ATOMIC_REQUESTS=True`, Django 6.1.1. Every request is a `DEFERRED` transaction. The second request starts it with a read (the form's validation), then tries to upgrade to a write while the first holds the write lock. SQLite refuses that upgrade with `SQLITE_BUSY` straight away and does not wait out the busy timeout, since waiting could deadlock. That is why it failed in 100 ms and not after 5 s. Whatever takes the write lock early can hit this: a double submit, two tabs, or the browser extension capturing while someone edits. Companies are just where it showed first. `LogoFormMixin` also runs `logos.from_url` inside the request transaction, so a slow logo fetch holds the write lock for the whole network round trip and makes the window wider. ## What would fix it - **SQLite options in `base.py`** whenever the engine is sqlite3. Django 5.1+ supports all of these: - `"transaction_mode": "IMMEDIATE"`: the write lock is taken when the transaction begins, so a second writer *waits* (the busy timeout then applies) and is not refused. - `"init_command": "PRAGMA journal_mode=WAL; PRAGMA synchronous=NORMAL;"`: readers stop blocking the writer and the writer stops blocking readers. - An explicit `"timeout"` (for example 20 s) rather than relying on the 5 s default. - Check that `manage.py backup` still produces a consistent copy under WAL (the `-wal`/`-shm` files), and that the image's data volume allows them. - **A submit guard in `app.js`** for every `form[method=post]`: disable the submitter after the first submit, and re-enable it on `pageshow` so the back button does not leave a dead form. It must still work with the script blocked, which today's forms already do. - **Keep network I/O outside the write transaction** where it can be: fetch the logo before the insert, or after commit (`transaction.on_commit`). ## Tests - A test that `DATABASES["default"]["OPTIONS"]` gets `transaction_mode=IMMEDIATE` and WAL for a file database and leaves `:memory:` alone. - A threaded test against a file SQLite database: two concurrent company creations, both answer 302 or one answers a form error, never a 500. - An e2e test that double-clicking *Save* on the company form sends one POST.

tiagoagueda added this to the 0.3.0 milestone

2026-09-15 14:27:23 +00:00

tiagoagueda added the

bug

label

2026-09-15 14:27:23 +00:00

tiagoagueda referenced this issue from a commit

2026-09-15 15:40:04 +00:00

Let a SQLite file's writers take turns, and send a form once

tiagoagueda closed this issue

2026-09-15 15:40:04 +00:00

tiagoagueda referenced this issue