From 7f233101f30f0600b8cbaefeb559884e6e27c5ca Mon Sep 17 00:00:00 2001 From: Ayla Croft Date: Wed, 7 Oct 2026 19:49:36 -0400 Subject: [PATCH] test: a sandboxed test takes the write lock before it reads SCR-376, SCR-377 and SCR-378, the three findings left over from PR #113. The mechanism, already filed: Ecto.Adapters.SQL.Sandbox begins every test's transaction with an explicit mode: :transaction, which Exqlite.Connection resolves ahead of the configured default_transaction_mode: :immediate, and which is a plain DEFERRED BEGIN. So slice 005's fix never reached the suite. A test that reads and then writes is upgrading, and SQLite answers SQLITE_BUSY on an upgrade without consulting the busy handler, whatever busy_timeout says. Five failures across three tables came from that: gateway_identities twice, personas once, each time while the other run of the same commit passed. What was missing was not the mechanism but the premise for a fix. Measured now, as a third case in slice 005's own two-connection harness: a write that is the transaction's FIRST statement is not an upgrade, so the handler is consulted and the writer waits instead of failing. The case asserts both the success and, by elapsed time, that it genuinely contended rather than sailing through. So DataCase.setup_sandbox/1 issues one zero-row DELETE per repo before the test body runs. The table is the repo's own migration table read from its configuration, not assumed: Trinity.Repo.Receipts sets migration_source: "receipts_schema_migrations", and hard-coding schema_migrations failed every test using the template rather than only the receipts ones. SQLite only; Postgres has no SQLITE_BUSY and no upgrade path to guard. All five observed instances are covered. identities_test uses DataCase directly; approvals_test and subagents_test use SessionCase, which does `use Trinity.DataCase` internally, so they route through the same setup. I checked that rather than assuming it, having first read a grep that suggested the opposite. Cost: no change I can distinguish from this machine's run-to-run variance. 148.8 s before, 153.8 s after, on a suite that has reported times further apart than that between identical runs. The reason it is cheap is structural rather than lucky: every file using the template is async: false, so there is no concurrency to serialise. The only async: true occurrence of the template is its own documentation. SCR-378, separately. Trinity.SandboxTest's os.time and os.clock case inherited the default 1 s wall clock and failed once on a loaded runner, for a reason it was not about: it asserts the two functions are available. It now names a generous limit. That is not a weakening, because the limit's own binding is proven on its own by "an infinite loop is killed on wall clock and the caller is told which limit bound", which passes max_time_ms: 200 and asserts the refusal by value. A budget asserted in two places is a budget that gets loosened in the wrong one. mix gate: 952 passed, exit 0. Signed-off-by: Ayla Croft --- test/support/data_case.ex | 34 ++++++++++++++++++ .../repo/sqlite_transaction_mode_test.exs | 36 +++++++++++++++++++ test/trinity/sandbox/sandbox_test.exs | 12 +++++-- 3 files changed, 80 insertions(+), 2 deletions(-) diff --git a/test/support/data_case.ex b/test/support/data_case.ex index 6c8fa43..571b3b1 100644 --- a/test/support/data_case.ex +++ b/test/support/data_case.ex @@ -50,12 +50,46 @@ defmodule Trinity.DataCase do # test writes inside the test's sandbox and the rows go with it. rpid = Ecto.Adapters.SQL.Sandbox.start_owner!(Trinity.Repo.Receipts, opts) + # SCR-376 and SCR-377: make each sandboxed transaction a writer before it reads anything. + # + # `Ecto.Adapters.SQL.Sandbox` begins every test's transaction with an explicit + # `mode: :transaction`, which `Exqlite.Connection` resolves ahead of the configured + # `default_transaction_mode: :immediate`, and which is a plain DEFERRED `BEGIN`. So slice 005's + # fix does not reach the suite: a test that reads and then writes is upgrading, and SQLite + # answers `SQLITE_BUSY` on an upgrade **without consulting the busy handler**, whatever + # `busy_timeout` says. Five failures across three tables came from exactly that. + # + # A write that is the transaction's *first* statement is not an upgrade, so the handler is + # consulted and the writer waits instead of failing. That is measured, not assumed: + # `test/trinity/repo/sqlite_transaction_mode_test.exs` drives two connections through this + # exact sequence and asserts both the success and that it genuinely contended. + # + # `WHERE 1 = 0` touches no row. The table is the repo's **own** migration table, read from its + # configuration rather than assumed: `Trinity.Repo.Receipts` sets + # `migration_source: "receipts_schema_migrations"` (config/config.exs), and hard-coding + # `schema_migrations` here failed every test using this template, not only the ones that touch + # receipts. The statement is here for the lock it takes, not for the rows it does not change. + # + # Cost: measured as negligible, because there is nothing to serialise. Every file using this + # case template is `async: false` (the only `async: true` occurrence of it is this file's own + # documentation), so sandboxed tests already run one at a time. + Enum.each([Trinity.Repo, Trinity.Repo.Receipts], &take_write_lock/1) + on_exit(fn -> Ecto.Adapters.SQL.Sandbox.stop_owner(rpid) Ecto.Adapters.SQL.Sandbox.stop_owner(pid) end) end + # SQLite only. Postgres has no SQLITE_BUSY and no upgrade path to guard, so taking a lock there + # would be a cost with no reason. + defp take_write_lock(repo) do + if repo.__adapter__() == Ecto.Adapters.SQLite3 do + source = repo.config()[:migration_source] || "schema_migrations" + Ecto.Adapters.SQL.query!(repo, "DELETE FROM #{source} WHERE 1 = 0", []) + end + end + @doc """ A helper that transforms changeset errors into a map of messages. diff --git a/test/trinity/repo/sqlite_transaction_mode_test.exs b/test/trinity/repo/sqlite_transaction_mode_test.exs index 4c9c1b7..ce638c9 100644 --- a/test/trinity/repo/sqlite_transaction_mode_test.exs +++ b/test/trinity/repo/sqlite_transaction_mode_test.exs @@ -86,4 +86,40 @@ defmodule Trinity.Repo.SqliteTransactionModeTest do assert :ok = Sqlite3.execute(a, "INSERT INTO t (v) VALUES ('from a')") :ok = Sqlite3.execute(a, "COMMIT") end + + # Added 2026-10-07 for SCR-376 and SCR-377. The two cases above settle the question slice 005 + # asked: DEFERRED-then-upgrade cannot wait, IMMEDIATE can. Neither answers the question the + # **suite** poses, because `Ecto.Adapters.SQL.Sandbox` begins every test's transaction with an + # explicit `mode: :transaction`, which is a plain DEFERRED `BEGIN` and overrides + # `default_transaction_mode: :immediate`. The sandbox's BEGIN is not ours to change. + # + # So: inside a transaction that is already DEFERRED, does issuing a **write as the first + # statement** — no read, therefore no upgrade — reach the busy handler? If it does, a sandboxed + # test can be made a writer at its start and the five Database busy failures lose their + # mechanism. If it does not, there is no mitigation at this layer and saying so is the finding. + test "DEFERRED, first statement a write: the handler is consulted, because this is not an upgrade", + %{a: a, b: b} do + :ok = Sqlite3.execute(b, "BEGIN IMMEDIATE") + :ok = Sqlite3.execute(b, "INSERT INTO t (v) VALUES ('from b')") + + :ok = Sqlite3.execute(a, "BEGIN DEFERRED") + + started = System.monotonic_time(:millisecond) + task = Task.async(fn -> Sqlite3.execute(a, "INSERT INTO t (v) VALUES ('from a')") end) + Process.sleep(200) + :ok = Sqlite3.execute(b, "COMMIT") + result = Task.await(task, 5_000) + elapsed = System.monotonic_time(:millisecond) - started + + assert :ok = result, + "a first-statement write in a DEFERRED transaction was refused rather than waiting. " <> + "Then taking the write lock at the start of a sandboxed test is not a mitigation for " <> + "SCR-377, and the fix has to be somewhere else." + + assert elapsed >= 200, + "it returned in #{elapsed} ms, before the holder committed at 200 ms, so it never " <> + "contended and this case proves nothing" + + :ok = Sqlite3.execute(a, "COMMIT") + end end diff --git a/test/trinity/sandbox/sandbox_test.exs b/test/trinity/sandbox/sandbox_test.exs index 5ba7147..2a804b4 100644 --- a/test/trinity/sandbox/sandbox_test.exs +++ b/test/trinity/sandbox/sandbox_test.exs @@ -123,8 +123,16 @@ defmodule Trinity.SandboxTest do test "what survives is named rather than discovered: os.time and os.clock still work" do # Not a hole, and not an accident either. These reach no resource, but they are # non-deterministic, which matters when a script's output can reach a receipt. - assert {:ok, [_], _} = Sandbox.run("return os.time()") - assert {:ok, [_], _} = Sandbox.run("return os.clock()") + # + # SCR-378: the limit is named here, generously, and that is not a weakening. What this test + # asserts is that the two functions are **available**; the default wall clock it used to + # inherit was incidental to that, and on a loaded runner a trivial call exceeded it and the + # test failed for a reason it was not about. The limit's own binding is proven on its own, by + # "an infinite loop is killed on wall clock and the caller is told which limit bound", which + # passes its own `max_time_ms: 200` and asserts the refusal by value. A budget asserted in two + # places is a budget that gets loosened in the wrong one. + assert {:ok, [_], _} = Sandbox.run("return os.time()", max_time_ms: 30_000) + assert {:ok, [_], _} = Sandbox.run("return os.clock()", max_time_ms: 30_000) end end end