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, `