Postulo/postulo

Fork 0

The browser suite fails intermittently on a database connection nobody closed, and blames whichever test was running #294

New issue

Closed

opened 2026-09-20 16:51:08 +00:00 by tiagoagueda · 3 comments

tiagoagueda commented

2026-09-20 16:51:08 +00:00

Owner

Observation

uv run pytest -m e2e fails perhaps one run in two, on a different test each time, and
every one of those tests passes when run on its own. Five full local runs during #247 and
#292 failed on test_sticky_header twice, test_submit_guard twice and nothing once; CI's
browser job has failed the same way at least once (run 514, job 3109) on a commit whose
other seven jobs were green.

It is not those tests. The failure is:

E   ResourceWarning: unclosed database in <sqlite3.Connection object at 0x...>
E   pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing database
    connection <sqlite3.Connection object at 0x...>: None

Why it moves around

Three things combine:

A SQLite connection from the live-server thread is left for the garbage collector
rather than closed.
filterwarnings = ["error"] in pyproject.toml:154 promotes the ResourceWarning
that finalising it raises into an exception.
Nothing decides when the collector runs, so pytest's unraisable-exception plugin
attributes it to whichever test happens to be executing or setting up at that moment.

That is the whole explanation for the symptom that makes it look like a test bug: it
reproduces in a full run and never in isolation, because a short run does not give the
collector a reason to fire. It has been seen as a FAILED on a test body and as an
ERROR at setup of a later one, which is the same event landing a few milliseconds apart.

It is not new

tests/e2e/test_submit_guard.py:52-55 already names the symptom, in a comment written on
2026-09-16 (9ebde4779) about a different cause:

Back is a real page load since #226 turned off htmx's history cache, so asserting
straight away asks about a page that is still arriving -- and leaves the request in
flight while the test server is torn down underneath it, which surfaces as a database
connection finalised mid-query.

So one instance was found and fixed by waiting for the page. The general case -- a
connection outliving the thread that opened it, whatever the reason -- was not.

What it costs

A CI job that has to be looked at and usually dismissed, which is the expensive kind of
red: after the second dismissal nobody reads the third. It cost three investigations in
one session, and one of those was a real failure hiding behind the noise.

Worth deciding

Where the connection comes from. live_server runs Django in a thread; each thread
gets its own connection and close_old_connections is not called on the way out. Whether
it is the server thread, a request still in flight, or a fixture's own connection is the
first thing to establish -- the answer decides the fix.
Closing it rather than silencing it. A fixture that closes connections after each
browser test is the honest fix. Adding ResourceWarning to filterwarnings would make
the suite quiet and also make it blind: the same warning is how a genuinely leaked
connection would announce itself, and #226's real bug announced itself exactly this way.
Whether the same hole exists in the unit suite. It has never surfaced there, which
may mean it cannot happen or may mean nothing has made the collector fire at the wrong
moment yet.

Classification

Bug, in the tests rather than in Postulo. Nothing a person using Postulo can see.

## Observation `uv run pytest -m e2e` fails perhaps one run in two, on a *different test each time*, and every one of those tests passes when run on its own. Five full local runs during #247 and #292 failed on `test_sticky_header` twice, `test_submit_guard` twice and nothing once; CI's `browser` job has failed the same way at least once (run 514, job 3109) on a commit whose other seven jobs were green. It is not those tests. The failure is: ``` E ResourceWarning: unclosed database in <sqlite3.Connection object at 0x...> E pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing database connection <sqlite3.Connection object at 0x...>: None ``` ## Why it moves around Three things combine: 1. A SQLite connection from the live-server thread is left for the garbage collector rather than closed. 2. `filterwarnings = ["error"]` in `pyproject.toml:154` promotes the `ResourceWarning` that finalising it raises into an exception. 3. Nothing decides *when* the collector runs, so pytest's unraisable-exception plugin attributes it to whichever test happens to be executing or setting up at that moment. That is the whole explanation for the symptom that makes it look like a test bug: it reproduces in a full run and never in isolation, because a short run does not give the collector a reason to fire. It has been seen as a `FAILED` on a test body and as an `ERROR at setup of` a later one, which is the same event landing a few milliseconds apart. ## It is not new `tests/e2e/test_submit_guard.py:52-55` already names the symptom, in a comment written on 2026-09-16 (`9ebde4779`) about a different cause: > Back is a real page load since #226 turned off htmx's history cache, so asserting > straight away asks about a page that is still arriving -- and **leaves the request in > flight while the test server is torn down underneath it, which surfaces as a database > connection finalised mid-query.** So one instance was found and fixed by waiting for the page. The general case -- a connection outliving the thread that opened it, whatever the reason -- was not. ## What it costs A CI job that has to be looked at and usually dismissed, which is the expensive kind of red: after the second dismissal nobody reads the third. It cost three investigations in one session, and one of those was a real failure hiding behind the noise. ## Worth deciding - **Where the connection comes from.** `live_server` runs Django in a thread; each thread gets its own connection and `close_old_connections` is not called on the way out. Whether it is the server thread, a request still in flight, or a fixture's own connection is the first thing to establish -- the answer decides the fix. - **Closing it rather than silencing it.** A fixture that closes connections after each browser test is the honest fix. Adding `ResourceWarning` to `filterwarnings` would make the suite quiet and also make it blind: the same warning is how a genuinely leaked connection would announce itself, and #226's real bug announced itself exactly this way. - **Whether the same hole exists in the unit suite.** It has never surfaced there, which may mean it cannot happen or may mean nothing has made the collector fire at the wrong moment yet. ## Classification Bug, in the tests rather than in Postulo. Nothing a person using Postulo can see.

tiagoagueda added this to the 0.5.0 milestone

2026-09-20 16:51:36 +00:00

tiagoagueda added the

bug

label

2026-09-20 16:51:47 +00:00

tiagoagueda commented

2026-09-20 17:55:37 +00:00

Author

Owner

A third test, which is the point rather than a detail.

Two full browser runs back to back, same tree, nothing changed between them:

run 1:  FAILED tests/e2e/test_reflow.py::test_no_page_scrolls_sideways_at_320_pixels[chromium-el]
run 2:  FAILED tests/e2e/test_submit_guard.py::test_the_export_can_be_taken_twice[chromium]
        E  pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing
           database connection <sqlite3.Connection object at 0x...>: None

test_reflow passes 4/4 in isolation, all three languages, and passed in run 2. The
observed set is now test_sticky_header, test_submit_guard and test_reflow -- and the
last of those is the suite's longest test, which is what you would expect if the thing
being sampled is whatever happens to be executing when the collector fires.

Worth recording because of how it reads when it lands on a page test: the Greek reflow
failure looks exactly like a real 320-pixel overflow in a language nobody on the project
reads, which is a genuine bug this suite exists to catch. Ten minutes went into proving it
was not one. That is the cost of the noise, and it is larger than the red job itself.

A third test, which is the point rather than a detail. Two full browser runs back to back, same tree, nothing changed between them: ``` run 1: FAILED tests/e2e/test_reflow.py::test_no_page_scrolls_sideways_at_320_pixels[chromium-el] run 2: FAILED tests/e2e/test_submit_guard.py::test_the_export_can_be_taken_twice[chromium] E pytest.PytestUnraisableExceptionWarning: Exception ignored while finalizing database connection <sqlite3.Connection object at 0x...>: None ``` `test_reflow` passes 4/4 in isolation, all three languages, and passed in run 2. The observed set is now `test_sticky_header`, `test_submit_guard` and `test_reflow` -- and the last of those is the suite's longest test, which is what you would expect if the thing being sampled is *whatever happens to be executing* when the collector fires. Worth recording because of how it reads when it lands on a page test: the Greek reflow failure looks exactly like a real 320-pixel overflow in a language nobody on the project reads, which is a genuine bug this suite exists to catch. Ten minutes went into proving it was not one. That is the cost of the noise, and it is larger than the red job itself.

tiagoagueda commented

2026-09-22 08:13:24 +00:00

Author

Owner

A sixteen-second reproduction, and two hypotheses ruled out

Investigated without a fix landing. Recording it so the next attempt starts here rather
than at the beginning.

It can be reproduced in isolation after all

The issue says it "reproduces in a full run and never in isolation". That is true only
because nothing makes the collector fire. Add this to tests/e2e/conftest.py:

@pytest.fixture(autouse=True)
def _collect_deliberately():
    yield
    from django.db import connections
    connections.close_all()
    gc.collect()

and uv run pytest -m e2e --browser chromium tests/e2e/test_smoke.py fails every time, in
about sixteen seconds, as ERROR at teardown of test_the_critical_path. That is the
whole debugging loop, instead of seven minutes at roughly even odds.

It also does what the issue hoped for on a full run: the failure becomes an error at
teardown rather than a failure inside a random test body. It does not become
deterministic — three full runs blamed test_the_critical_path twice and
test_the_header_is_there_after_scrolling_and_an_anchor_clears_it once — so this is worth
having as a debugging aid and is not worth committing on its own: it converts an
intermittent red into a constant one.

Where the connection comes from

Patching sqlite3.connect and sqlite3.dbapi2.connect — Django's backend does
from sqlite3 import dbapi2 as Database and calls Database.connect, so patching only the
first sees nothing — and recording a stack per connection gives, at the end of the smoke
test, two connections open:

made on thread MainThread                      <- the test database, legitimately open
made on thread Thread-3 (process_request_thread)  <- the leak

with the second created through ensure_connection → connect() inside a live-server
request thread. So it is a handler thread's own connection, and the test thread cannot
reach it: connections.close_all() only ever sees the thread it runs on.

Two things it is not

Not the wrapper Django hands the thread. ThreadedWSGIServer.close_request already
calls connections.close_all() in the handler thread, and instrumenting it shows the
thread holding exactly one connection at that moment — the shared one from
connections_override. Whatever leaks is gone from the registry before the request ends.

Not the in-memory close() guard. The obvious theory was that Django makes close() a
no-op when is_in_memory_db(), so nothing ever shuts a connection a thread opened for
itself. Giving the browser suite a file-backed database through
django_db_modify_db_settings — verified applied — changes nothing: same failure, same
test, same sixteen seconds.

Where to look next

The connection is created during a request and is not in the registry when that request
ends. The remaining candidate is a keep-alive handler thread: daemon_threads = True,
so a thread still parked in handle() has neither returned nor reached close_request,
and its connection is only finalised when the process tears it down. That would explain
both the thread name and the absence at close_request time. Worth testing by closing the
browser context, or by taking keep-alive out of the test server, before anything else.

## A sixteen-second reproduction, and two hypotheses ruled out Investigated without a fix landing. Recording it so the next attempt starts here rather than at the beginning. ### It can be reproduced in isolation after all The issue says it "reproduces in a full run and never in isolation". That is true only because nothing makes the collector fire. Add this to `tests/e2e/conftest.py`: ```python @pytest.fixture(autouse=True) def _collect_deliberately(): yield from django.db import connections connections.close_all() gc.collect() ``` and `uv run pytest -m e2e --browser chromium tests/e2e/test_smoke.py` fails **every time, in about sixteen seconds**, as `ERROR at teardown of test_the_critical_path`. That is the whole debugging loop, instead of seven minutes at roughly even odds. It also does what the issue hoped for on a full run: the failure becomes an *error at teardown* rather than a failure inside a random test body. It does not become deterministic — three full runs blamed `test_the_critical_path` twice and `test_the_header_is_there_after_scrolling_and_an_anchor_clears_it` once — so this is worth having as a debugging aid and **is not worth committing on its own**: it converts an intermittent red into a constant one. ### Where the connection comes from Patching `sqlite3.connect` *and* `sqlite3.dbapi2.connect` — Django's backend does `from sqlite3 import dbapi2 as Database` and calls `Database.connect`, so patching only the first sees nothing — and recording a stack per connection gives, at the end of the smoke test, two connections open: ``` made on thread MainThread <- the test database, legitimately open made on thread Thread-3 (process_request_thread) <- the leak ``` with the second created through `ensure_connection` → `connect()` inside a live-server request thread. So it is a handler thread's own connection, and the test thread cannot reach it: `connections.close_all()` only ever sees the thread it runs on. ### Two things it is *not* **Not the wrapper Django hands the thread.** `ThreadedWSGIServer.close_request` already calls `connections.close_all()` in the handler thread, and instrumenting it shows the thread holding exactly one connection at that moment — the shared one from `connections_override`. Whatever leaks is gone from the registry before the request ends. **Not the in-memory `close()` guard.** The obvious theory was that Django makes `close()` a no-op when `is_in_memory_db()`, so nothing ever shuts a connection a thread opened for itself. Giving the browser suite a file-backed database through `django_db_modify_db_settings` — verified applied — changes nothing: same failure, same test, same sixteen seconds. ### Where to look next The connection is created during a request and is not in the registry when that request ends. The remaining candidate is a **keep-alive handler thread**: `daemon_threads = True`, so a thread still parked in `handle()` has neither returned nor reached `close_request`, and its connection is only finalised when the process tears it down. That would explain both the thread name and the absence at `close_request` time. Worth testing by closing the browser context, or by taking keep-alive out of the test server, before anything else.

tiagoagueda referenced this issue from a commit

2026-09-23 13:43:19 +00:00

Close the database connections the live server's dead threads leave behind

tiagoagueda commented

2026-09-28 12:07:18 +00:00

Author

Owner

Landed on main as 30b132e42. Closing.

The last lead in the investigation above was the right one, one step further on: the connection belonged to a live-server worker thread that had finished and never reached close_request, so nothing in the thread's own registry was left to close it and the collector found it whenever it next ran, inside whichever test was executing. The fix does on time what the dead thread would have done: the browser suite sweeps the connections the live server's dead threads leave behind, so the collector is left nothing to find, and the ResourceWarning stays switched on to announce a leak that is genuinely new.

tests/e2e/test_db_leak_guard.py plays the worker: a thread that shares the server's wrapper, reads the database, then hosts an event loop that reads it again, which is the shape of the PDF request. Without the sweep it fails.

The browser job is green on the current head, e143fc80d. Two runs on this machine on 2026-09-22, before the fix, were the last seen to blame a test at random (test_submit_guard and test_sticky_header, neither with an assertion in the log). If it comes back, reopen this rather than filing it again: the sixteen-second reproduction above still applies.

Landed on `main` as `30b132e42`. Closing. The last lead in the investigation above was the right one, one step further on: the connection belonged to a live-server worker thread that had finished and never reached `close_request`, so nothing in the thread's own registry was left to close it and the collector found it whenever it next ran, inside whichever test was executing. The fix does on time what the dead thread would have done: the browser suite sweeps the connections the live server's dead threads leave behind, so the collector is left nothing to find, and the `ResourceWarning` stays switched on to announce a leak that is genuinely new. `tests/e2e/test_db_leak_guard.py` plays the worker: a thread that shares the server's wrapper, reads the database, then hosts an event loop that reads it again, which is the shape of the PDF request. Without the sweep it fails. The browser job is green on the current head, `e143fc80d`. Two runs on this machine on 2026-09-22, before the fix, were the last seen to blame a test at random (`test_submit_guard` and `test_sticky_header`, neither with an assertion in the log). If it comes back, reopen this rather than filing it again: the sixteen-second reproduction above still applies.

tiagoagueda closed this issue

2026-09-28 12:07:19 +00:00