From 770b29c8511cf406b85544684e26487273fbc23a Mon Sep 17 00:00:00 2001 From: lane c0e Date: Sat, 5 Sep 2026 19:03:07 -0700 Subject: [PATCH 1/2] ledger(CCV1-023/-009): attribute the post-reap refusal to the ADAPTER fence, and pin it CCV1-023's seeded note said the fixture that model_performance-c0e was filed for 'asserts the TOOL-layer refusal (which passes via the session latch)'. That sentence was removed wholesale by PR #71 when the row flipped CONFORMS, but was never replaced by the right answer -- so the ledger has been silent on WHY its own flagship custody fixture passes. Measured, one mechanism at a time, against real bd + an isolated dolt server: * delete the adapter's custody-identity fence (PR #68, b3fac1e) and test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim fails at 'assert resolved.success is False' -- the close LANDS. The session latch is what lets it through. * delete the tool layer's 'except A.FencedError' latch-clearing (PR #3, 69b717e) and the refusal still happens, but the fixture fails at 'assert session._held is None'. So two mechanisms at two layers, and the session latch is neither. Pinned executably rather than left as prose: test_post_reap_refusal_originates_below_the_session_latch asserts the latch still names the item at the moment of the refused call, that the ADAPTER refuses with no session in the picture, that the surfaced wording is the fence's and not the latch's, and that an integrator's close of the same unheld item still succeeds. Its own discrimination measured three ways (fence removed -> DID NOT RAISE; refusal re-sourced to the latch -> wording red; fence re-keyed on 'unheld' instead of identity -> integrator half red). test_row_ccv1_009 gained a part 4 so the ledger notices if that pin is deleted. CCV1-009 re-assessed: stays CONFORMS, both halves RUN this time rather than probed for existence. assertion.kind deliberately unchanged. STALE-NOTE AUDIT of every CCV1 row (the item asked for it explicitly) found four more, all corrected here, none a disposition change: * CCV1-002 said reclaim_eligible has 'exactly two routes'; PR #76 added a third, and the source docstring has said 'three, and only three' since. Two path-2 cites added so the row covers the mechanism it describes. * CCV1-003, CCV1-004, CCV1-010 each defer their indexed upgrade on 'that suite runs in nothing (CCV1-022)'. CCV1-022 went green in PR #68. * CCV1-017 said Fixture 4 'does not exist in ANY suite'; CCV1-023 flipped CONFORMS on the file that contains it. ledger/reconcile-report.md carries the same claims and is deliberately NOT touched: it is a dated, self-declared superseded snapshot. --- .../STALE-NOTE-AUDIT.md | 116 ++ .../evidence/discrim-A-fence-reverted.log | 250 +++++ .../discrim-B-latch-clearing-reverted.log | 237 +++++ .../evidence/pin-mutA-fence-removed.log | 285 +++++ .../pin-mutB-refusal-moved-to-latch.log | 298 ++++++ .../pin-mutC-fence-rekeyed-on-unheld.log | 472 +++++++++ .../evidence/tier-ledger-mutate.log | 161 +++ .../evidence/tier1-unit.log | 992 ++++++++++++++++++ .../evidence/tier2-integration.log | 51 + .../evidence/tiers-summary.txt | 1 + ledger/checks/test_custody_rows.py | 21 + ledger/rows.yaml | 163 ++- .../tests/test_reap_recovery.py | 77 ++ 13 files changed, 3106 insertions(+), 18 deletions(-) create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/STALE-NOTE-AUDIT.md create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-A-fence-reverted.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-B-latch-clearing-reverted.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutA-fence-removed.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutB-refusal-moved-to-latch.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutC-fence-rekeyed-on-unheld.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/tier-ledger-mutate.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/tier1-unit.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/tier2-integration.log create mode 100644 docs/lanes/c0e-ccv1-023-ledger-note/evidence/tiers-summary.txt diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/STALE-NOTE-AUDIT.md b/docs/lanes/c0e-ccv1-023-ledger-note/STALE-NOTE-AUDIT.md new file mode 100644 index 0000000..b9b8a51 --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/STALE-NOTE-AUDIT.md @@ -0,0 +1,116 @@ +# Stale mechanism-claim audit — every CCV1 row, 2026-09-05 + +Lane `c0e-ccv1-023-ledger-note`, work item `model_performance-c0e`. + +`model_performance-c0e` asked for one deliverable to be answered explicitly: + +> **Say explicitly whether any OTHER ledger row makes a mechanism claim that is now +> stale.** #68, #76 and #77 all landed since these notes were written; a second wrong +> note is likelier than not, and finding it now is cheap. + +**Answer: yes — five, not one.** All five are CONFORMS rows whose *disposition* is +correct and whose *notes* describe a world that no longer exists. Four of the five are +the same claim repeated. All five are corrected in `ledger/rows.yaml` in this change; +no disposition and no `assertion.kind` was changed by this lane. + +## Method + +Not a skim. Three passes over all 24 CCV1 rows: + +1. Grep every row's notes for the mechanism vocabulary the three merges touch — + `reap`, `reclaim`, `TTL`, `liveness`, `sweep`, `heartbeat`, `sweeps.`, `xfail`, + `runs in no`, `unrun`, `does not exist`, `doctor`. +2. For every hit, read the CURRENT source or CI config that the claim is about, and + compare. A claim is only stale if the artefact it describes disagrees with it *now*. +3. Where the source itself states the fact in prose (a docstring), quote both sides so + the disagreement is checkable rather than asserted. + +## The five + +### 1. CCV1-002 — "exactly two routes" to reclaim-eligible. **STALE. Corrected.** + +The note said: + +> `custody.reclaim_eligible` reaches "eligible" by exactly two routes -- a stale/absent +> last_seen, or the one-way escalation ceiling. + +`src/amplifier_work_tracker/custody.py::reclaim_eligible`'s own docstring says: + +> Three paths to eligible, and only three: 1. STALE ... 2. DEAD HOLDER ... 3. +> ESCALATION CEILING + +The dead-holder path landed in **PR #76 (`46d7da4`, `model_performance-oy4`)**, after +this note was written. The ledger and the source disagreed on the *count of the very +mechanism the row is about* — the highest-value catch in this audit, and one this lane +would not have looked for without the deliverable that told it to. + +**The clause is not weakened.** Core 2 says total hold duration never disqualifies a +claim; path 2 keys on the HOLDER's liveness, never the hold's age, is fenced to only +ACCELERATE path 1 inside a window path 1 would have covered anyway, and every +unknowable case resolves to NOT eligible. Disposition stays CONFORMS. + +**Also fixed:** the row's `indexed` refs covered only paths 1 and 3, so it did not +actually cover the mechanism it now describes. Two path-2 cites added from +`tests/unit/test_custody_dead_holder.py` +(`test_a_live_holder_deep_inside_the_ttl_is_left_alone`, +`test_ttl_staleness_still_wins_and_costs_no_pid_probe`), and `last_measured` moved +2026-09-01 → 2026-09-05 because they were run, not assumed. + +### 2–4. CCV1-003, CCV1-004, CCV1-010 — "that suite runs in nothing (CCV1-022)". **STALE. Corrected.** + +Three rows defer their own indexed upgrade on a blocker that is gone: + +| Row | The stale sentence | +|---|---| +| CCV1-003 | "...which still runs in no CI (CCV1-022) ... Upgrade this row to an `indexed` cite when CCV1-022 goes green." | +| CCV1-004 | "...but that suite runs in nothing (CCV1-022), so it cannot be cited as measured." | +| CCV1-010 | "...in the modules suite) runs in nothing -- CCV1-022." | + +**CCV1-022 is green**, closed by **PR #68 (`b3fac1e`)**, and its own note says so. The +suite is wired three ways: the venv install (`Makefile:24`), the `test-module` target +inside `make test` (`Makefile:99,108`), and `.github/workflows/ci.yml:125-126` +("Tier 5 -- tool module tests"). Every fixture the three rows cite was measured passing +on this branch 2026-09-05. + +This is the *worse* failure mode of the two in this audit, because it is self-sealing: a +row that says "cannot be cited as measured" tells the next reader not to bother +measuring. Corrected to say what is actually true — the fixtures run, and the only thing +left is the citation itself, which stays a named, now-unblocked follow-up. + +### 5. CCV1-017 — "Fixture 4 does not exist in ANY suite ... asserted by nothing". **STALE. Corrected.** + +The note said the behavioural single-hold fixture "does not exist in ANY suite -- see +CCV1-023 -- so the refusal is enforced and asserted by nothing." + +Both halves are false. **CCV1-023 itself flipped CONFORMS on the file that contains it.** +`modules/tool-work-tracker/tests/test_conformance_fixtures.py` carries four Fixture-4 +tests (`test_fixture4_a_directed_second_claim_is_refused_while_holding`, +`..._a_queue_second_claim_is_refused_while_holding`, +`..._the_second_claim_succeeds_once_the_first_is_resolved`, +`..._the_second_claim_succeeds_once_the_first_is_released`), measured passing +2026-09-05. Two rows of one ledger disagreed with each other about whether a fixture +exists. + +## Checked and NOT stale + +* **CCV1-006 / CCV1-007** (`sweeps.alive`, the TTL-enforced-by-sweep prose) — read + against **PR #77 (`0055cd2`)**, which made `sweeps.alive` report `unknown` rather than + FAIL for a root the service does not serve. Neither note asserts the failing-vs-unknown + behaviour; both describe the heartbeat's existence and the "TTL does not enforce + itself" prose, and both remain true. No change. +* **CCV1-009 / CCV1-022 / CCV1-023's xfail sentences** — already corrected by the + 2026-09-03 re-review; verified, not re-corrected. +* **`ledger/reconcile-report.md`** — carries the same "runs in nothing" claims in four + places (`:253`, `:271`, `:313`, `:356`). **Deliberately NOT touched.** It is an + explicitly dated, explicitly superseded snapshot ("### 1a. SEED snapshot (2026-09-01) + -- history, superseded by the table above"), and it already says of itself that + rewriting it is the wrong move. A historical report that is edited to agree with the + present is no longer evidence of anything. Recorded here instead. +* The remaining CCV1 rows carry no mechanism claim touched by #68, #76 or #77. + +## OSV1 rows + +Out of scope and stated as such: the OSV1 family was seeded 2026-09-04 — *after* all +three merges — by the operator-surface highway that is still actively pushing to this +repo. Its rows cannot be stale with respect to merges that predate them, and auditing a +family another lane is concurrently rewriting would produce conflicts, not truth. diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-A-fence-reverted.log b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-A-fence-reverted.log new file mode 100644 index 0000000..21ace87 --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-A-fence-reverted.log @@ -0,0 +1,250 @@ +F [100%] +=================================== FAILURES =================================== +__ test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim ___ + +project = 'reapproj17cccf4977' + + @pytest.mark.asyncio + async def test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim(project): + """Trigger path 1: the explicit `work_resolve` refusal. Claim -> force + reap -> resolve refuses (fenced) -> but the SAME session's next + `work_claim` must still succeed, in the same process. + + Was `xfail(strict=True)` for ledger row CCV1-009 (`work_item_pipeline-dn4`) + while `Beads.resolve`'s fence ran only under `if current.status == "held"` + and a reaped item is `open`, so the stale holder's close landed. That + PRODUCT defect is fixed -- the fence is now keyed on custody IDENTITY, + not item status, and CCV1-009 reads CONFORMS -- so the marker was + XPASSing (strict) and failing this suite. Removed rather than re-aimed: + the behaviour it described no longer exists. The same refusal is pinned + as a discriminating good/bad pair in `test_conformance_fixtures.py` + (contract Fixture 2) and at the adapter layer in + `tests/integration/test_post_reclaim_fence.py`.""" + add_session = WorkTrackerSession({"actor": _unique("adder")}) + first = await add_session.add(project, "first reap-recovery item", acceptance="n/a") + assert first.success is True + + session = WorkTrackerSession({"actor": _unique("resolver")}) + claimed = await session.claim(project) + assert claimed.success is True + item_id = claimed.output["claimed"] # type: ignore[index] + + reaped = _force_reap(session, project) + assert reaped["reclaimed_count"] == 1 + + resolved = await session.resolve(item_id, "trying to close after being reclaimed") +> assert resolved.success is False +E AssertionError: assert True is False +E + where True = ToolResult(success=True, output={'resolved': 'reapproj17cccf4977-9gx', 'resolution': 'trying to close after being reclaimed'}, error=None).success + +modules/tool-work-tracker/tests/test_reap_recovery.py:82: AssertionError +---------------------------- Captured stdout setup ----------------------------- +Starting server with Config HP="127.0.0.1:56989"|T="28800000"|R="false"|L="info" +---------------------------- Captured stderr setup ----------------------------- +time="2026-09-05T18:50:31-07:00" level=info msg="Creating root@localhost superuser" +time="2026-09-05T18:50:31-07:00" level=info msg="Server ready. Accepting connections." +time="2026-09-05T18:50:31-07:00" level=warning msg="secure_file_priv is set to \"\", which is insecure." +time="2026-09-05T18:50:31-07:00" level=warning msg="Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read." +time="2026-09-05T18:50:31-07:00" level=warning msg="Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory." +time="2026-09-05T18:50:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=1 +time="2026-09-05T18:50:31-07:00" level=info msg=ConnectionClosed connectionID=1 +time="2026-09-05T18:50:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2 +time="2026-09-05T18:50:31-07:00" level=info msg=ConnectionClosed connectionID=2 +time="2026-09-05T18:50:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=3 +time="2026-09-05T18:50:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=4 +time="2026-09-05T18:50:31-07:00" level=info msg=ConnectionClosed connectionID=3 +time="2026-09-05T18:50:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=5 +time="2026-09-05T18:50:31-07:00" level=info msg=ConnectionClosed connectionID=4 +time="2026-09-05T18:50:31-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:50:31.578067122 -0700 PDT m=+0.535342178" connectionDb=reapproj17cccf4977 connectionID=5 error="table not found: schema_migrations" queryTime="2026-09-05 18:50:31.579400415 -0700 PDT m=+0.536675439" +time="2026-09-05T18:50:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=6 +time="2026-09-05T18:50:31-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:50:31.579874525 -0700 PDT m=+0.537149581" connectionDb=reapproj17cccf4977 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:50:31.580746171 -0700 PDT m=+0.538021195" +time="2026-09-05T18:50:31-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:50:31.579874525 -0700 PDT m=+0.537149581" connectionDb=reapproj17cccf4977 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:50:31.582321559 -0700 PDT m=+0.539596599" +time="2026-09-05T18:50:31-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:50:31.579874525 -0700 PDT m=+0.537149581" connectionDb=reapproj17cccf4977 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:50:31.584904048 -0700 PDT m=+0.542179088" +time="2026-09-05T18:50:33-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:50:31.579874525 -0700 PDT m=+0.537149581" connectionDb=reapproj17cccf4977 connectionID=6 error="table not found: ignored_schema_migrations" queryTime="2026-09-05 18:50:33.109540048 -0700 PDT m=+2.066815072" +time="2026-09-05T18:50:33-07:00" level=info msg=ConnectionClosed connectionID=6 +time="2026-09-05T18:50:33-07:00" level=info msg=ConnectionClosed connectionID=5 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=7 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=7 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=8 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=9 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=8 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=9 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=10 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=10 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=11 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=12 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=11 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=12 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=14 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=13 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=13 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=15 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=14 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=15 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=16 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=16 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=17 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=17 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=18 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=18 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=19 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=19 +----------------------------- Captured stdout call ----------------------------- + +----------------------------- Captured stderr call ----------------------------- +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=20 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=20 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=21 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=21 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=22 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=23 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=22 +time="2026-09-05T18:50:34-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=24 +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=24 +time="2026-09-05T18:50:34-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:50:34.831400042 -0700 PDT m=+3.788675082" connectionDb=reapproj17cccf4977 connectionID=23 error="backup 'backup_export' not found" queryTime="2026-09-05 18:50:34.924145902 -0700 PDT m=+3.881420942" +time="2026-09-05T18:50:34-07:00" level=info msg=ConnectionClosed connectionID=23 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=25 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=25 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=26 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=26 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=27 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=27 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=28 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=28 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=29 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=29 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=30 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=31 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=30 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=32 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=31 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=32 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=33 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=33 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=34 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=34 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=35 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=35 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=36 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=36 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=37 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=37 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=38 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=38 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=39 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=39 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=40 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=40 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=41 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=41 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=42 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=42 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=43 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=43 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=44 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=44 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=45 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=45 +time="2026-09-05T18:50:35-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=46 +time="2026-09-05T18:50:35-07:00" level=info msg=ConnectionClosed connectionID=46 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=47 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=47 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=48 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=49 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=48 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=50 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=50 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=49 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=51 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=51 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=52 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=52 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=53 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=53 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=54 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=54 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=55 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=55 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=56 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=56 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=57 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=57 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=58 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=58 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=59 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=59 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=60 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=60 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=61 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=61 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=62 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=62 +time="2026-09-05T18:50:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=63 +time="2026-09-05T18:50:36-07:00" level=info msg=ConnectionClosed connectionID=63 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=64 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=64 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=65 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=66 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=65 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=67 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=67 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=66 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=68 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=68 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=69 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=69 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=70 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=70 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=71 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=71 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=72 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=72 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=73 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=73 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=74 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=74 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=75 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=75 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=76 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=76 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=77 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=77 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=78 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=78 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=79 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=80 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=79 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=81 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=81 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=80 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=82 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=82 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=83 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=83 +time="2026-09-05T18:50:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=84 +time="2026-09-05T18:50:37-07:00" level=info msg=ConnectionClosed connectionID=84 +time="2026-09-05T18:50:38-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=85 +time="2026-09-05T18:50:38-07:00" level=info msg=ConnectionClosed connectionID=85 +time="2026-09-05T18:50:38-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=86 +time="2026-09-05T18:50:38-07:00" level=info msg=ConnectionClosed connectionID=86 +------------------------------ Captured log call ------------------------------- +ERROR amplifier_work_tracker.webpush:webpush.py:435 ntfy alarm unexpected failure for reclaimed reapproj17cccf4977-9gx: asyncio.run() cannot be called from a running event loop +--------------------------- Captured stderr teardown --------------------------- +time="2026-09-05T18:50:38-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=87 +time="2026-09-05T18:50:38-07:00" level=info msg="stats stopped: context canceled" +time="2026-09-05T18:50:38-07:00" level=info msg=ConnectionClosed connectionID=87 +time="2026-09-05T18:50:38-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=88 +time="2026-09-05T18:50:38-07:00" level=info msg=ConnectionClosed connectionID=88 +time="2026-09-05T18:50:38-07:00" level=info msg="Server closing listener. No longer accepting connections." +time="2026-09-05T18:50:38-07:00" level=info msg="stats stopped: context canceled" +=============================== warnings summary =============================== +modules/tool-work-tracker/tests/test_reap_recovery.py::test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim + /home/bkrabach/dev/hw-model-performance/lanes/c0e-ccv1-023-ledger-note/amplifier-work-tracker/.venv/lib/python3.12/site-packages/_pytest/stash.py:108: RuntimeWarning: coroutine 'alarm_for_reclaimed_item' was never awaited + del self._storage[key] + Enable tracemalloc to get traceback where the object was allocated. + See https://docs.pytest.org/en/stable/how-to/capture-warnings.html#resource-warnings for more info. + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +=========================== short test summary info ============================ +FAILED modules/tool-work-tracker/tests/test_reap_recovery.py::test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim +1 failed, 1 warning in 8.42s diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-B-latch-clearing-reverted.log b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-B-latch-clearing-reverted.log new file mode 100644 index 0000000..ea98484 --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/discrim-B-latch-clearing-reverted.log @@ -0,0 +1,237 @@ +F [100%] +=================================== FAILURES =================================== +__ test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim ___ + +project = 'reapproj1af25cf318' + + @pytest.mark.asyncio + async def test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim(project): + """Trigger path 1: the explicit `work_resolve` refusal. Claim -> force + reap -> resolve refuses (fenced) -> but the SAME session's next + `work_claim` must still succeed, in the same process. + + Was `xfail(strict=True)` for ledger row CCV1-009 (`work_item_pipeline-dn4`) + while `Beads.resolve`'s fence ran only under `if current.status == "held"` + and a reaped item is `open`, so the stale holder's close landed. That + PRODUCT defect is fixed -- the fence is now keyed on custody IDENTITY, + not item status, and CCV1-009 reads CONFORMS -- so the marker was + XPASSing (strict) and failing this suite. Removed rather than re-aimed: + the behaviour it described no longer exists. The same refusal is pinned + as a discriminating good/bad pair in `test_conformance_fixtures.py` + (contract Fixture 2) and at the adapter layer in + `tests/integration/test_post_reclaim_fence.py`.""" + add_session = WorkTrackerSession({"actor": _unique("adder")}) + first = await add_session.add(project, "first reap-recovery item", acceptance="n/a") + assert first.success is True + + session = WorkTrackerSession({"actor": _unique("resolver")}) + claimed = await session.claim(project) + assert claimed.success is True + item_id = claimed.output["claimed"] # type: ignore[index] + + reaped = _force_reap(session, project) + assert reaped["reclaimed_count"] == 1 + + resolved = await session.resolve(item_id, "trying to close after being reclaimed") + assert resolved.success is False + assert "reclaimed" in str(resolved.output).lower() + + # The fix: session state must not stay poisoned. +> assert session._held is None # noqa: SLF001 + ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ +E AssertionError: assert _Held(project='reapproj1af25cf318', item_id='reapproj1af25cf318-1vo', actor='resolverf741fff641', generation=1, stop=<...44440428ef0: unset>, thread=, lost_reason=None) is None +E + where _Held(project='reapproj1af25cf318', item_id='reapproj1af25cf318-1vo', actor='resolverf741fff641', generation=1, stop=<...44440428ef0: unset>, thread=, lost_reason=None) = ._held + +modules/tool-work-tracker/tests/test_reap_recovery.py:86: AssertionError +---------------------------- Captured stdout setup ----------------------------- +Starting server with Config HP="127.0.0.1:60719"|T="28800000"|R="false"|L="info" +---------------------------- Captured stderr setup ----------------------------- +time="2026-09-05T18:51:06-07:00" level=info msg="Creating root@localhost superuser" +time="2026-09-05T18:51:06-07:00" level=info msg="Server ready. Accepting connections." +time="2026-09-05T18:51:06-07:00" level=warning msg="secure_file_priv is set to \"\", which is insecure." +time="2026-09-05T18:51:06-07:00" level=warning msg="Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read." +time="2026-09-05T18:51:06-07:00" level=warning msg="Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory." +time="2026-09-05T18:51:06-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=1 +time="2026-09-05T18:51:06-07:00" level=info msg=ConnectionClosed connectionID=1 +time="2026-09-05T18:51:07-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2 +time="2026-09-05T18:51:07-07:00" level=info msg=ConnectionClosed connectionID=2 +time="2026-09-05T18:51:07-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=3 +time="2026-09-05T18:51:07-07:00" level=info msg=ConnectionClosed connectionID=3 +time="2026-09-05T18:51:07-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=4 +time="2026-09-05T18:51:07-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=5 +time="2026-09-05T18:51:07-07:00" level=info msg=ConnectionClosed connectionID=4 +time="2026-09-05T18:51:07-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:51:07.375636526 -0700 PDT m=+0.479000671" connectionDb=reapproj1af25cf318 connectionID=5 error="table not found: schema_migrations" queryTime="2026-09-05 18:51:07.376714219 -0700 PDT m=+0.480078380" +time="2026-09-05T18:51:07-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=6 +time="2026-09-05T18:51:07-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:51:07.377103514 -0700 PDT m=+0.480467675" connectionDb=reapproj1af25cf318 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:51:07.377882904 -0700 PDT m=+0.481247065" +time="2026-09-05T18:51:07-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:51:07.377103514 -0700 PDT m=+0.480467675" connectionDb=reapproj1af25cf318 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:51:07.379525588 -0700 PDT m=+0.482889765" +time="2026-09-05T18:51:07-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:51:07.377103514 -0700 PDT m=+0.480467675" connectionDb=reapproj1af25cf318 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:51:07.381857997 -0700 PDT m=+0.485222158" +time="2026-09-05T18:51:08-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:51:07.377103514 -0700 PDT m=+0.480467675" connectionDb=reapproj1af25cf318 connectionID=6 error="table not found: ignored_schema_migrations" queryTime="2026-09-05 18:51:08.837469207 -0700 PDT m=+1.940833352" +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=6 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=5 +time="2026-09-05T18:51:09-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=7 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=7 +time="2026-09-05T18:51:09-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=8 +time="2026-09-05T18:51:09-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=9 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=8 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=9 +time="2026-09-05T18:51:09-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=10 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=10 +time="2026-09-05T18:51:09-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=11 +time="2026-09-05T18:51:09-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=12 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=11 +time="2026-09-05T18:51:09-07:00" level=info msg=ConnectionClosed connectionID=12 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=13 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=13 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=14 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=15 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=14 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=15 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=16 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=16 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=17 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=17 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=18 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=18 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=19 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=19 +----------------------------- Captured stdout call ----------------------------- + +----------------------------- Captured stderr call ----------------------------- +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=20 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=20 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=21 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=21 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=22 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=23 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=22 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=24 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=24 +time="2026-09-05T18:51:10-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:51:10.372746793 -0700 PDT m=+3.476110938" connectionDb=reapproj1af25cf318 connectionID=23 error="backup 'backup_export' not found" queryTime="2026-09-05 18:51:10.480071511 -0700 PDT m=+3.583435640" +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=23 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=25 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=25 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=26 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=26 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=27 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=27 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=28 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=28 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=29 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=29 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=30 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=30 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=31 +time="2026-09-05T18:51:10-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=32 +time="2026-09-05T18:51:10-07:00" level=info msg=ConnectionClosed connectionID=31 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=32 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=33 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=33 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=34 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=34 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=35 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=35 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=36 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=36 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=37 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=37 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=38 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=38 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=39 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=39 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=40 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=40 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=41 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=41 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=42 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=42 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=43 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=43 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=44 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=44 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=45 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=45 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=46 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=46 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=47 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=47 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=48 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=49 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=48 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=50 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=50 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=49 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=51 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=51 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=52 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=52 +time="2026-09-05T18:51:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=53 +time="2026-09-05T18:51:11-07:00" level=info msg=ConnectionClosed connectionID=53 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=54 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=54 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=55 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=55 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=56 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=56 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=57 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=57 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=58 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=58 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=59 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=59 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=60 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=60 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=61 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=61 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=62 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=62 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=63 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=63 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=64 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=64 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=65 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=66 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=65 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=67 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=67 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=66 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=68 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=68 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=69 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=69 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=70 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=70 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=71 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=71 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=72 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=72 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=73 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=73 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=74 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=74 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=75 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=75 +time="2026-09-05T18:51:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=76 +time="2026-09-05T18:51:12-07:00" level=info msg=ConnectionClosed connectionID=76 +time="2026-09-05T18:51:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=77 +time="2026-09-05T18:51:13-07:00" level=info msg=ConnectionClosed connectionID=77 +------------------------------ Captured log call ------------------------------- +ERROR amplifier_work_tracker.webpush:webpush.py:435 ntfy alarm unexpected failure for reclaimed reapproj1af25cf318-1vo: asyncio.run() cannot be called from a running event loop +--------------------------- Captured stderr teardown --------------------------- +time="2026-09-05T18:51:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=78 +time="2026-09-05T18:51:13-07:00" level=info msg="stats stopped: context canceled" +time="2026-09-05T18:51:13-07:00" level=info msg=ConnectionClosed connectionID=78 +time="2026-09-05T18:51:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=79 +time="2026-09-05T18:51:13-07:00" level=info msg=ConnectionClosed connectionID=79 +time="2026-09-05T18:51:13-07:00" level=info msg="Server closing listener. No longer accepting connections." +time="2026-09-05T18:51:13-07:00" level=info msg="stats stopped: context canceled" +=============================== warnings summary =============================== +modules/tool-work-tracker/tests/test_reap_recovery.py::test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim + /home/bkrabach/dev/hw-model-performance/lanes/c0e-ccv1-023-ledger-note/amplifier-work-tracker/.venv/lib/python3.12/site-packages/_pytest/stash.py:108: RuntimeWarning: coroutine 'alarm_for_reclaimed_item' was never awaited + del self._storage[key] + Enable tracemalloc to get traceback where the object was allocated. + See https://docs.pytest.org/en/stable/how-to/capture-warnings.html#resource-warnings for more info. + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +=========================== short test summary info ============================ +FAILED modules/tool-work-tracker/tests/test_reap_recovery.py::test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim +1 failed, 1 warning in 6.30s diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutA-fence-removed.log b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutA-fence-removed.log new file mode 100644 index 0000000..18a00b0 --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutA-fence-removed.log @@ -0,0 +1,285 @@ +F [100%] +=================================== FAILURES =================================== +__________ test_post_reap_refusal_originates_below_the_session_latch ___________ + +project = 'reapproj13707b757f' + + @pytest.mark.asyncio + async def test_post_reap_refusal_originates_below_the_session_latch(project): + """MECHANISM PIN for the test directly above -- ledger rows CCV1-009 + (Core 7) and CCV1-023 (Freeze 3), work item `model_performance-c0e`. + + The test above asserts THAT the post-reap resolve is refused. It does + not assert WHERE the refusal comes from, and the ledger once recorded + the wrong answer: CCV1-023's seeded note said this fixture "asserts the + TOOL-layer refusal (which passes via the session latch)". The session + latch is not a fence -- after a reap it still names the item, so it + passes the call straight THROUGH. The refusal is the ADAPTER's + custody-identity fence (`resolve_outcome`'s `elif cust_holder == who + and current.holder != who`, PR #68 / b3fac1e). + + Prose cannot hold that distinction still, so this pins it executably. + Each assertion below fails under a different regression: + + 1. the latch still names the item at the moment of the refused call + -- if the refusal ever moves UP into the latch, this is the first + thing that has to change, and it changes here first; + 2. the ADAPTER refuses on its own, with no `WorkTrackerSession` in + the picture at all -- delete the fence branch and this raises + nothing (measured: the close then LANDS, `success=True`); + 3. the refusal the tool surfaces is the fence's wording, not the + latch's -- a latch-sourced refusal would say "did not claim"; + 4. the other half of Core 7, at the same site: an integrator's plain + close of that same unheld item still succeeds in one call. A fence + keyed on "the item is unheld" rather than on custody IDENTITY + would pass 1-3 and fail here. + """ + add_session = WorkTrackerSession({"actor": _unique("adder")}) + added = await add_session.add(project, "mechanism-pin item", acceptance="n/a") + assert added.success is True + + session = WorkTrackerSession({"actor": _unique("stale")}) + claimed = await session.claim(project) + assert claimed.success is True + item_id = claimed.output["claimed"] # type: ignore[index] + + assert _force_reap(session, project)["reclaimed_count"] == 1 + + # 1. The latch is NOT the fence: it still names this very item, so + # `resolve`'s own `held.item_id != item_id` gate cannot refuse. + held = session._held # noqa: SLF001 -- test-only reach + assert held is not None, "the latch was cleared before the resolve was even attempted" + assert held.item_id == item_id + stale_actor = held.actor + + bd = session._project(project) # noqa: SLF001 + after_reap = bd.get(item_id) + assert after_reap.status == "open" + assert after_reap.holder is None + + # 2. The adapter refuses by itself -- no session, no latch. +> with pytest.raises(A.FencedError) as exc: + ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ +E Failed: DID NOT RAISE FencedError + +modules/tool-work-tracker/tests/test_reap_recovery.py:151: Failed +---------------------------- Captured stdout setup ----------------------------- +Starting server with Config HP="127.0.0.1:48087"|T="28800000"|R="false"|L="info" +---------------------------- Captured stderr setup ----------------------------- +time="2026-09-05T18:54:52-07:00" level=info msg="Creating root@localhost superuser" +time="2026-09-05T18:54:52-07:00" level=info msg="Server ready. Accepting connections." +time="2026-09-05T18:54:52-07:00" level=warning msg="secure_file_priv is set to \"\", which is insecure." +time="2026-09-05T18:54:52-07:00" level=warning msg="Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read." +time="2026-09-05T18:54:52-07:00" level=warning msg="Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory." +time="2026-09-05T18:54:52-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=1 +time="2026-09-05T18:54:52-07:00" level=info msg=ConnectionClosed connectionID=1 +time="2026-09-05T18:54:52-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2 +time="2026-09-05T18:54:52-07:00" level=info msg=ConnectionClosed connectionID=2 +time="2026-09-05T18:54:52-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=3 +time="2026-09-05T18:54:52-07:00" level=info msg=ConnectionClosed connectionID=3 +time="2026-09-05T18:54:52-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=4 +time="2026-09-05T18:54:52-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=5 +time="2026-09-05T18:54:52-07:00" level=info msg=ConnectionClosed connectionID=4 +time="2026-09-05T18:54:52-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:54:52.805330243 -0700 PDT m=+0.529912590" connectionDb=reapproj13707b757f connectionID=5 error="table not found: schema_migrations" queryTime="2026-09-05 18:54:52.807187182 -0700 PDT m=+0.531769529" +time="2026-09-05T18:54:52-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=6 +time="2026-09-05T18:54:52-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:54:52.807908524 -0700 PDT m=+0.532490855" connectionDb=reapproj13707b757f connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:54:52.808559642 -0700 PDT m=+0.533141989" +time="2026-09-05T18:54:52-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:54:52.807908524 -0700 PDT m=+0.532490855" connectionDb=reapproj13707b757f connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:54:52.810404581 -0700 PDT m=+0.534986928" +time="2026-09-05T18:54:52-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:54:52.807908524 -0700 PDT m=+0.532490855" connectionDb=reapproj13707b757f connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:54:52.811650402 -0700 PDT m=+0.536232733" +time="2026-09-05T18:54:54-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:54:52.807908524 -0700 PDT m=+0.532490855" connectionDb=reapproj13707b757f connectionID=6 error="table not found: ignored_schema_migrations" queryTime="2026-09-05 18:54:54.206765262 -0700 PDT m=+1.931347609" +time="2026-09-05T18:54:54-07:00" level=info msg=ConnectionClosed connectionID=6 +time="2026-09-05T18:54:54-07:00" level=info msg=ConnectionClosed connectionID=5 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=7 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=7 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=8 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=9 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=8 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=9 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=10 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=10 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=11 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=12 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=11 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=12 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=13 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=13 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=14 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=15 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=14 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=15 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=16 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=16 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=17 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=17 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=18 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=18 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=19 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=19 +----------------------------- Captured stdout call ----------------------------- + +----------------------------- Captured stderr call ----------------------------- +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=20 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=20 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=21 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=21 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=22 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=23 +time="2026-09-05T18:54:55-07:00" level=info msg=ConnectionClosed connectionID=22 +time="2026-09-05T18:54:55-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=24 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=24 +time="2026-09-05T18:54:56-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:54:55.967983532 -0700 PDT m=+3.692565879" connectionDb=reapproj13707b757f connectionID=23 error="backup 'backup_export' not found" queryTime="2026-09-05 18:54:56.072596725 -0700 PDT m=+3.797179088" +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=23 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=25 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=25 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=26 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=26 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=27 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=27 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=28 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=28 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=29 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=29 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=30 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=30 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=31 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=32 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=31 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=32 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=33 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=33 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=34 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=34 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=35 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=35 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=36 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=36 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=37 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=37 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=38 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=38 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=39 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=39 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=40 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=40 +time="2026-09-05T18:54:56-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=41 +time="2026-09-05T18:54:56-07:00" level=info msg=ConnectionClosed connectionID=41 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=42 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=42 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=43 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=43 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=44 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=44 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=45 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=45 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=46 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=46 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=47 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=47 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=48 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=49 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=48 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=50 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=50 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=49 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=51 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=51 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=52 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=52 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=53 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=53 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=54 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=54 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=55 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=55 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=56 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=56 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=57 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=57 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=58 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=58 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=59 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=59 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=60 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=60 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=61 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=61 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=62 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=62 +time="2026-09-05T18:54:57-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=63 +time="2026-09-05T18:54:57-07:00" level=info msg=ConnectionClosed connectionID=63 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=64 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=64 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=65 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=66 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=65 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=67 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=67 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=66 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=68 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=68 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=69 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=69 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=70 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=70 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=71 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=71 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=72 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=72 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=73 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=73 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=74 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=74 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=75 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=75 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=76 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=76 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=77 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=77 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=78 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=78 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=79 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=79 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=80 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=80 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=81 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=81 +time="2026-09-05T18:54:58-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=82 +time="2026-09-05T18:54:58-07:00" level=info msg=ConnectionClosed connectionID=82 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=83 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=83 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=84 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=85 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=84 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=86 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=86 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=85 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=87 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=87 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=88 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=88 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=89 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=89 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=90 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=90 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=91 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=91 +------------------------------ Captured log call ------------------------------- +ERROR amplifier_work_tracker.webpush:webpush.py:435 ntfy alarm unexpected failure for reclaimed reapproj13707b757f-86q: asyncio.run() cannot be called from a running event loop +--------------------------- Captured stderr teardown --------------------------- +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=92 +time="2026-09-05T18:54:59-07:00" level=info msg="stats stopped: context canceled" +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=92 +time="2026-09-05T18:54:59-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=93 +time="2026-09-05T18:54:59-07:00" level=info msg=ConnectionClosed connectionID=93 +time="2026-09-05T18:54:59-07:00" level=info msg="Server closing listener. No longer accepting connections." +time="2026-09-05T18:54:59-07:00" level=info msg="stats stopped: context canceled" +=============================== warnings summary =============================== +modules/tool-work-tracker/tests/test_reap_recovery.py::test_post_reap_refusal_originates_below_the_session_latch + /home/bkrabach/dev/hw-model-performance/lanes/c0e-ccv1-023-ledger-note/amplifier-work-tracker/.venv/lib/python3.12/site-packages/_pytest/stash.py:108: RuntimeWarning: coroutine 'alarm_for_reclaimed_item' was never awaited + del self._storage[key] + Enable tracemalloc to get traceback where the object was allocated. + See https://docs.pytest.org/en/stable/how-to/capture-warnings.html#resource-warnings for more info. + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +=========================== short test summary info ============================ +FAILED modules/tool-work-tracker/tests/test_reap_recovery.py::test_post_reap_refusal_originates_below_the_session_latch +1 failed, 1 warning in 7.32s diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutB-refusal-moved-to-latch.log b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutB-refusal-moved-to-latch.log new file mode 100644 index 0000000..d721fc9 --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutB-refusal-moved-to-latch.log @@ -0,0 +1,298 @@ +F [100%] +=================================== FAILURES =================================== +__________ test_post_reap_refusal_originates_below_the_session_latch ___________ + +project = 'reapproj483d77f8e6' + + @pytest.mark.asyncio + async def test_post_reap_refusal_originates_below_the_session_latch(project): + """MECHANISM PIN for the test directly above -- ledger rows CCV1-009 + (Core 7) and CCV1-023 (Freeze 3), work item `model_performance-c0e`. + + The test above asserts THAT the post-reap resolve is refused. It does + not assert WHERE the refusal comes from, and the ledger once recorded + the wrong answer: CCV1-023's seeded note said this fixture "asserts the + TOOL-layer refusal (which passes via the session latch)". The session + latch is not a fence -- after a reap it still names the item, so it + passes the call straight THROUGH. The refusal is the ADAPTER's + custody-identity fence (`resolve_outcome`'s `elif cust_holder == who + and current.holder != who`, PR #68 / b3fac1e). + + Prose cannot hold that distinction still, so this pins it executably. + Each assertion below fails under a different regression: + + 1. the latch still names the item at the moment of the refused call + -- if the refusal ever moves UP into the latch, this is the first + thing that has to change, and it changes here first; + 2. the ADAPTER refuses on its own, with no `WorkTrackerSession` in + the picture at all -- delete the fence branch and this raises + nothing (measured: the close then LANDS, `success=True`); + 3. the refusal the tool surfaces is the fence's wording, not the + latch's -- a latch-sourced refusal would say "did not claim"; + 4. the other half of Core 7, at the same site: an integrator's plain + close of that same unheld item still succeeds in one call. A fence + keyed on "the item is unheld" rather than on custody IDENTITY + would pass 1-3 and fail here. + """ + add_session = WorkTrackerSession({"actor": _unique("adder")}) + added = await add_session.add(project, "mechanism-pin item", acceptance="n/a") + assert added.success is True + + session = WorkTrackerSession({"actor": _unique("stale")}) + claimed = await session.claim(project) + assert claimed.success is True + item_id = claimed.output["claimed"] # type: ignore[index] + + assert _force_reap(session, project)["reclaimed_count"] == 1 + + # 1. The latch is NOT the fence: it still names this very item, so + # `resolve`'s own `held.item_id != item_id` gate cannot refuse. + held = session._held # noqa: SLF001 -- test-only reach + assert held is not None, "the latch was cleared before the resolve was even attempted" + assert held.item_id == item_id + stale_actor = held.actor + + bd = session._project(project) # noqa: SLF001 + after_reap = bd.get(item_id) + assert after_reap.status == "open" + assert after_reap.holder is None + + # 2. The adapter refuses by itself -- no session, no latch. + with pytest.raises(A.FencedError) as exc: + bd.resolve(item_id, "closing after the reap, straight at the adapter", actor=stale_actor) + assert "not held by this session" in str(exc.value) + assert bd.get(item_id).status == "open", "the fenced call must not have written anything" + + # 3. What the tool surfaces is the FENCE's text, not the latch's. + refused = await session.resolve(item_id, "trying to close after being reclaimed") + assert refused.success is False + message = str(refused.output) +> assert "custody names" in message, ( + f"the refusal no longer carries the adapter fence's wording: {message!r}" + ) +E AssertionError: the refusal no longer carries the adapter fence's wording: "not currently holding 'reapproj483d77f8e6-emw' in this session -- refusing to resolve an item this session did not claim" +E assert 'custody names' in "not currently holding 'reapproj483d77f8e6-emw' in this session -- refusing to resolve an item this session did not claim" + +modules/tool-work-tracker/tests/test_reap_recovery.py:160: AssertionError +---------------------------- Captured stdout setup ----------------------------- +Starting server with Config HP="127.0.0.1:41109"|T="28800000"|R="false"|L="info" +---------------------------- Captured stderr setup ----------------------------- +time="2026-09-05T18:55:08-07:00" level=info msg="Creating root@localhost superuser" +time="2026-09-05T18:55:08-07:00" level=info msg="Server ready. Accepting connections." +time="2026-09-05T18:55:08-07:00" level=warning msg="secure_file_priv is set to \"\", which is insecure." +time="2026-09-05T18:55:08-07:00" level=warning msg="Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read." +time="2026-09-05T18:55:08-07:00" level=warning msg="Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory." +time="2026-09-05T18:55:08-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=1 +time="2026-09-05T18:55:08-07:00" level=info msg=ConnectionClosed connectionID=1 +time="2026-09-05T18:55:08-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2 +time="2026-09-05T18:55:08-07:00" level=info msg=ConnectionClosed connectionID=2 +time="2026-09-05T18:55:08-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=3 +time="2026-09-05T18:55:08-07:00" level=info msg=ConnectionClosed connectionID=3 +time="2026-09-05T18:55:08-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=4 +time="2026-09-05T18:55:08-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=5 +time="2026-09-05T18:55:08-07:00" level=info msg=ConnectionClosed connectionID=4 +time="2026-09-05T18:55:08-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:08.892739865 -0700 PDT m=+0.482862988" connectionDb=reapproj483d77f8e6 connectionID=5 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:08.894536133 -0700 PDT m=+0.484659256" +time="2026-09-05T18:55:08-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=6 +time="2026-09-05T18:55:08-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:08.895194531 -0700 PDT m=+0.485317638" connectionDb=reapproj483d77f8e6 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:08.895920321 -0700 PDT m=+0.486043444" +time="2026-09-05T18:55:08-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:08.895194531 -0700 PDT m=+0.485317638" connectionDb=reapproj483d77f8e6 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:08.897419965 -0700 PDT m=+0.487543072" +time="2026-09-05T18:55:08-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:08.895194531 -0700 PDT m=+0.485317638" connectionDb=reapproj483d77f8e6 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:08.900121958 -0700 PDT m=+0.490245081" +time="2026-09-05T18:55:10-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:08.895194531 -0700 PDT m=+0.485317638" connectionDb=reapproj483d77f8e6 connectionID=6 error="table not found: ignored_schema_migrations" queryTime="2026-09-05 18:55:10.401662059 -0700 PDT m=+1.991785182" +time="2026-09-05T18:55:10-07:00" level=info msg=ConnectionClosed connectionID=6 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=5 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=7 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=7 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=8 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=9 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=8 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=9 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=10 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=10 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=11 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=12 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=11 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=12 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=13 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=13 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=14 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=15 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=14 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=15 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=16 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=16 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=17 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=17 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=18 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=18 +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=19 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=19 +----------------------------- Captured stdout call ----------------------------- + +----------------------------- Captured stderr call ----------------------------- +time="2026-09-05T18:55:11-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=20 +time="2026-09-05T18:55:11-07:00" level=info msg=ConnectionClosed connectionID=20 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=21 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=21 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=22 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=23 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=22 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=24 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=24 +time="2026-09-05T18:55:12-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:12.112124276 -0700 PDT m=+3.702247415" connectionDb=reapproj483d77f8e6 connectionID=23 error="backup 'backup_export' not found" queryTime="2026-09-05 18:55:12.194155338 -0700 PDT m=+3.784278461" +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=23 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=25 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=25 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=26 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=26 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=27 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=27 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=28 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=28 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=29 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=29 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=30 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=30 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=31 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=32 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=31 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=32 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=33 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=33 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=34 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=34 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=35 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=35 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=36 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=36 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=37 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=37 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=38 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=38 +time="2026-09-05T18:55:12-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=39 +time="2026-09-05T18:55:12-07:00" level=info msg=ConnectionClosed connectionID=39 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=40 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=40 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=41 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=41 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=42 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=42 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=43 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=43 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=44 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=44 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=45 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=45 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=46 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=46 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=47 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=48 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=47 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=49 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=48 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=50 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=50 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=49 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=51 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=51 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=52 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=52 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=53 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=53 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=54 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=54 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=55 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=55 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=56 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=56 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=57 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=57 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=58 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=58 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=59 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=59 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=60 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=60 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=61 +time="2026-09-05T18:55:13-07:00" level=info msg=ConnectionClosed connectionID=61 +time="2026-09-05T18:55:13-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=62 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=62 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=63 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=63 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=64 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=64 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=65 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=66 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=65 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=67 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=67 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=66 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=68 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=68 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=69 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=69 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=70 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=70 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=71 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=71 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=72 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=72 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=73 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=73 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=74 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=74 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=75 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=75 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=76 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=76 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=77 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=77 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=78 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=78 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=79 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=79 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=80 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=80 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=81 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=81 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=82 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=82 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=83 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=83 +time="2026-09-05T18:55:14-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=84 +time="2026-09-05T18:55:14-07:00" level=info msg=ConnectionClosed connectionID=84 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=85 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=85 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=86 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=86 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=87 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=87 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=88 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=88 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=89 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=89 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=90 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=90 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=91 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=91 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=92 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=92 +------------------------------ Captured log call ------------------------------- +ERROR amplifier_work_tracker.webpush:webpush.py:435 ntfy alarm unexpected failure for reclaimed reapproj483d77f8e6-emw: asyncio.run() cannot be called from a running event loop +--------------------------- Captured stderr teardown --------------------------- +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=93 +time="2026-09-05T18:55:15-07:00" level=info msg="stats stopped: context canceled" +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=93 +time="2026-09-05T18:55:15-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=94 +time="2026-09-05T18:55:15-07:00" level=info msg=ConnectionClosed connectionID=94 +time="2026-09-05T18:55:15-07:00" level=info msg="Server closing listener. No longer accepting connections." +time="2026-09-05T18:55:15-07:00" level=info msg="stats stopped: context canceled" +=============================== warnings summary =============================== +modules/tool-work-tracker/tests/test_reap_recovery.py::test_post_reap_refusal_originates_below_the_session_latch + /home/bkrabach/dev/hw-model-performance/lanes/c0e-ccv1-023-ledger-note/amplifier-work-tracker/.venv/lib/python3.12/site-packages/_pytest/stash.py:108: RuntimeWarning: coroutine 'alarm_for_reclaimed_item' was never awaited + del self._storage[key] + Enable tracemalloc to get traceback where the object was allocated. + See https://docs.pytest.org/en/stable/how-to/capture-warnings.html#resource-warnings for more info. + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +=========================== short test summary info ============================ +FAILED modules/tool-work-tracker/tests/test_reap_recovery.py::test_post_reap_refusal_originates_below_the_session_latch +1 failed, 1 warning in 7.08s diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutC-fence-rekeyed-on-unheld.log b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutC-fence-rekeyed-on-unheld.log new file mode 100644 index 0000000..5ecf948 --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/pin-mutC-fence-rekeyed-on-unheld.log @@ -0,0 +1,472 @@ +F [100%] +=================================== FAILURES =================================== +__________ test_post_reap_refusal_originates_below_the_session_latch ___________ + +project = 'reapprojc990544696' + + @pytest.mark.asyncio + async def test_post_reap_refusal_originates_below_the_session_latch(project): + """MECHANISM PIN for the test directly above -- ledger rows CCV1-009 + (Core 7) and CCV1-023 (Freeze 3), work item `model_performance-c0e`. + + The test above asserts THAT the post-reap resolve is refused. It does + not assert WHERE the refusal comes from, and the ledger once recorded + the wrong answer: CCV1-023's seeded note said this fixture "asserts the + TOOL-layer refusal (which passes via the session latch)". The session + latch is not a fence -- after a reap it still names the item, so it + passes the call straight THROUGH. The refusal is the ADAPTER's + custody-identity fence (`resolve_outcome`'s `elif cust_holder == who + and current.holder != who`, PR #68 / b3fac1e). + + Prose cannot hold that distinction still, so this pins it executably. + Each assertion below fails under a different regression: + + 1. the latch still names the item at the moment of the refused call + -- if the refusal ever moves UP into the latch, this is the first + thing that has to change, and it changes here first; + 2. the ADAPTER refuses on its own, with no `WorkTrackerSession` in + the picture at all -- delete the fence branch and this raises + nothing (measured: the close then LANDS, `success=True`); + 3. the refusal the tool surfaces is the fence's wording, not the + latch's -- a latch-sourced refusal would say "did not claim"; + 4. the other half of Core 7, at the same site: an integrator's plain + close of that same unheld item still succeeds in one call. A fence + keyed on "the item is unheld" rather than on custody IDENTITY + would pass 1-3 and fail here. + """ + add_session = WorkTrackerSession({"actor": _unique("adder")}) + added = await add_session.add(project, "mechanism-pin item", acceptance="n/a") + assert added.success is True + + session = WorkTrackerSession({"actor": _unique("stale")}) + claimed = await session.claim(project) + assert claimed.success is True + item_id = claimed.output["claimed"] # type: ignore[index] + + assert _force_reap(session, project)["reclaimed_count"] == 1 + + # 1. The latch is NOT the fence: it still names this very item, so + # `resolve`'s own `held.item_id != item_id` gate cannot refuse. + held = session._held # noqa: SLF001 -- test-only reach + assert held is not None, "the latch was cleared before the resolve was even attempted" + assert held.item_id == item_id + stale_actor = held.actor + + bd = session._project(project) # noqa: SLF001 + after_reap = bd.get(item_id) + assert after_reap.status == "open" + assert after_reap.holder is None + + # 2. The adapter refuses by itself -- no session, no latch. + with pytest.raises(A.FencedError) as exc: + bd.resolve(item_id, "closing after the reap, straight at the adapter", actor=stale_actor) + assert "not held by this session" in str(exc.value) + assert bd.get(item_id).status == "open", "the fenced call must not have written anything" + + # 3. What the tool surfaces is the FENCE's text, not the latch's. + refused = await session.resolve(item_id, "trying to close after being reclaimed") + assert refused.success is False + message = str(refused.output) + assert "custody names" in message, ( + f"the refusal no longer carries the adapter fence's wording: {message!r}" + ) + assert "did not claim" not in message, ( + "the refusal is now the SESSION LATCH's -- the mechanism this row's note " + f"says is not the one operating: {message!r}" + ) + + # 4. Core 7's other half, same item, same state: everyone who is not the + # stale holder is exactly as unfenced as before. +> integrator = bd.resolve(item_id, "closed out by the integrator", actor=_unique("integrator")) + ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ + +modules/tool-work-tracker/tests/test_reap_recovery.py:170: +_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ + +self = +item_id = 'reapprojc990544696-3xg', reason = 'closed out by the integrator' +actor = 'integrator690d135eb9' + + def resolve(self, item_id: str, reason: str, *, actor: str | None = None) -> Item: + """Close an item and VERIFY the write landed -- the `Item`-returning + projection of `resolve_outcome`, which every existing caller already + uses and which is unchanged for them. + + A pure one-line projection ON PURPOSE: two entry points to one + operation can only stay honest if one of them cannot hold logic of + its own to drift with. Callers that need to distinguish "I wrote + this resolution just now" from "this identical resolution was + already stored" (the CLI, `work_resolve`) call `resolve_outcome` + directly for its `idempotent` flag. + """ +> return self.resolve_outcome(item_id, reason, actor=actor).item + ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ + +src/amplifier_work_tracker/adapter.py:4077: +_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ + +self = +item_id = 'reapprojc990544696-3xg', reason = 'closed out by the integrator' +actor = 'integrator690d135eb9' + + def resolve_outcome( + self, item_id: str, reason: str, *, actor: str | None = None + ) -> ResolveOutcome: + """Close an item and VERIFY the write landed. Exit code is not proof. + + WHAT "LANDED" MEANS: the item stores the TEXT THIS CALL SENT -- + not merely that the item is closed. Comparing status alone was the + measured defect (work_tracker item model_performance-uma): a + resolve against an already-closed item exited 0 and echoed the OLD + text back as if it were the new one, silently discarding a + correction. `resolve` is checked against `_resolution_landed` at + BOTH places it decides that question -- the normal post-write + readback AND the contended path below -- because a caller on the + contended path is precisely the one least able to reason about + what actually happened. + + THE RULE, on a target that is ALREADY resolved (checked BEFORE any + write, so "NOTHING WAS WRITTEN" is literally true): + + - text IDENTICAL (after `_norm_resolution`) -> success, + `idempotent=True`, no write attempted. This carve-out is + required, not a softening: the shipped contention contract + sells resolve's no-op as RETRY SAFETY, and a retry re-sends + the identical string. A blanket error would fail a legitimate + retry of a write that did land, and tell its caller their + resolve failed when it succeeded. + - text DIFFERS -> `BeadsError` (`_divergent_resolution_error`), + nothing written, the remedy (`reopen`) named as a runnable + command. Correcting a published record is a deliberate, + audited transition -- never an invisible side effect of a call + the caller believes is idempotent. + + Resolving an OPEN item is unchanged, byte for byte. + + FENCED in every state a caller can no longer legitimately close + from -- but the fence is keyed on WHO the custody record names, + never on the item's status alone. Both halves matter, and each one + was, at some point, a measured bug: + + HALF ONE -- an integrator's plain resolve must stay a single call. + Resolving an item nobody currently holds (open/blocked/deferred/ + resolved), even one filed or last held by someone else entirely, + needs no fence and no override. The fence used to fire on custody + metadata ALONE, so a STALE record from a hold that ended long ago + kept naming a "current holder" who held nothing, refusing an + integrator's close of someone else's already-unheld report + (work_tracker item 79t, PR #51). Anyone who is not the session that + record names is exactly as unfenced as before. + + HALF TWO -- the stale holder itself is refused in EVERY + post-reclaim state, including the released-but-not-yet-re-claimed + one (contract `custody-coordination.v1` Core 7; ledger row + CCV1-009; work_tracker item pipeline-dn4). 79t's fix reached for + the item's status as its discriminator (`status == "held"`), which + reinstated the very bug the fence exists to close: `reap` does not + leave a reclaimed item `held` -- `supervisor.reap_project` calls + `release`, which puts it back to `open` and clears bd's assignee -- + so the one state the fence is FOR was the one state it skipped, and + the stale holder's close landed with exit 0 and no refusal + anywhere. Status was never the right question; custody identity is. + + Hence the three checks below, in the order they can be answered: + + - held, with a custody record: that record is authoritative over + bd's own assignee, because a reclaim CLEARS the assignee rather + than reassigning it -- "no current holder" and "never held at + all" look identical in bd, and only the custody record can tell + them apart. Refuse unless BOTH name this caller. + - held, no custody record: fall back to bd's assignee alone -- + enough to catch a live takeover by another session. + - NOT held, but the custody record still names this caller: this + session's hold ended without this session closing the item -- + reclaimed by `reap`, or handed back by `release`, which are + indistinguishable by construction (see `agent_stats`, which + documents why). Either way it does not hold the item now, and + its close is refused. + + A custody record is deliberately left in place across a reclaim, so + it can still answer "who held this last" -- that is what makes the + third check possible at all. The `current.holder != who` guard on + it is what keeps a holder's own already-landed close re-attemptable + (a resolved item retains its assignee, so a wedged session + confirming its own close is never mistaken for a reclaimed one -- + see this method's verify-by-read-back branch below). + + Every refusal names the real holder and the recovery: re-claim the + item, or wait for `reap` to reclaim a stale hold. + """ + who = actor or self._actor + # ONE pre-write read serves every precondition below -- the + # custody fence, THEN the already-resolved rule -- so both are + # decided before the `bd close` write is even attempted (see the + # "NOTHING WAS WRITTEN" promise above). Deliberately tolerant of a + # read failure when no actor is given, so an item that does not + # exist still surfaces through bd's own `close` error exactly as + # before -- this method must not newly re-diagnose "not found". + try: + current: Item | None = self.get(item_id) + except BeadsError: + if who: + raise + current = None + if who and current is not None: + cust = current.meta.get(C.CUSTODY_KEY) if isinstance(current.meta, dict) else None + cust_holder = cust.get("holder") if isinstance(cust, dict) else None + if current.status == "held": + if cust_holder: + if current.holder != who or cust_holder != who: + raise FencedError( + f"refusing to close {item_id}: current holder is " + f"{current.holder!r} (custody holder {cust_holder!r}), " + f"not {who!r}. Your claim was reclaimed while you were away." + ) + elif current.holder and current.holder != who: + raise FencedError( + f"refusing to close {item_id}: it is held by {current.holder!r}, " + f"not {who!r}. Your claim was reclaimed while you were away." + ) + elif current.holder != who: +> raise FencedError( + f"refusing to close {item_id}: not held by this session -- custody " + f"names {who!r} as its last holder, but the item is now " + f"{current.status!r} with no current holder. Your claim was " + f"reclaimed (or released) while you were away. Re-claim it first, " + f"then resolve." + ) +E amplifier_work_tracker.adapter.FencedError: refusing to close reapprojc990544696-3xg: not held by this session -- custody names 'integrator690d135eb9' as its last holder, but the item is now 'open' with no current holder. Your claim was reclaimed (or released) while you were away. Re-claim it first, then resolve. + +src/amplifier_work_tracker/adapter.py:4198: FencedError +---------------------------- Captured stdout setup ----------------------------- +Starting server with Config HP="127.0.0.1:49421"|T="28800000"|R="false"|L="info" +---------------------------- Captured stderr setup ----------------------------- +time="2026-09-05T18:55:25-07:00" level=info msg="Creating root@localhost superuser" +time="2026-09-05T18:55:25-07:00" level=info msg="Server ready. Accepting connections." +time="2026-09-05T18:55:25-07:00" level=warning msg="secure_file_priv is set to \"\", which is insecure." +time="2026-09-05T18:55:25-07:00" level=warning msg="Any user with GRANT FILE privileges will be able to read any file which the sql-server process can read." +time="2026-09-05T18:55:25-07:00" level=warning msg="Please consider restarting the server with secure_file_priv set to a safe (or non-existent) directory." +time="2026-09-05T18:55:25-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=1 +time="2026-09-05T18:55:25-07:00" level=info msg=ConnectionClosed connectionID=1 +time="2026-09-05T18:55:25-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2 +time="2026-09-05T18:55:25-07:00" level=info msg=ConnectionClosed connectionID=2 +time="2026-09-05T18:55:25-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=3 +time="2026-09-05T18:55:25-07:00" level=info msg=ConnectionClosed connectionID=3 +time="2026-09-05T18:55:25-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=4 +time="2026-09-05T18:55:25-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=5 +time="2026-09-05T18:55:25-07:00" level=info msg=ConnectionClosed connectionID=4 +time="2026-09-05T18:55:25-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:25.539908345 -0700 PDT m=+0.519863963" connectionDb=reapprojc990544696 connectionID=5 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:25.541159733 -0700 PDT m=+0.521115335" +time="2026-09-05T18:55:25-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=6 +time="2026-09-05T18:55:25-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:25.541490261 -0700 PDT m=+0.521445863" connectionDb=reapprojc990544696 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:25.542169395 -0700 PDT m=+0.522124997" +time="2026-09-05T18:55:25-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:25.541490261 -0700 PDT m=+0.521445863" connectionDb=reapprojc990544696 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:25.543739743 -0700 PDT m=+0.523695377" +time="2026-09-05T18:55:25-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:25.541490261 -0700 PDT m=+0.521445863" connectionDb=reapprojc990544696 connectionID=6 error="table not found: schema_migrations" queryTime="2026-09-05 18:55:25.545502826 -0700 PDT m=+0.525458428" +time="2026-09-05T18:55:27-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:25.541490261 -0700 PDT m=+0.521445863" connectionDb=reapprojc990544696 connectionID=6 error="table not found: ignored_schema_migrations" queryTime="2026-09-05 18:55:27.043897067 -0700 PDT m=+2.023852669" +time="2026-09-05T18:55:27-07:00" level=info msg=ConnectionClosed connectionID=6 +time="2026-09-05T18:55:27-07:00" level=info msg=ConnectionClosed connectionID=5 +time="2026-09-05T18:55:27-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=7 +time="2026-09-05T18:55:27-07:00" level=info msg=ConnectionClosed connectionID=7 +time="2026-09-05T18:55:27-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=8 +time="2026-09-05T18:55:27-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=9 +time="2026-09-05T18:55:27-07:00" level=info msg=ConnectionClosed connectionID=8 +time="2026-09-05T18:55:27-07:00" level=info msg=ConnectionClosed connectionID=9 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=10 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=10 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=11 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=12 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=11 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=12 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=13 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=13 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=14 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=15 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=14 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=15 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=16 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=16 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=17 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=17 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=18 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=18 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=19 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=19 +----------------------------- Captured stdout call ----------------------------- + +----------------------------- Captured stderr call ----------------------------- +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=20 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=20 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=21 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=21 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=22 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=23 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=22 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=24 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=24 +time="2026-09-05T18:55:28-07:00" level=warning msg="error running query" connectTime="2026-09-05 18:55:28.639499994 -0700 PDT m=+3.619455580" connectionDb=reapprojc990544696 connectionID=23 error="backup 'backup_export' not found" queryTime="2026-09-05 18:55:28.731943028 -0700 PDT m=+3.711898630" +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=23 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=25 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=25 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=26 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=26 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=27 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=27 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=28 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=28 +time="2026-09-05T18:55:28-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=29 +time="2026-09-05T18:55:28-07:00" level=info msg=ConnectionClosed connectionID=29 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=30 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=30 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=31 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=32 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=31 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=32 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=33 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=33 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=34 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=34 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=35 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=35 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=36 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=36 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=37 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=37 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=38 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=38 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=39 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=39 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=40 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=40 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=41 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=41 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=42 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=42 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=43 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=43 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=44 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=44 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=45 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=45 +time="2026-09-05T18:55:29-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=46 +time="2026-09-05T18:55:29-07:00" level=info msg=ConnectionClosed connectionID=46 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=47 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=47 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=48 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=49 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=48 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=50 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=50 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=49 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=51 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=51 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=52 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=52 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=53 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=53 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=54 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=54 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=55 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=55 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=56 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=56 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=57 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=57 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=58 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=58 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=59 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=59 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=60 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=60 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=61 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=61 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=62 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=62 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=63 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=63 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=64 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=64 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=65 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=66 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=65 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=67 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=67 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=66 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=68 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=68 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=69 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=69 +time="2026-09-05T18:55:30-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=70 +time="2026-09-05T18:55:30-07:00" level=info msg=ConnectionClosed connectionID=70 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=71 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=71 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=72 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=72 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=73 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=73 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=74 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=74 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=75 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=75 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=76 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=76 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=77 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=77 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=78 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=78 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=79 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=79 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=80 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=80 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=81 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=81 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=82 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=82 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=83 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=83 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=84 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=84 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=85 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=85 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=86 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=86 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=87 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=87 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=88 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=88 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=89 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=89 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=90 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=90 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=91 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=91 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=92 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=92 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=93 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=93 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=94 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=94 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=95 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=95 +time="2026-09-05T18:55:31-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=96 +time="2026-09-05T18:55:31-07:00" level=info msg=ConnectionClosed connectionID=96 +time="2026-09-05T18:55:32-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=97 +time="2026-09-05T18:55:32-07:00" level=info msg=ConnectionClosed connectionID=97 +------------------------------ Captured log call ------------------------------- +ERROR amplifier_work_tracker.webpush:webpush.py:435 ntfy alarm unexpected failure for reclaimed reapprojc990544696-3xg: asyncio.run() cannot be called from a running event loop +--------------------------- Captured stderr teardown --------------------------- +time="2026-09-05T18:55:32-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=98 +time="2026-09-05T18:55:32-07:00" level=info msg="stats stopped: context canceled" +time="2026-09-05T18:55:32-07:00" level=info msg=ConnectionClosed connectionID=98 +time="2026-09-05T18:55:32-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=99 +time="2026-09-05T18:55:32-07:00" level=info msg=ConnectionClosed connectionID=99 +time="2026-09-05T18:55:32-07:00" level=info msg="Server closing listener. No longer accepting connections." +time="2026-09-05T18:55:32-07:00" level=info msg="stats stopped: context canceled" +=============================== warnings summary =============================== +modules/tool-work-tracker/tests/test_reap_recovery.py::test_post_reap_refusal_originates_below_the_session_latch + /home/bkrabach/dev/hw-model-performance/lanes/c0e-ccv1-023-ledger-note/amplifier-work-tracker/.venv/lib/python3.12/site-packages/_pytest/stash.py:108: RuntimeWarning: coroutine 'alarm_for_reclaimed_item' was never awaited + del self._storage[key] + Enable tracemalloc to get traceback where the object was allocated. + See https://docs.pytest.org/en/stable/how-to/capture-warnings.html#resource-warnings for more info. + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +=========================== short test summary info ============================ +FAILED modules/tool-work-tracker/tests/test_reap_recovery.py::test_post_reap_refusal_originates_below_the_session_latch +1 failed, 1 warning in 7.19s diff --git a/docs/lanes/c0e-ccv1-023-ledger-note/evidence/tier-ledger-mutate.log b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/tier-ledger-mutate.log new file mode 100644 index 0000000..51d53ec --- /dev/null +++ b/docs/lanes/c0e-ccv1-023-ledger-note/evidence/tier-ledger-mutate.log @@ -0,0 +1,161 @@ +.venv/bin/python -m ledger.checks.mutation_harness +LEDGER MUTATION HARNESS -- discriminating-power evidence +Each probe is run against a counterfactual repo and must go RED. +Injection only: no product-code edit, no subprocess, nothing written to the repo. + +PINNING PROBES (row is red; probe pins the CURRENT non-conformant shape; + counterfactual = the FIXED behaviour) + [PROVEN ] OSV1-034 VIOLATION-MOVEMENT (GAP) + test_row_osv1_034 :: a Changelog entry records the owner's rendered-page look + +CONFORMANCE PROBES (row is green; probe asserts the invariant; + counterfactual = the known-wrong shape it forbids) + [PROVEN ] CCV1-000 LEDGER-INTEGRITY (CONFORMS) + test_row_ccv1_000 :: the governed contract moved under the pinned hash + [PROVEN ] CCV1-003 REGRESSION (CONFORMS) + test_row_ccv1_003 :: the failed-custody arm returns a bare failure again (no compensating release) + [PROVEN ] CCV1-004 REGRESSION (CONFORMS) + test_row_ccv1_004 :: a failed renewal no longer stops the loop (retry returns) + [PROVEN ] CCV1-005 REGRESSION (CONFORMS) + test_row_ccv1_005 :: the custody-keeps-itself-fresh reassurance returns to the skill + [PROVEN ] CCV1-008 REGRESSION (CONFORMS) + test_row_ccv1_008 :: awareness.md states the TTL release as automatic again + [PROVEN ] CCV1-009 REGRESSION (CONFORMS) + test_row_ccv1_009 :: the close fence is re-gated on item status (the original post-reclaim gap) + [PROVEN ] CCV1-011 REGRESSION (CONFORMS) + test_row_ccv1_011 :: renewal fences on holder only -- a zombie's generation matches again + [PROVEN ] CCV1-012 REGRESSION (CONFORMS) + test_row_ccv1_012 :: release reports its outcome from the exit code, not the read-back + [PROVEN ] CCV1-013 REGRESSION (CONFORMS) + test_row_ccv1_013 :: claim_item returns an Item parsed from the writing process's own stdout + [PROVEN ] CCV1-015 REGRESSION (CONFORMS) + test_row_ccv1_015 :: _verified_write stops verifying the SUCCESS path + [PROVEN ] CCV1-016 REGRESSION (CONFORMS) + test_row_ccv1_016 :: the transaction-was-aborted guarantee Incident B disproved returns to the prose + [PROVEN ] CCV1-017 REGRESSION (CONFORMS) + test_row_ccv1_017 :: the single-hold refusal is removed from the tool seam + [PROVEN ] CCV1-021 REGRESSION (CONFORMS) + test_row_ccv1_021 :: `make test` stops collecting ledger/checks + [PROVEN ] CCV1-022 REGRESSION (CONFORMS) + test_row_ccv1_022 :: CI stops installing the tool module editable (suite runs in nothing again) + [PROVEN ] CCV1-023 REGRESSION (CONFORMS) + test_row_ccv1_023 :: the contract's corrected Fixture 1 Test-location line regresses to the stale path + [PROVEN ] OSV1-000 LEDGER-INTEGRITY (CONFORMS) + test_row_osv1_000 :: a governed contract moved under the pinned hash + [PROVEN ] OSV1-001 REGRESSION (CONFORMS) + test_row_osv1_001 :: the hero keeps its throughput figure but stops stating the window it covers + [PROVEN ] OSV1-001 REGRESSION (CONFORMS) + test_row_osv1_001 :: the needs-attention count is dropped from the L0 hero again + [PROVEN ] OSV1-002 REGRESSION (CONFORMS) + test_row_osv1_002 :: the --amber alias acquires its own literal value (a bespoke fourth status hue) + [PROVEN ] OSV1-003 REGRESSION (CONFORMS) + test_row_osv1_003 :: the browser measures a calm L1 painting --blocked again (97 px, the pre-fix reading) + [PROVEN ] OSV1-003 REGRESSION (CONFORMS) + test_row_osv1_003 :: the retired pre-blend-3 palette comes back to webpwa.py's offline body (the specimen this row pinned as PRESENT until OSV1-005 closed it, now guarded from the other side) + [PROVEN ] OSV1-003 REGRESSION (CONFORMS) + test_row_osv1_003 :: the sweep goes blind: the genuinely-alarming fixture reports 0 --blocked where it measured 264, so the row's calm zeroes stop being evidence + [PROVEN ] OSV1-004 REGRESSION (CONFORMS) + test_row_osv1_004 :: a status chip loses its word and carries only a class + [PROVEN ] OSV1-005 REGRESSION (CONFORMS) + test_row_osv1_005 :: a module outside the token module ships its own stylesheet again, re-declaring role tokens as literal hexes -- the second-source-of-visual-truth half Core 4 could not reach before the 2026-09-04 true-up + [PROVEN ] OSV1-005 REGRESSION (CONFORMS) + test_row_osv1_005 :: one inline `style=` attribute carries a literal colour again (Core 4 tolerates zero, so one site is the whole defect) + [PROVEN ] OSV1-006 REGRESSION (CONFORMS) + test_row_osv1_006 :: an inline computed-geometry site appears that nobody registered + [PROVEN ] OSV1-007 REGRESSION (CONFORMS) + test_row_osv1_007 :: the L1 GET view acquires a mutating adapter call + [PROVEN ] OSV1-008 REGRESSION (CONFORMS) + test_row_osv1_008 :: L1 goes back to rendering no live region at all (Core 6's announcement half failing one step earlier than the swap) + [PROVEN ] OSV1-008 REGRESSION (CONFORMS) + test_row_osv1_008 :: the browser measures L0's tagged live region destroyed by the swap again (node identity lost -- the reading a destroy-and-rebuild cannot fake) + [PROVEN ] OSV1-008 REGRESSION (CONFORMS) + test_row_osv1_008 :: the browser measures an open `
` no longer surviving the swap + [PROVEN ] OSV1-008 REGRESSION (CONFORMS) + test_row_osv1_008 :: the browser measures the pause CONTROL no longer surviving the swap + [PROVEN ] OSV1-008 REGRESSION (CONFORMS) + test_row_osv1_008 :: the surviving region's announcement is replaced across the swap (node kept, sentence cut off -- the half a node-identity check alone would miss) + [PROVEN ] OSV1-009 REGRESSION (CONFORMS) + test_row_osv1_009 :: --ink-quiet falls back below the text floor in the :root[data-theme="light"] block + [PROVEN ] OSV1-009 REGRESSION (CONFORMS) + test_row_osv1_009 :: --ink-quiet falls back below the text floor in the prefers-color-scheme light block + [PROVEN ] OSV1-010 REGRESSION (CONFORMS) + test_row_osv1_010 :: the browser measures one interactive control back under 44px on a swept render + [PROVEN ] OSV1-010 REGRESSION (CONFORMS) + test_row_osv1_010 :: the one enumerated non-text exemption grows to cover more than the donut track + [PROVEN ] OSV1-011 REGRESSION (CONFORMS) + test_row_osv1_011 :: reduced motion becomes per-widget opt-in (a second @media block) + [PROVEN ] OSV1-011 REGRESSION (CONFORMS) + test_row_osv1_011 :: the browser measures an animation still RUNNING under the preference on a swept render, while the stylesheet still says the right thing + [PROVEN ] OSV1-012 REGRESSION (CONFORMS) + test_row_osv1_012 :: the empty attention queue goes back to a bare container -- slot, no sentence + [PROVEN ] OSV1-012 REGRESSION (CONFORMS) + test_row_osv1_012 :: the sentence survives but `.empty-note` stops holding a box, so the slot collapses + [PROVEN ] OSV1-013 REGRESSION (CONFORMS) + test_row_osv1_013 :: the manifest declares a template engine + [PROVEN ] OSV1-014 REGRESSION (CONFORMS) + test_row_osv1_014 :: the manifest declares a charting library + [PROVEN ] OSV1-015 REGRESSION (CONFORMS) + test_row_osv1_015 :: the L1 view's bounded query goes unbounded again + [PROVEN ] OSV1-016 REGRESSION (CONFORMS) + test_row_osv1_016 :: the first-paint resolver leaves , so the stored theme is never applied + [PROVEN ] OSV1-016 REGRESSION (CONFORMS) + test_row_osv1_016 :: the theme choice stops surviving a refresh + [PROVEN ] OSV1-017 REGRESSION (CONFORMS) + test_row_osv1_017 :: the push channel acquires a second call site + [PROVEN ] OSV1-020 REGRESSION (CONFORMS) + test_row_osv1_020 :: Conformance 1's injected-alarm-chip bad half stops catching its defect + [PROVEN ] OSV1-021 REGRESSION (CONFORMS) + test_row_osv1_021 :: Conformance 2's Tier-A good half is deferred again behind an xfail + [PROVEN ] OSV1-021 REGRESSION (CONFORMS) + test_row_osv1_021 :: a rendered status chip loses its word (the Tier-B half) + [PROVEN ] OSV1-022 REGRESSION (CONFORMS) + test_row_osv1_022 :: Conformance 3's naive-replacement bad half stops losing the open disclosure + [PROVEN ] OSV1-022 REGRESSION (CONFORMS) + test_row_osv1_022 :: the whole-body innerHTML swap (the bad fixture's own premise) changes shape + [PROVEN ] OSV1-023 REGRESSION (CONFORMS) + test_row_osv1_023 :: Conformance 4's contrast bad half loses its dark-mode control + [PROVEN ] OSV1-023 REGRESSION (CONFORMS) + test_row_osv1_023 :: a swept breakpoint disappears from the stylesheet + [PROVEN ] OSV1-024 REGRESSION (CONFORMS) + test_row_osv1_024 :: Conformance 5's good half is deferred again behind an xfail naming OSV1-001 + [PROVEN ] OSV1-024 REGRESSION (CONFORMS) + test_row_osv1_024 :: OSV1-001 reopens, so Conformance 5 is no longer demonstrated end-to-end + [PROVEN ] OSV1-025 REGRESSION (CONFORMS) + test_row_osv1_025 :: OSV1-005 reopens, so Conformance 6 is no longer demonstrated end-to-end + [PROVEN ] OSV1-026 REGRESSION (CONFORMS) + test_row_osv1_026 :: Conformance 7's L1 good half is deferred again behind an xfail naming OSV1-012 + [PROVEN ] OSV1-026 REGRESSION (CONFORMS) + test_row_osv1_026 :: OSV1-012 reopens, so Conformance 7 is no longer demonstrated end-to-end + [PROVEN ] OSV1-027 REGRESSION (CONFORMS) + test_row_osv1_027 :: CI stops running the Tier-A kit (the 'runs in a gate' half) + [PROVEN ] OSV1-028 REGRESSION (CONFORMS) + test_row_osv1_028 :: the manifest's chromium pin moves while the recorded numbers stay behind + [PROVEN ] OSV1-029 REGRESSION (CONFORMS) + test_row_osv1_029 :: the Tier-B kit stops reading its own artifacts back before asserting + [PROVEN ] OSV1-030 REGRESSION (CONFORMS) + test_row_osv1_030 :: Conformance 4's contrast bad half borrows the LIVE token pair again, so its defect goes back to following the product's own fixes around + [PROVEN ] OSV1-030 REGRESSION (CONFORMS) + test_row_osv1_030 :: a re-recorded run shows one of the fourteen fixture arms measuring at or above the floor it is supposed to fail + [PROVEN ] OSV1-031 REGRESSION (CONFORMS) + test_row_osv1_031 :: a green Core-carrying row (OSV1-008) goes back to VIOLATION, so Freeze 5's condition stops holding under a Freeze row that still reads CONFORMS + [PROVEN ] OSV1-032 REGRESSION (CONFORMS) + test_row_osv1_032 :: a literal inline site returns (Freeze 6's second conjunct, inline half -- simulable now that the row is green; it was not while simulating the FIX meant rewriting 66 real sites) + [PROVEN ] OSV1-032 REGRESSION (CONFORMS) + test_row_osv1_032 :: a page-local stylesheet returns with literal declarations (Freeze 6's second conjunct, `