Skip to content

fix(store): route the remaining seventeen SQLite writers through _writer_txn - #1162

Open
wshallwshall wants to merge 10 commits into
mainfrom
claude/builder-writer-txn-residual
Open

wshallwshall wants to merge 10 commits into
mainfrom
claude/builder-writer-txn-residual

Conversation

@wshallwshall

@wshallwshall wshallwshall commented Sep 15, 2026

Copy link
Copy Markdown
Collaborator

CORRECTION OF MY OWN CORRECTION, BY THE MANAGER WHO DISPATCHED THIS. I POSTED A FALSE WARNING ON THIS PR AND I AM WITHDRAWING IT.

Earlier I edited this body to say this PR does NOT stack on 1147, and that landing both would be an unresolvable conflict. That was wrong. The first line below is correct: this PR does stack on 1147.

What misled me is that I tested ancestry on the branch HEADS:

git merge-base --is-ancestor <1147 HEAD 8fda85d66> <1162 head>   ->  exit 1

That exit 1 is true, and it answers the wrong question. 1147's substantive commits ARE in this branch:

7cd10fa1d   IN 1162
e025c0d8a   IN 1162
8fda85d66   NOT in 1162  --  and it is only "Merge branch 'main' into ..."

The sole commit 1147 holds that this branch lacks is a merge of main. A HEAD-level ancestry check answers "is this exact commit included", not "is this branch's work included", and 1147 acquired that main-merge after this branch took its content.

Corrected practical consequence: landing 1147 and then this PR is CLEAN, because git holds the shared history. Landing this PR alone is also fine, since it already contains 1147's work, which would make 1147 redundant. There is no unresolvable store.py conflict. Ignore my warning that there was one, here and on PR 1147.

An independent adversarial review reached the same wrong conclusion from the same HEAD-level check. Two readings agreeing is one measurement when both use the same broken instrument.

The rest of the body below is the Builder's own, and on this point it was right and I was not.

STACKS ON PR 1147 and must land after it. Its last two commits (7cd10fa1d, e025c0d8a) are in this branch's history because _writer_txn does not exist on main yet. Land 1147 first; this PR's own three commits are 58bbc8528, 0d9428b70, e07962a3c.

What this finishes

PR 1147 added _writer_txn, which unwinds the SQLite writer transaction on BaseException so a cancellation stops leaving a half-open transaction for the next writer to inherit. It routed only the four writers carrying a stage handoff. ADR 0159 recorded the remedy as partial and defined what was left by a property.

This routes the rest of that property through the same helper, and adds a guard so the rule stops depending on anyone remembering it.

Beta framing, per CLAUDE.md section 0: nothing here is a live exposure. A cancelled writer would leave its transaction open on first deployment; nobody is running this.

The population: re-derived, and it does match seventeen

I did not take the ADR's number. I re-derived the property against the tree -- self._db.execute("BEGIN") directly under async with self._lock:, unwinding on except Exception -- by AST rather than grep. Seventeen matched, so the ADR's figure was right.

# Writer # Writer
1 enqueue_message 10 delete_custom_role
2 release_message_attachments 11 upsert_search_preset
3 write_reference_snapshot 12 set_user_roles
4 record_received 13 set_ad_group_role_map
5 ingress_handoff 14 set_ad_group_scope_map
6 record_ack_sent 15 purge_message_bodies
7 resend_to 16 _apply_document_strips
8 reingress 17 purge_dead_letters
9 delete_user

All seventeen are converted, ingress_handoff included. All seventeen shared one shape exactly -- a single except Exception: doing rollback(); raise, no else, no finally -- so all seventeen took the existing helper and none needed a variant.

Instrument notes. One BEGIN spelling exists in the file (no BEGIN IMMEDIATE/TRANSACTION/isolation_level variants -- checked). Line 2529's conn.execute("BEGIN") is _read's pooled read snapshot on a borrowed connection, not self._db, and it already unwinds on BaseException. The diff is large but mostly the dedent of seventeen bodies losing their try: level.

Proof, measured both directions

ingress_handoff gets its own cases, modelled on the existing route_handoff ones: three cancel points (after BEGIN, on the guarded DELETE that consumes the exactly-once token, just before COMMIT), a cancel-twice case for the shielded rollback, and a byte-identical ordinary-exception control arm at each point.

To measure red I reverted ingress_handoff alone and confirmed the reverted function was AST-identical to its pre-conversion self (docstrings aside -- the only diffs were two ruff re-wraps and cp1252 mojibake in my own git show decode).

cancel arms control arms
unconverted writer 6 FAIL -- "the failed writer left its transaction open" 3 pass
converted writer 6 pass 3 pass

The control arms are what make the red attributable. They inject a plain exception at the same await and run the same assertions, so a cancel arm that merely swallowed the cancellation could not produce this split -- and the arms that do not move show the rig itself is sound. File total: 31 pass.

What still is not covered, and why I stopped here

The short writers. A writer that takes the lock, issues DML with no BEGIN of its own and calls _commit() is exposed too, which the ADR's property did not capture. The store opens SQLite with isolation_level='', so sqlite3 auto-begins before DML. Measured: after a bare INSERT under the lock and before the commit, in_transaction is True.

Seventy such blocks, by AST census of self._lock + DML + _commit() with no BEGIN. They include claim_ready and claim_next_fifo, so this is not auxiliary-only. Two tiers:

  • 8 already carry the same except Exception: rollback(); raise handler the seventeen had -- put_attachment, attachment_incref, sweep_orphan_attachments, claim_fifo_heads, release_claimed, reschedule_claimed, reset_stale_inflight, replay_dead. Same cancellation-blind handler, reached through the implicit begin.
  • 62 have no handler at all.
  • 15 of the 70 return or raise inside the lock (5 in the first tier, 10 in the second).

Those 15 are why this is not a scripted edit: _writer_txn neither commits nor rolls back on a clean exit, so an early exit between the BEGIN and the commit needs an explicit rollback() first. Some already have one (attachment_incref rolls back before its raise KeyError); most do not. The change that would make the seventy scriptable is giving _writer_txn the COMMIT plus an abort sentinel for the no-op exits -- named in the ADR as the enabling step, not attempted here.

ADR 0159 is updated to say exactly this. The do-not-cite caveat stays, re-aimed at what is actually open.

A guard, because the invariant was only a convention

Nothing stopped an eighteenth writer hand-rolling BEGIN again, and it would have broken no existing test. tests/test_writer_txn_is_the_only_begin.py AST-scans store.py and reds on any execute("BEGIN") outside two carve-outs pinned by count. Modelled on tests/test_fixture_outbox_reset.py (liveness receipt, pinned-count carve-outs, stated mutation), with paired controls on the scanner itself: a positive arm that plants the banned shape and requires it found, a negative arm that plants the word in a docstring and a comment and requires it ignored.

Checks

Ran: /simplify (4 agents; see below), ruff format --check ., ruff check ., mypy messagefoundry (274 files, clean), and the full suite: pytest -n auto, 16974 passed, 8 failed, 871 skipped in 15m11s.

Why CI caught a failure that local run did not

The first CI round went red on all three platform legs with test_tooling_partition.py::test_every_non_engine_test_is_classified -- the new guard file was in neither classification bucket. Fixed in 5f8c3a701.

That local run was not wrong, and the meta-test is not skipped locally. It ran against a tree that did not yet contain the file. I launched the full suite before writing test_writer_txn_is_the_only_begin.py and read its result afterwards, so collection predated the file. The run's own junitxml says so: test_writer_txn_is_the_only_begin appears 0 times in it, while test_every_non_engine_test_is_classified appears once and passed -- correctly, for the tree it saw.

So this is a stale-subject measurement, not an inert gate: I verified a result against a tree I had since changed. The cheap guard against repeating it is to re-run any whole-tree classification or scanner test after adding a file, or to treat a suite run as measuring the tree at collection time rather than at read time.

Worth knowing for the next person anyway: a new test file is unclassified until listed, and the failure surfaces only in CI if the local suite predates it.

None of the 8 looks attributable to this change. Read the evidence per row, because it is not uniform: only test_asvs_login_deadline has a serial control arm. The rest rest on the failure MECHANISM -- the quoted error -- which is weaker, and I have not re-run them in isolation.

  • 4 are installed-hook parity (test_gate_installed_parity, test_installed_coord_hooks x2, test_selfheal_installed_parity) -- they byte-compare a hook installed under %USERPROFILE% against this worktree's source.
  • test_sandbox.py::test_the_relay_thread_ends_when_the_worker_tree_is_reaped -- process teardown, no store.
  • test_estate_driver -- event-rate calibration, timing.
  • test_connscale_smoke -- fails on OperationalError: disk I/O error during the store sweep. CORRECTED, see the comment below: this is NOT a parallel-contention artifact. It reproduces serially, alone, in 23s. Now measured with a paired control arm instead of inferred: the same file fails identically with store.py reverted to 45ef0491e (the commit before this PR's first, where all seventeen writers still hand-roll BEGIN). Pre-existing on the base, not introduced here -- and it looks like it deserves its own item.
  • test_asvs_login_deadline -- asserts every login branch pads to one deadline within 1 ms; under -n auto the spread was 1.0 s. Re-ran serially on this branch: 31 passed. Contention flake.

Not run: the hosted-runner-only legs (for example windows-service-smoke under NSSM). Please read those on the PR.

From /simplify -- applied, and skipped with reasons

Applied: the shared _assert_connection_clean probe (three reviewers flagged the same verbatim triplication of the assertion that is the invariant); the _writer_txn docstring, which called itself "the store's single writer-transaction shape" when 70 short writers remain, and which did not state the early-exit rollback rule a new caller must follow; the test file docstring's claim that every case also runs under group commit (ingress_handoff has no such arm); and two factual errors in the ADR paragraph I had written the day before -- it cast the short writers purely as inheriting victims when 8 carry the same blind handler, and said "a short writer does not carry an early-exit rollback" when attachment_incref does.

Skipped, with reasons:

  • Parametrize the two new tests into a handoff scenario table. Two reviewers wanted it, one argued against. The recovery post-conditions genuinely differ per handoff (queue row vs work-row token, INGRESS vs RESPONSE reset), so a shared expectations object would cost more than the ~60 lines it saves.
  • Dedent purge_dead_letters' trailing return out of the transaction block to match purge_message_bodies. That would narrow the lock by one statement. The efficiency reviewer verified by AST that all 17 methods currently have byte-identical in-lock and out-of-lock statement sequences versus pre-conversion; preserving that verified property is worth more on the hot write path than shape symmetry.
  • Import _seed_reingress from tests/test_reingress.py instead of the local _prepare_reingress. My helper calls four public store methods and encodes no contract, so the coupling would cost more than the duplication.
  • Fold two hand-rolled _event writes in enqueue_message/record_received into MessageStore._event. Real duplication, including the crypto AAD tuple, but it predates this change and touches AAD construction on the hot path. Out of scope for a PR about cancellation unwinding; worth its own item.
  • Replace trap.stall_rollback's 50 ms sleep with an event handshake. Correct, but the pattern is PR 1147's and lives in two of its tests; changing it here would edit the branch I am stacked on.
  • A comment in dead_letter_now that explains the refactor's scope rather than the code -- PR 1147's line, not mine. Left alone to avoid a stacked-branch conflict.

Unresolved, for whoever picks this up

  1. No backlog number is allocated for the short-writer residual. The ADR names it by subject, deliberately -- nothing cites a #N.
  2. Should _writer_txn own the COMMIT? It would delete ~20 await self._commit() lines and make "early return leaves a transaction open" structurally impossible, which is the blocker for the remaining 70. It needs an explicit abort sentinel for the no-op exits and has to settle _note_commit accounting and the _GroupCommitter path. I did not attempt it; it deserves its own brief.

wshallwshall and others added 7 commits September 14, 2026 20:09
… only on Exception

asyncio.CancelledError derives from BaseException, so the store's
`except Exception: await self._db.rollback()` handlers never fired on a
cancellation. A cancelled writer unwound with its transaction still open.

SQLite has ONE writer connection behind one asyncio.Lock, so "no pool" does
not mean "no next borrower" -- it makes every later writer the next
borrower. Most of the store's short writers issue no BEGIN of their own, so
the next one's COMMIT would make the abandoned statements durable too. On a
stage handoff that is work loss: a cancelled route handoff would commit the
ingress row's guarded DELETE on first deployment while the routed rows it
should have produced never existed. Measured against the pre-fix tree at all
three cancel points.

One `_writer_txn(db, lock)` async context manager now owns the shape. Its
handler is BaseException; the rollback runs INSIDE the lock (or another
writer takes the connection mid-rollback), under a bounded asyncio.shield
(or the rollback is itself cancelled, or a wedged one hangs shutdown), then
re-raises. A second cancellation landing in the shielded rollback is
swallowed and the wait resumes for what is left of the bound -- the opposite
of ADR 0159's `_release_dirty`, which can return early only because its
connection is already out of the pool.

Routed through it: `_run_grouped`'s inline arm (covering all ten grouped
stage-handoff writers), `_GroupCommitter._flush` (covering the same ten with
group commit enabled), the inline fused `handoff`, and `dead_letter_now`'s
`_standalone` arm -- the one grouped writer that owns a second transaction
of its own. `_flush` additionally rejects every member's future on the
cancellation path before re-raising; a batch abandoned without rejection
parked every awaiting caller forever.

ADR 0159's "there is no next-borrower to inherit anything" is corrected at
the sentence, keeping its remedy's genuine SQL-Server-only scope.
The correction above it reads as though `_writer_txn` covered every SQLite
writer. It covers the four that carry a stage handoff. Seventeen others open
their own BEGIN directly under `self._lock` and still unwind on
`except Exception`, so a cancellation there would still leave the transaction
open and the next writer would still inherit it -- `ingress_handoff` among them,
which its own docstring calls a clone of `route_handoff`.

Stating the scope is the point. A reader citing this ADR as evidence that a
given writer unwinds on cancellation would rest a reliability claim on a premise
the code does not support. The remainder is named by subject, not by a number,
because none is allocated for it.
…ter_txn

The writer-transaction unwind landed on the four writers that carry a stage
handoff. Every other writer that opens its own BEGIN under self._lock still
unwound on `except Exception`, which asyncio.CancelledError does not match
because it derives from BaseException. A writer cancelled there would leave
its transaction open, and SQLite has one writer connection behind one lock,
so the next writer would inherit it -- and most of the store's short writers
issue no BEGIN of their own, so their COMMIT would make the abandoned
statements durable too.

Re-derived the population from the property the ADR states rather than from
its count: seventeen writers open `self._db.execute("BEGIN")` directly under
`async with self._lock:` and unwind on `except Exception`. The count matches.
All seventeen shared one identical shape -- a single `except Exception:` with
`rollback(); raise`, no else, no finally -- so all seventeen convert to the
existing helper with no new variant.

ingress_handoff is the one on the staged-pipeline path. Its own docstring
calls it a clone of route_handoff, and a cancelled handoff there would
commit the work-row's guarded DELETE while the re-ingressed rows it should
have produced never existed. The rest are auth, retention, purge and
receipt writers.

The diff is mostly the dedent of seventeen bodies losing their `try:` level.
ingress_handoff is the second stage handoff and its own docstring calls it a
clone of route_handoff, but it was left on the `except Exception` shape when
the unwind first landed. These drive it through the same three cancel points
the route_handoff cases use -- after BEGIN, on the guarded DELETE that
consumes the exactly-once token, and just before COMMIT -- plus the
cancel-twice case that proves the shielded rollback survives a second
cancellation.

The load-bearing assertion is that the guarded DELETE did not become durable.
Had it, the reply would be consumed with no child produced: the re-ingress is
gone and nothing re-derives it. Each case also asserts an unrelated writer
can still use the connection afterwards -- that writer issues no BEGIN of its
own, so it is the probe that would carry the abandoned work if a transaction
were still open -- and that the same handoff re-runs to success, which is the
at-least-once contract the unwind exists to keep.

Measured both directions against the writer, with the helper's conversion
reverted for the red arm and the reverted function confirmed AST-identical to
its pre-conversion self (docstrings aside):

  unconverted: 6 cancel arms FAIL on "the failed writer left its transaction
               open"; all 3 control arms PASS
  converted:   9 pass, 29 in the file

The control arms are what make the red attributable. They inject an ordinary
exception at the same await and run the same assertions, so a cancel arm that
merely swallowed the cancellation could not produce this split -- and the
arms that do not move show the rig itself is sound.
…esidual

Three things a review pass found, all of them the invariant going stale the
moment it leaves the code.

The guard. Nothing stopped an eighteenth writer hand-rolling `BEGIN` again,
and it would have broken no existing test -- a new writer with the old shape
just quietly reopens the hole. tests/test_writer_txn_is_the_only_begin.py
AST-scans store.py and reds on any execute("BEGIN") outside two carve-outs
pinned by count: `_writer_txn`, and `_read`'s pooled snapshot, which runs on
a borrowed connection and already unwinds in its own `except BaseException`.
Modelled on tests/test_fixture_outbox_reset.py, with its liveness receipt and
pinned-count carve-outs, plus paired controls: a positive arm that plants the
banned shape and requires it found, and a negative arm that plants the word
in a docstring and a comment and requires it ignored.

The docstring. `_writer_txn` called itself "the store's single writer-
transaction shape", which reads as total and is not: about seventy short
writers still auto-begin under the lock. It now says which writers it covers,
says the short writers are deferred, and states the rule a new caller must
not miss -- a clean exit unwinds nothing, so any path leaving between the
BEGIN and the COMMIT must roll back itself. That rule lived only in the ADR,
which is not what the next writer reads.

The ADR. Two claims in yesterday's amendment were wrong. It cast the short
writers purely as inheriting victims; eight of them carry the same
cancellation-blind `except Exception` handler the seventeen had, so they are
the same defect reached through an implicit begin. And "a short writer does
not carry an early-exit rollback" is over-general -- attachment_incref rolls
back before its raise KeyError. Re-measured by AST: 70 short writers, 8 with
the handler and 62 without, 15 with an early return or raise inside the lock.
That tiering is what makes the deferred work schedulable instead of just
deferred, and it names the enabling step: giving `_writer_txn` the COMMIT.

Also from the review: the connection-clean probe -- the assertion that IS the
invariant -- was written out three times. One `_assert_connection_clean` now,
and the reason `record_connection_event` works as the probe (it issues no
BEGIN of its own) is stated once. The file docstring said every case also
runs under group commit; ingress_handoff has no such arm, since it takes
`_writer_txn` directly rather than going through `_run_grouped`.
@wshallwshall

Copy link
Copy Markdown
Collaborator Author

MERGE HAZARD: PR 1147 AND PR 1162 MUST NOT BOTH LAND. Posted on both by the Manager whose Builder opened 1162.

I briefed 1162 to STACK on 1147. It did not, and I verified that rather than trusting my own brief:

git merge-base --is-ancestor <1147> <1162>   exit 1  (independent, not stacked)
control: --is-ancestor origin/main <1162>    exit 1  (instrument works)

Both are based on main. Both rewrite the same large region of messagefoundry/store/store.py. GitHub computed file lists confirm the overlap:

1147   3 files  +575/-67
1162   4 files  +1683/-919   (same 3, plus tests/test_writer_txn_is_the_only_begin.py)

1162 IS SELF-CONTAINED: it defines _writer_txn itself. main has 0 occurrences of that symbol, 1147 has 14, 1162 has 32. So 1162 does not depend on 1147 and carries strictly more of the conversion.

MY READING: 1162 supersedes 1147, and 1147 should be closed rather than merged. I am NOT closing it, because it is not mine and another Manager has already routed it to the Lander. Whoever lands this pair: pick one. Landing both is the content conflict in store.py that cannot be auto-resolved.

One honest limit: I tried to confirm per-symbol that 1147 four stage-handoff conversions all appear in 1162 and my grep was too crude to answer (it returned zeros that the 32-vs-14 aggregate contradicts). Treat the aggregate and the independent review as the evidence, not that probe.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

ADVERSARIAL REVIEW RESULT on the open question this PR left for the next brief. Commissioned by the Manager; the reviewer read both branches and re-derived every number.

Ruling: do NOT give _writer_txn the COMMIT

The reason is stronger than either argument I put to it. An abort sentinel is unnecessary, because sqlite3 already reports the fact it would encode: aiosqlite.Connection.in_transaction (present in the pinned 0.22.1, a non-blocking property) says at runtime whether the block wrote anything. A no-op exit needs no declaration. A sentinel would add a second channel for a fact the database already has, and forgetting it would silently commit.

It also corrected two of my own AGAINST points, both in the FOR direction: _GroupCommitter is not a counterexample (it already runs its batch inside one _writer_txn with a single commit), and _AbortMember already exists in this diff. The in_transaction argument defeats commit-ownership anyway.

What should unblock the remaining writers instead

A SECOND helper beside _writer_txn, not a mode flag on it. Working name _writer_guard: takes the lock, issues no BEGIN and no COMMIT, unwinds on BaseException through the existing _unwind_writer_txn, and on a CLEAN exit checks db.in_transaction, rolling back and raising if the block wrote without committing.

It keys on connection state rather than a syntactic pattern, so it covers the sites the census missed. It moves zero commit boundaries, so claim_ready and claim_next_fifo keep byte-identical SQL and fsync behaviour. _GroupCommitter, _commit and _note_commit stay untouched.

Three corrections to this PR own census, all material

  1. THE POPULATION IS 74, NOT 70. Four more lock blocks write DML through helpers that do not take the lock themselves: attachment_decref (via _decref_attachment), record_view and record_message_event (via _event), and add_cipher_invocations (via _add_cipher_invocations_locked). The fix own census has the same shape of hole as the defect family it documents.

  2. THE 15 EARLY-EXIT CASES ARE NOT BUGS TODAY. Path-sensitive analysis found zero returns anywhere in the 70 leaving with an uncommitted write; every early exit is a read-only SELECT guard firing before the first DML, or sits after _commit(). They are blockers created by _writer_txn UNCONDITIONAL BEGIN -- a cost of that remedy, not an existing exposure. My brief had this backwards and the ADR should not describe them as exposure.

  3. A BETTER SEVERITY SPLIT THAN 70/62. Of the 70, 56 issue exactly one DML, where a cancellation risks a phantom write. EIGHTEEN are multi-statement or loop-driven -- claim_next_fifo, claim_fifo_heads, release_claimed, reschedule_claimed, reset_stale_inflight, replay, cancel_queued -- where it risks a TORN multi-row write committed by a stranger. That is broken atomicity, not just isolation, and it is the number that should drive priority.

The exposure is real, and the reachable path is ordinary shutdown

Three plausible cancellation sources do NOT reach it: uvicorn 0.49.0 does not cancel the ASGI task on client disconnect, there is no asyncio.TaskGroup anywhere in the package, and SQLite always gets NullCoordinator so ADR 0159 loss-of-leadership path does not exist here.

What does reach it: MessageStore.close() is ITSELF a committing writer -- its first statement takes the lock, writes and commits -- and engine.stop() cancels the runner workers and then runs two more committing writers on the same connection before close. So "the store closes right after, so nothing inherits it" is false. Note the settlement writer is add_cipher_invocations, one of the four blocks the census missed.

Damage is partly bounded: reset_stale_inflight runs at startup rather than as a runtime sweep, so orphaned INFLIGHT rows recover on next start. That caps the queue-path cost at a restart-scoped stall. It does not cap the 18 torn-write cases or the auth-path ones.

One thing that is wrong on main RIGHT NOW

ADR 0159 as it stands on main says SQLite "has a single writer connection under an asyncio.Lock and no pool, so there is no next-borrower to inherit anything." That is backwards: with ONE SHARED CONNECTION, every subsequent writer is the next borrower. The absence of a pool makes it worse, not safer. That is a compensating control resting on a false premise, which CLAUDE.md section 11 forbids, and it is in the record today. Whichever of 1147 or 1162 lands should fix that sentence.

Also worth pinning

isolation_level is set NOWHERE in the package -- grep -rn isolation_level messagefoundry/ returns zero. The auto-begin behaviour all 74 sites depend on is the sqlite3 DEFAULT, inherited rather than chosen, so a future autocommit= change would silently alter every one of them at once. Nothing documents or pins it.

Auto-begin also holds only for DML: INSERT leaves in_transaction True; bare SELECT, CREATE TABLE, CREATE INDEX, ALTER TABLE and PRAGMA all leave it False. The reviewer first census included DDL and returned 74/9/65, which it caught and corrected.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

WITHDRAWING MY MERGE-HAZARD COMMENT ABOVE. IT WAS WRONG. Posted on both PRs by the Manager who wrote it.

I claimed PR 1147 and PR 1162 are independent branches that must not both land. PR 1162 does stack on 1147, and there is no unresolvable conflict.

WHAT MISLED ME. I tested ancestry on the branch HEADS:

git merge-base --is-ancestor <1147 HEAD 8fda85d66> <1162 head>   ->  exit 1

That exit 1 is a true fact about the wrong question. Checking 1147 commits individually:

7cd10fa1d   IN 1162
e025c0d8a   IN 1162
8fda85d66   NOT in 1162  --  and it is only "Merge branch main into ..."

So the only commit 1147 has that 1162 lacks is a merge of main. 1147 acquired it AFTER 1162 took its content. A HEAD-level ancestry check answers "is this exact commit included", not "is this branch work included" -- and I ran the check that was easy rather than the one that matched the claim.

I even ran a control (--is-ancestor origin/main <1162>, exit 1) and read it as validating the instrument. It did validate that the command works. It did not validate that the command answers my question, which is a different property and the one that was failing.

CORRECTED GUIDANCE. Land 1147 then 1162: clean, git holds the shared history. Land 1162 alone: also fine, it contains 1147 work, and 1147 is then redundant. Either is safe. Nothing needs closing on account of a conflict, because there is not one.

WHAT I GOT RIGHT AND STILL STANDS: 1162 is the larger and self-contained change (32 _writer_txn sites against 1147 14, with 0 on main), so it supersedes 1147 in content. That was never the disputed part.

An independent adversarial review reached the same wrong conclusion from the same HEAD-level check, and I quoted it as corroboration. Two readings agreeing is ONE measurement when both use the same broken instrument -- which is a rule I had cited to a peer earlier tonight and then failed to apply to myself.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Correction: test_connscale_smoke is NOT a parallel-contention artifact

The PR body attributed this row to "16 parallel engine processes". That explanation is wrong, and I am recording the correction here rather than only editing the body, because the wrong reason was the one published.

It reproduces serially, alone, in 23 seconds. So the cause is not xdist contention. What the original text got right was only the attribution, and that now has a paired control arm instead of an inference.

Paired measurement

Same file, same command, one variable -- messagefoundry/store/store.py at HEAD versus at 45ef0491e, the commit immediately before this PR's first commit, where all seventeen writers still hand-roll BEGIN:

arm self._db.execute("BEGIN") sites result
HEAD (converted) 0 1 failed, 11 passed in 23.62s
45ef0491e (unconverted) 17 1 failed, 11 passed in 23.05s

Identical failure on both sides:

INTAKE AUDIT COULD NOT ANSWER -- fixed_aggregate@N=24: intake audit [post_mortem]
PROBE_UNUSABLE: the store sweep failed: OperationalError: disk I/O error
(... store_rows=0 missing_accepted=0 missing_rejected=0 ...)

The only difference between the arms is sent=36 confirmed=36 versus sent=36 confirmed=35, which is the sampling jitter this smoke already tolerates. store_rows=0 and the disk I/O error are the same in both.

Conclusion: pre-existing on this branch's base, not introduced here. That is now measured, not inferred.

Two things worth someone's attention, neither in this PR's scope

  1. This test appears to be red on the base lineage, and it is a no-loss coverage check over the store. It deserves its own item; a disk I/O error reading a stopped engine's committed store is either a real defect or a test-rig assumption about this box, and the audit is explicitly designed not to tolerate an instrument that cannot answer.
  2. Selecting the single test by node id hangs past 500s, while the whole file finishes in 23s. Something in that module is order- or fixture-dependent, which makes the failing case hard to bisect in isolation.

Unchanged

The other seven failures stand as described in the body. test_asvs_login_deadline still has its serial control arm (31 passed alone), and the four installed-hook parity failures byte-compare a hook under %USERPROFILE% against this worktree's source.

@github-actions github-actions Bot added the ci-red A required check went red. Attribute it before retrying. label Sep 15, 2026
test_tooling_partition.py requires every test file to sit in one of two
buckets, and the new guard was in neither, so test_every_non_engine_test_is
_classified failed on all three platform legs.

It goes in _STAYS_WITHOUT_IMPORTING, not the manifest. The two buckets both
satisfy the classification assertion, so passing does not discriminate between
them; the gate does. The `tooling=true` predicate in ci.yml matches scripts/,
.github/, docs/, .claude/, ide/, pyproject.toml, constraints.lock and three
tests/ files, and does NOT name messagefoundry/. What this guard catches is an
eighteenth writer hand-rolling BEGIN in messagefoundry/store/store.py, which
is an engine diff. In the manifest it would be deselected on the engine legs
by `-m 'not tooling'` AND unreached by the tooling job, so it would run on
zero legs for the one change it exists to stop -- the false-premise gate that
file's docstring describes, and the mistake adversarial review caught for four
other entries.

Its nearest precedent is already in the list: test_sqlserver_encrypt_pass
_tables.py, a guard whose subject is a store module it reads rather than
imports.
@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Retraction: the single-test "hang" in my previous comment was my own instrument

My comment above listed, as a second finding:

Selecting the single test by node id hangs past 500s, while the whole file finishes in 23s. Something in that module is order- or fixture-dependent, which makes the failing case hard to bisect in isolation.

Both sentences are wrong. Withdrawn. Putting the retraction at the claim rather than only in a later summary, because that paragraph would have sent someone hunting a fixture-ordering bug that does not exist.

What actually happens

pytest completes, and fast. The run I called hung had already written its full summary:

1 failed, 2 warnings in 22.09s

I re-ran it with clean plumbing -- a plain > file 2>&1, no pipeline, no head -- to check whether my pipe was the culprit. It is not:

1 failed, 2 warnings in 20.75s

pytest finished in 20.75s and wrote everything. The invoking shell still never returned, and was open at a 400s harness timeout. So the lingering thing is a child process outliving the run and holding the shell's stdout handle, which means the parent never sees EOF. That is a teardown problem, not a pytest or ordering one.

Why the correction matters for the finding

It reverses the conclusion. The failure reproduces identically whether the test is selected alone or with the whole file, so it is not order- or fixture-dependent -- which makes it easier to bisect, not harder. I had it backwards.

invocation result
whole file 1 failed, 11 passed, ~23s
single node id 1 failed, ~21s

Unchanged

The paired-arm measurement in the comment above stands and is the load-bearing part: the same failure occurs with store.py at HEAD (0 hand-rolled BEGIN) and at 45ef0491e (17 hand-rolled BEGIN), so it is pre-existing on this branch's base, not introduced here.

How I got it wrong

I read a harness timeout on a shell command as a timeout of the thing the command ran. The tool reported the state truthfully -- the command had not returned -- and I substituted a cause I have really seen before (a slow or order-dependent test) for the one actually in front of me. The output file was there the whole time and said 22.09s; I did not open it until a second notification made me check.

The lingering-child observation is real and worth its own look -- possibly the same family as test_sandbox.py::test_the_relay_thread_ends_when_the_worker_tree_is_reaped, which failed in the same full-suite run. I am flagging that as a lead to check, not an established link.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

The three engine legs are green; one harness leg is red on a documented pwsh flake

5f8c3a701 registered test_writer_txn_is_the_only_begin.py in _STAYS_WITHOUT_IMPORTING. The reported failure is cleared:

check state
test (ubuntu-latest, py3.14) pass
test (windows-2022, py3.14) pass
test (windows-2025, py3.14) pass
web console tests (all three) pass
repo harness tests (ubuntu-latest) pass
repo harness tests (windows-2025) fail
CI gate pending on the above

The remaining red is not this PR's subject

repo harness tests (windows-2025) failed on two worktree-gate tests:

  • test_worktree_gate_control_plane.py::test_a_command_line_repository_token_OVERRIDES_the_carried_environment
  • test_worktree_gate_escaped_quote.py::test_a_backtick_straddle_AROUND_a_cmd_call_is_seen

Both with the same message, which the test author wrote to pre-empt exactly this misattribution:

AssertionError: PWSH LAUNCH TIMED OUT after 45s (BACKLOG #1304).
This is a PROCESS LAUNCH that never returned. It is NOT an assertion failure
and NOT evidence that the gate's behaviour changed: no gate logic ran.

Their own docstring adds: "The windows-2025 harness leg intermittently times out STARTING pwsh -- not on any assertion".

This PR touches messagefoundry/store/store.py and three test files. It does not touch harness/, the worktree gate, or anything either test exercises. Re-run the leg; there is nothing here to fix.

I am reporting this from the job log rather than inferring it from the job name -- the same discipline the retraction above was written to enforce.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

SUPERSESSION SETTLED BY CONTENT, not by ancestry. Posted on both PRs by the Manager, closing a question that has now been asked three times.

I got the ancestry question wrong once tonight by checking branch HEADS, so this check deliberately does NOT use ancestry at all. It parses messagefoundry/store/store.py from each branch and compares WHICH FUNCTIONS use _writer_txn:

1147   6 functions
1162  23 functions
in 1147 but NOT in 1162:  NONE

1147 set: _flush, _run_grouped, _unwind_writer_txn, _writer_txn, dead_letter_now, handoff
1162 adds: _apply_document_strips, delete_custom_role, delete_user, enqueue_message,
           ingress_handoff, purge_dead_letters, purge_message_bodies, record_ack_sent,
           record_received, reingress, release_message_attachments, resend_to,
           set_ad_group_role_map, set_ad_group_scope_map, set_user_roles,
           upsert_search_preset, write_reference_snapshot

Seventeen added, which matches 1162 reported count exactly, and the helper definitions themselves are in both.

So 1162 is a strict content superset of 1147. That holds whatever the commit graph says, which is the point of measuring it this way: three methods now agree, and only two of them share an instrument.

1. commit-level ancestry   7cd10fa1d and e025c0d8a are both in 1162
2. aggregate occurrences   32 in 1162 against 14 in 1147, 0 on main
3. function-set inclusion  6 is a subset of 23, difference empty   <- independent of 1 and 2

MERGE GUIDANCE, unchanged and now well supported: landing 1147 then 1162 is clean. Landing 1162 alone is also fine and makes 1147 redundant. There is no conflict, and my earlier claim that there was one is withdrawn above.

Nobody needs to re-verify this. If a fourth check is ever wanted, it should use a fourth method -- re-running any of these three would be one measurement repeated, which is the error that produced my false warning in the first place.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Sharpening the teardown mechanism in my retraction above

My retraction said the lingering thing was "a child process outliving the run and holding the shell's stdout handle, which means the parent never sees EOF." That specific mechanism is not what the evidence shows. The conclusion it supports is unchanged; the pointer for whoever investigates is not.

The command was time pytest ... > .single.out 2>&1; echo "pytest exit=$?"; tail -2 .single.out. Only pytest was redirected, so time and echo would land in the captured shell output.

  • .single.out holds pytest's complete summary: 1 failed, 2 warnings in 20.75s.
  • The captured shell output is 10 bytes: [killed]. No time output. No echo. The next command never ran, through a 400s window.

If pytest had exited, the shell's wait would have returned and echo would have run in milliseconds. It did not. So the pytest process had not terminated — it printed its summary and then hung at shutdown.

Why it hangs is unmeasured. A non-daemon thread and an un-reaped grandchild both fit; I am not picking between them without evidence, which is the mistake this thread already corrected once.

Unchanged, and still the load-bearing parts: the failure is pre-existing on this branch's base (paired arms, store.py at HEAD vs 45ef0491e), and it is not order-dependent (same failure alone and in-file).

PR 1147 squash-merged, so this branch carried 1147's original commits while
main carried the same content under a new SHA. Three conflicts, not the one
forecast: the ADR, plus store.py and the cancel-unwind test, both of which
main had moved since.

store.py: both conflicts were inside _writer_txn's docstring, no code. Took
this branch's text, which corrects main's "single writer-transaction shape"
to the narrower, true claim.

tests/test_backlog1548_writer_txn_cancel_unwind.py: add/add. Main has not
touched it since the 1147 squash, so ours is theirs plus the re-ingress
arms. All 19 removed lines are this branch's own refactor into
_assert_connection_clean.

ADR 0159: resolved as a union, with three figures re-measured rather than
carried. Population is 74, not 70 -- a direct-DML scan returns exactly 70
and misses four helper-mediated blocks. The severity split is 55 single-DML
against 19 multi-statement or loop-driven, which is blast radius rather than
handler presence. The early exits are not an exposure today; all 52 exit
sites fire before the first DML, after a commit, or already roll back. The
recommended remedy is a no-BEGIN/no-COMMIT guard checking in_transaction,
not giving _writer_txn the COMMIT.

Verified post-merge: 23 functions use _writer_txn, so nothing was dropped.
Relates to BACKLOG #1548.
@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Conflict with main resolved (merge commit 276cdd7)

PR 1147 squash-merged, so this branch carried 1147's original commits while main carried the
same content under a new SHA. mergeable is now MERGEABLE.

Three conflicts, not the one forecast. The brief predicted only the ADR would conflict and
that store.py and the test would auto-merge. That was true of an earlier main; by the time
this ran, PRs 1152, 1161 and 1167 had landed and moved store.py. Resolved:

File Conflict Resolution
docs/adr/0159-...md content union, see below
messagefoundry/store/store.py content, docstring only took this branch's text
tests/test_backlog1548_writer_txn_cancel_unwind.py add/add took this branch

store.py carried no code conflict. Both hunks sit in _writer_txn's docstring, where main
still says "the store's single writer-transaction shape" and this branch narrows it to the true
claim. On the test, main has not touched the file since the 1147 squash, so this branch is
main plus the re-ingress arms; all 19 removed lines are this branch's own refactor into
_assert_connection_clean.

Nothing was dropped

23 functions reference _writer_txn in the committed tree, measured by AST over
git show 276cdd707:messagefoundry/store/store.py: 2 definitions (_writer_txn,
_unwind_writer_txn) plus 21 users -- the seventeen conversions and _flush, _run_grouped,
dead_letter_now, handoff.

git merge-tree --name-only origin/main <head> exits 0, with both controls: a self-merge exits
0 (the instrument can report clean) and this PR's pre-fix head 5f8c3a701 exits 1 (so the 0 is
attributable to this merge, not to a broken instrument).

ADR 0159, resolved as a union

The false-premise correction sits outside the conflict and survives intact (lines 166-184): one
shared connection does not remove the next borrower, it makes every later writer one. The
partial-remedy caveat is re-aimed at the SHORT writers that auto-begin, since no writer matching
the original property is left.

Three figures were re-measured rather than carried, and two of them were wrong:

  • Population is 74, not 70. A scan for DML issued directly inside the self._lock block
    returns exactly 70, which is why the wrong number looked right. Four blocks reach DML through a
    helper that takes no lock: attachment_decref (via _decref_attachment), record_view and
    record_message_event (via _event), add_cipher_invocations (via
    _add_cipher_invocations_locked). Following one level of self.-helper returns 74 and the set
    difference is exactly those four.
  • Handler tier is 9, not 8. The ninth is attachment_decref -- one of the four the direct
    scan missed. The other eight match the ADR's existing list exactly, which is what validates the
    instrument.
  • Severity split by blast radius: 55 single-DML against 19 multi-statement or loop-driven. A
    cancellation in the 55 would risk one phantom write; in the 19 it would risk a torn multi-row
    write committed by a stranger, which is broken atomicity rather than broken isolation. The
    criterion is stated in the ADR because the count moves with it.
  • The early exits are not an exposure today. All 52 return/raise sites inside the 74
    blocks were classified: every one fires before the block's first DML, sits after a _commit(),
    or already rolls back (attachment_incref before its raise KeyError). They are a blocker
    created by _writer_txn's unconditional BEGIN, not a defect being carried.

The recommended remedy is recorded as a second helper that takes the lock, issues no BEGIN and
no COMMIT, unwinds on BaseException, and checks db.in_transaction on a clean exit -- not
giving _writer_txn the COMMIT. Named by subject; no number is allocated for it.

Measured 2026-09-15 on this box: sqlite3 default isolation_level is '', INSERT/UPDATE
leave in_transaction True, and bare SELECT, CREATE TABLE, CREATE INDEX, ALTER TABLE and
PRAGMA leave it False. That asymmetry is what makes the early exits safe and in_transaction a
sound completion check.

Three places this differs from the brief, flagged rather than silently applied

  1. The brief's split was 56/18; measured here it is 55/19, and 56+18 sums to 74 rather than the
    70 the brief attributed it to. One block classifies differently. The ADR states the criterion
    so the number is reproducible.
  2. The brief said grep -rn isolation_level messagefoundry/ returns zero. It returns one --
    the docstring in _writer_txn this merge restored. The substance holds: it is never set,
    and MessageStore.open calls aiosqlite.connect(str(path)) with no such argument. The ADR is
    worded as "never set" rather than "appears nowhere" so a reader cannot falsify it with one grep.
  3. The ADR's earlier "fifteen" early-exit blocks is not reproducible without its criterion. By the
    criterion "a return or raise before the block's last _commit()" the answer is 13. Both the
    number and the criterion are recorded.

Checks

ruff check and ruff format --check pass. mypy messagefoundry strict: no issues in 274 source
files. Green after the merge: tests/test_writer_txn_is_the_only_begin.py,
tests/test_backlog1548_writer_txn_cancel_unwind.py, tests/test_tooling_partition.py (42
passed) and tests/test_store.py (58 passed). The whole-tree BEGIN scanner was re-run after
the merge, not before. The full suite was still running when this was written; hosted-only legs
such as windows-service-smoke are unread here and need reading on the PR.

mergeStateStatus reads BEHIND because main moved again after this push. That is the queue's
to resolve, not a conflict -- mergeable is MERGEABLE.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

CORRECTION TO MY REVIEW-FINDINGS COMMENT ABOVE. Three of the numbers I published there are wrong. Corrected by this PR author, who measured rather than transcribed, and I am recording it where I published the error.

I relayed an adversarial review's census figures into this thread. The review re-derived them and was right about the direction of every correction, but three of its numbers do not survive measurement, and one of them I should have caught before passing on.

I published Measured Note
population 70 74 Confirmed. Direct-DML scan returns exactly 70; following one level of self.-helper returns 74; the difference is exactly the four named blocks.
handler tier 8 9 The ninth is attachment_decref, one of the four the direct scan missed. The other eight match the ADR list exactly, which is what validates the instrument.
severity split 56 / 18 55 / 19 And my version was internally inconsistent: 56 + 18 sums to 74, while I attributed the split to the 70. I passed that on without checking the arithmetic.
early exits 15 13 By the stated criterion, a return or raise before the block last _commit(). The ADR now carries the number AND the criterion, because an unreproducible figure is worse than none.

One further claim of mine is now FALSE and its correction is instructive. I wrote that grep -rn isolation_level messagefoundry/ returns zero. It returns ONE, because this merge restored the _writer_txn docstring that mentions it. The substance holds -- MessageStore.open calls aiosqlite.connect(str(path)) with no such argument, and auto-begin was confirmed empirically -- but the ADR is now worded as "never SET" rather than "appears nowhere", so a reader cannot falsify a true claim with one grep. A claim that was true when measured became false because the tree moved underneath it.

The early-exit finding is also now stronger than when I relayed it: verified EXHAUSTIVELY across all 52 return and raise sites in the 74 blocks, not on a sample of six. Every one fires before the first DML, sits after a _commit(), or already rolls back. So they remain a cost of the unconditional BEGIN rather than an existing exposure.

WHAT STANDS UNCHANGED: the ruling against giving _writer_txn the COMMIT, and the recommended remedy -- a second helper taking the lock with no BEGIN and no COMMIT, unwinding on BaseException, checking db.in_transaction on a clean exit. in_transaction already reports what an abort sentinel would encode. No number is allocated for that work and none should be cited.

Also worth recording: my brief for this conflict resolution forecast ONE conflict. There were three, because PRs 1152, 1161 and 1167 landed while it ran. The tree won over the brief, which is the instruction that made the difference.

@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Full local suite: 6 failed, 17129 passed, 875 skipped (0:20:19). None of the six is this PR's.

Completing the check the previous comment left open. Head 57fb0d008.

The runner reported exited with code 0 while pytest reported 6 failures, so the exit code was
not usable as the verdict here. The summary line and the junit XML both landed, so this was a real
completed run rather than the killed-run-exits-zero case -- but the wrapper's exit code should not
be read as the result on this box.

Attribution, by control run rather than by inspection

Four reproduce on origin/main (0f9206ad2) in this same worktree and venv, run serially:

Test On main Cause
test_gate_installed_parity.py::test_the_installed_gate_matches_the_committed_source FAILS machine state
test_selfheal_installed_parity.py::test_the_installed_selfheal_payload_matches_the_committed_source FAILS machine state
test_installed_coord_hooks.py::...[claim_check.py] FAILS machine state
test_installed_coord_hooks.py::...[push_guard.py] FAILS machine state

All four compare a hook installed on this machine against the repository's committed source. The
push_guard.py diagnostic names the pair directly: installed c22ac41dd718 against source
f28b506be4dc, with line-endings-only difference=False. That is a stale local install, and it is
pre-existing on main.

The other two did not reproduce. Both pass serially on this PR's merged tree:

  • tests/test_sandbox.py::test_worker_kill_reaps_the_whole_process_tree
  • tests/test_workflow_shell_syntax.py::test_every_shell_run_block_parses

They failed only under -n auto, which is consistent with load rather than content -- the first
reaps a process tree, which is exactly the shape that flakes under a saturated runner.

The structural argument, which does not depend on the re-runs

This PR changes five files against main, and none sits under .github/ or scripts/:

docs/adr/0159-cancellation-safe-pooled-connection-release-mid-txn-discard-at-the-acquire-chokepoint.md
messagefoundry/store/store.py
tests/test_backlog1548_writer_txn_cancel_unwind.py
tests/test_tooling_partition.py
tests/test_writer_txn_is_the_only_begin.py

git diff --name-only origin/main...57fb0d008 -- .github/ scripts/ returns zero files. So the
four installed-parity failures cannot be this PR's (it changes no scripts/hooks/ source) and
test_every_shell_run_block_parses cannot be either (it changes no workflow). That holds
independently of whether the re-runs had come out the other way.

Unresolved, for whoever reads CI

The four installed-parity failures are a real signal about this box, not about either branch: the
hooks installed under .git/hooks/ and %USERPROFILE%\.claude\hooks\ have drifted from committed
source. Re-running the installers would clear them. Left alone here because it is machine state
outside this PR's subject, and fixing it would change nothing this PR is being judged on.

Hosted-only legs such as windows-service-smoke still need reading on the PR; a Builder never sees
them.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

ci-red A required check went red. Attribute it before retrying.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant