diff --git a/AGENTS.md b/AGENTS.md index f8d998d..e4303c0 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -26,7 +26,7 @@ Nothing above the seam should ever need to change for a Beads upgrade. ## `doctor` is the gate, not a suggestion Run `amplifier-work-tracker doctor` after any `bd` upgrade and before -trusting parallel agents against a queue. It must report **36/36 +trusting parallel agents against a queue. It must report **37/37 assumptions hold**; anything less means Beads' behavior moved out from under an assumption we depend on (or, for `sweeps.alive`, that the reap/notify sweep loops have stopped completing sweeps, or, for @@ -48,7 +48,9 @@ merged total to 34, which is MEASURED from `doctor` on the merged tree -- not 33+2 arithmetic, which would have said 35. The two `defer`/`block`.`refuses_resolved` assumptions -- the fence on the destructive-reopen defect, `model_performance-2nx` -- then take it to -**36**, again MEASURED from `doctor`, not computed.) +**36**, again MEASURED from `doctor`, not computed. `read.unavailable_not_absent` +(model_performance-8zv) makes it **37** -- measured on the rebased branch, not +computed from 36+1.) ## Test scope @@ -134,7 +136,7 @@ runs itself is how you lose data you meant to keep. ## What "done" looks like -Full suite green, `doctor` 36/36, `ruff check` / `ruff format --check` / +Full suite green, `doctor` 37/37, `ruff check` / `ruff format --check` / `pyright` clean. For any change to the bundle's zero-state install path (service bootstrap, `work_tracker_install`, prereqs), the acceptance gate is a fresh Digital Twin Universe run from a genuinely empty machine (no `bd`, diff --git a/docs/lanes/8zv-dolt-scan-dir/DONE-NOTE.md b/docs/lanes/8zv-dolt-scan-dir/DONE-NOTE.md new file mode 100644 index 0000000..f64745b --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/DONE-NOTE.md @@ -0,0 +1,228 @@ +# Lane 8zv — pin the dolt scan directory; stop reporting infrastructure failure as "item not found" + +Item: `model_performance-8zv` (project `model_performance`). +Repo: `github.com/microsoft/amplifier-work-tracker`, branch `lane/8zv-dolt-scan-dir`. +Spend: **$0** — no API calls, no DTU, no infrastructure created, nothing registered in +the infra ledger and nothing to tear down. The whole lane is a code change plus rpz's +own $0 harness. + +Diagnosis was **not** re-derived: lane `model_performance-rpz` owns it +(`ai-notes` branch `lane/rpz-dolt-error-misreport`, commit `a6c6e03`). This lane fixes, +measures, and fences it. + +--- + +## 1. What was wrong (rpz's diagnosis, restated only to anchor the fix) + +The `dolt` CLI enumerates its data directory and `lstat()`s every entry on **every** +invocation — including the pure client mode (`--host/--port` against the already-running +shared server) that every `_dolt_*` helper in `adapter.py` uses, where no local database +is relevant at all. With no `--data-dir` given, that directory is the **inherited current +working directory** — whatever directory the calling agent happened to be in. If an entry +vanishes between `readdir` and `lstat`, dolt aborts the whole query. + +`_dolt_sql` / `_dolt_sql_json` passed no `cwd=` to `_run_bounded`, so the failure rate of +a work-tracker read was set by an unrelated process's litter in `/tmp`. + +--- + +## 2. What changed (all in `adapter.py` unless named otherwise) + +| # | Change | Why this one | +|---|---|---| +| 1 | `_dolt_scan_dir()` — a stable, empty, memoised directory we own (`$XDG_CACHE_HOME`/`~/.cache/amplifier-work-tracker/dolt-scan`, overridable via `AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR`). Applied **two independent ways**: `cwd=` on the two hot helpers, and `--data-dir` in `_dolt_conn_args()` so *every* dolt invocation in the module gets it by construction. | REMOVES the failure rather than tolerating it. Both remedies measured 0/25 under the load that produced 7/25 and 12/25 unpinned. Two, not one, because they are independent — a refactor dropping either must not silently reopen the defect. | +| 2 | `_run_dolt_sql_bounded()` — the same bounded transport retry `Beads._run` already had for `bd`, now on the direct-SQL path; `"failed to load database names"` added to `_RETRYABLE_CONNECTION`. | The retry classification lived **only** in `Beads._run`. The direct dolt-SQL path had none, across 19 call sites. Adding the string alone would have landed in a table this path never read. Putting the loop in one helper is what makes all 19 benefit. | +| 3 | `BeadsUnavailableError(BeadsError)` + one classifier `_sql_failure()` at the six SQL read sites. `claim_item` and `get_readonly` re-raise it untouched; `project_summary` reports `UNAVAILABLE: …` (`STATUS_UNAVAILABLE_PREFIX`, `is_unavailable_status`). | A **type**, not a substring callers must grep. `get_readonly` stops discarding the cause — the specific one-line defect, on the exact path `context/awareness.md` hazard #6 tells agents to trust. | +| 4 | `contract.py`: new assumption `read.unavailable_not_absent`, fencing **both** directions. | A regression now breaks loudly under `doctor`. | +| 5 | CLI/web follow-on: `cli.cmd_instances` prints the new status verbatim (no second copy of the rule); `webapp._dashboard_row` paints an unreachable project amber **Unavailable** rather than crimson **Broken**; `webbrowse` says "unknown, not broken". | `instances` had no vocabulary between `ok` and `ERROR`. | + +**`doctor` now measures 35/35** — read off `doctor`, not computed (33+2 arithmetic would +have said 36 last time and been wrong). `AGENTS.md` updated in all three places that +carried the old count. + +--- + +## 3. Deliverables + +### 3.1 The failure is REMOVED, and it was measured — **DONE** + +rpz's own harness, run verbatim (`git show lane/rpz-dolt-error-misreport:probes/rpz-dolt-error-misreport/repro.sh`, +sha256 `77635c7a…`; copied to the capture root and run there, unmodified). **Two runs**; +raw counts pasted exactly as printed: + +``` +RUN A — stock installed CLI (0.1.0, unfixed) on PATH + 0. empty cwd : real 0m0.056s + /tmp (66292 entries): real 0m8.685s + 2. raw dolt, cwd = churning dir (== today's code path) failures: 7 / 25 + 3. FIX A -- identical load, cwd pinned to a stable dir failures: 0 / 25 + 4. FIX B -- cwd left churning, --data-dir pinned failures: 0 / 25 + +RUN B — LANE build (fix applied) shimmed first on PATH + 0. empty cwd : real 0m0.036s + /tmp (66292 entries): real 0m0.873s + 2. raw dolt, cwd = churning dir (== today's code path) failures: 12 / 25 + 3. FIX A -- identical load, cwd pinned to a stable dir failures: 0 / 25 + 4. FIX B -- cwd left churning, --data-dir pinned failures: 0 / 25 +``` + +So: **25/25 succeed with the scan directory pinned, by either remedy, in both runs**, +against 7/25 and 12/25 failures unpinned under the same load in the same run. + +**Deviation from the item's wording, stated plainly:** the item predicted "failed 6/25". +Measured today it was **7/25 and 12/25** — the same defect, a *worse* failure rate than +filed (this host's `/tmp` has grown from rpz's 52,281 entries to 66,292). The pinned +counts are the ones the deliverable turns on, and they are 0/25 both times. + +Stage 5 is the end-to-end half, on `model_performance-8zv` — an item that exists and that +this session **holds** — read-only, mutating nothing: + +``` +RUN A (stock CLI): 7 of 8 attempts -> "item 'model_performance-8zv' not found in project 'model_performance'" + 1 of 8 attempts -> the real record +RUN B (lane build): 8 of 8 attempts -> the real record +``` + +Run B's stage 2 shows a *harsher* load (12/25 raw failures) than run A's, so the fixed +CLI was not merely luckier. + +Raw captures: `.amplifier/evaluation/treatment-validation/2026-09-02-model_performance-8zv/` +(`harness-run-A-stock.txt`, `harness-run-B-fixed.txt`, `repro.sh`, `shim-bin/`). + +### 3.2 `claim --id ` past the retry budget — **DONE** + +Names the transient condition; does **not** say "item not found". +Tests: `tests/cli/test_cli_unavailable_not_absent.py::test_claim_id_on_an_existing_item_does_not_say_item_not_found_when_unreachable` +(real CLI subprocess, real `dolt`, real closed port — genuinely past +`_run_dolt_sql_bounded`'s budget), and +`tests/unit/test_unavailable_not_absent.py::test_claim_item_under_transport_failure_does_not_say_item_not_found`. + +### 3.3 `list --id ` past the retry budget — **DONE** + +Still carries the underlying cause; `get_readonly` no longer discards it. +Tests: `tests/cli/…::test_list_id_on_an_existing_item_does_not_deny_it_when_the_db_is_unreachable`, +`tests/unit/…::test_get_readonly_under_transport_failure_does_not_claim_absence`, +`…::test_get_readonly_transport_failure_is_a_distinct_TYPE`. + +### 3.4 `instances` — **DONE** + +Retries first, then reports a status distinct from **both** `ok` and `ERROR` naming the +transient cause, with counts left `None` rather than fabricated. +Tests: `tests/cli/…::test_instances_reports_UNAVAILABLE_not_ERROR_when_the_db_is_unreachable`, +`tests/unit/…::test_project_summary_under_transport_failure_is_UNAVAILABLE_not_ERROR`, +`…::test_project_summary_unavailable_is_distinct_from_every_other_status`. + +### 3.5 The no-blurring guardrail — **DONE** (treated as load-bearing as the rest) + +Genuine absence on a **healthy** database reports absence exactly as it does today, on +all three verbs, with no "maybe transient" hedge anywhere: + +- `tests/cli/…::test_list_id_on_a_genuinely_absent_item_is_UNCHANGED` +- `tests/cli/…::test_claim_id_on_a_genuinely_absent_item_is_UNCHANGED` +- `tests/cli/…::test_instances_on_a_healthy_server_is_UNCHANGED` +- `tests/unit/…::test_get_readonly_genuine_absence_is_UNCHANGED` (asserts the message + **byte for byte**), `…::test_get_readonly_wrong_project_prefix_is_UNCHANGED`, + `…::test_claim_item_genuine_absence_is_UNCHANGED`, + `…::test_project_summary_real_read_failure_still_reports_ERROR` (a *reachable* database + that cannot be read is still an honest `ERROR`, not softened), + `…::test_project_summary_healthy_is_UNCHANGED` +- `tests/unit/test_dolt_scan_dir.py::test_a_real_domain_failure_is_not_classified_transient` + and `…::test_direct_sql_does_not_retry_a_real_domain_failure` — the classifier itself. + +Note, deliberately: **the three CLI-tier guardrail tests pass on the PARENT commit as well +as on the fix.** That is the point of them — they are the fence that says nothing moved. + +### 3.6 `doctor` assumption — **DONE** + +`contract.py::check_unavailable_not_absent`, id `read.unavailable_not_absent`, registered +in `CHECKS`. Fences both directions in one check. The transport failure is *injected* at +`_dolt_sql`/`_dolt_sql_json` (restored in a `finally`) rather than provoked by churning a +real directory — this check runs inside `doctor` on operators' machines, and injecting also +places the failure past the retry budget, which is the condition the deliverable names. + +`doctor` on this tree: **`All 35 assumptions hold.`** + +### 3.7 Fail-before evidence — **DONE** + +`docs/lanes/8zv-dolt-scan-dir/evidence/fail-before.txt` — the three new test files run +against the parent commit's source (`src/` + `AGENTS.md` reverted to +`2468a6946ee7e04e82ad9d563af86d48a5d66355`, the new tests kept): + +``` +unit : 18 failed, 2 passed +cli : 3 failed, 3 passed +``` + +The 3 CLI passes and 2 unit passes are exactly the unchanged-behaviour guardrails +(§3.5) — they must pass before *and* after. Every test describing the defect fails there. + +--- + +## 4. Test tiers — all four, by name, plus the modules tier + +| Tier | Command | Result | +|---|---|---| +| unit | `pytest tests/unit` (`make test-unit`) | **810 passed** | +| integration | `pytest -m integration tests/integration` (`make test-integration`) | **322 passed, 3 skipped** (14:00) | +| cli | `pytest -m cli tests/cli` (`make test-cli`) | **86 passed, 1 failed** — the pre-existing `test_doctor_quick_succeeds_against_the_real_installed_bd` | +| ledger | `pytest ledger/checks` (`make test-ledger`) | **24 passed** | +| modules | `pytest modules/tool-work-tracker/tests` (not in `testpaths`) | **100 passed, 1 failed** — the pre-existing `test_explicit_resolve_refusal_after_reap_…` | +| lint/types | `make check` (`ruff check`, `ruff format --check`, `pyright src tests`) | clean, `0 errors` | +| doctor | `amplifier_work_tracker.cli doctor` | **All 35 assumptions hold** | + +Both failures are the two named in the item as PRE-EXISTING and NOT this lane's +(`model_performance-jyg`, `model_performance-c0e`). **`jyg` was checked rather than +assumed**: its failure line is `[FAIL] sweeps.alive — no heartbeat ever recorded…`, an +environment/service condition in the isolated test workspace, and the *new* +`read.unavailable_not_absent` check reports `[PASS]` inside that very run. The third named +item (`tests/unit/test_supervisor_web.py`, a port-binding flake) did not fire. + +The modules tier needs a separate install the repo's own dev extras do not perform — +`uv pip install -e modules/tool-work-tracker` (plus `amplifier-core` and `pytest-asyncio` +per the item's KNOWN note), or the whole tier fails at **collection** with +`ModuleNotFoundError: No module named 'amplifier_module_tool_work_tracker'` and looks like +a real breakage. Recorded here because it cost real time and the item's KNOWN note names +only two of the three missing packages. + +Raw tier output: `docs/lanes/8zv-dolt-scan-dir/evidence/tier-*.txt`. + +--- + +## 5. Decisions made without asking (per the no-waiting-on-humans rule) + +1. **Both remedies, not one.** The item ranked `--data-dir` and `cwd=` as alternatives. + Both are applied: they are independent, both measured 0/25, and the combination + survives a future refactor that drops either. Cost: ~3 lines. +2. **`--data-dir` lives in `_dolt_conn_args`, not on the two hot helpers.** That covers + the other four `dolt` call sites (`DROP DATABASE`, `SHOW CREATE`, the copy script) + by construction. "Remember to pass it at each call site" is exactly the discipline + that failed here in the first place — the same argument `_bd_env`'s own docstring + makes about telemetry. +3. **Genuine-absence wording left byte-identical.** The item said `get_readonly` "must + stop discarding the cause". It does — for the transient case, which is the case that + was lying. Appending bd's cause to a *real* "not found" would have changed the very + message the no-blurring deliverable requires to be unchanged, so the cause is carried + by the exception **type** and its message instead. `from e` already preserved the + chain; the message did not, and now does, where it matters. +4. **Retry budget reused, not reinvented.** `_MAX_CONNECTION_RETRIES` / the existing + backoff cap, so there is one answer to "how long do we tolerate a blip", not two. +5. **Scan directory under `~/.cache`, not the workspace root or `~/.beads/…/dolt`.** The + workspace root grows a directory per project; the dolt data directory churns as dolt + writes. Both would reintroduce the cost the pin removes. Falls back to one + process-lifetime temp directory if the cache directory cannot be created — degrading to + today's behaviour beats breaking every SQL read. +6. **Stage 5 run through a PATH shim, not by installing over the user's tool.** Installing + the lane build as `amplifier-work-tracker` would have changed behaviour for live + sessions on this host. The shim is a 2-line script first on `PATH`, and the capture + records which binary each run used. + +## 6. What remains open + +- The `--data-dir` flag position is verified against `dolt 2.2.3` only (the version this + repo pins via `check_version`). An older dolt without the global flag would fail loudly + at the first SQL call, not silently — but it is untested. +- `_dolt_scan_dir()` is memoised per process. A long-lived process whose cache directory + is deleted underneath it re-creates the directory on the next call (`is_dir()` guard), + but this is asserted by construction, not by a test that deletes it mid-run. +- The CLI/web `UNAVAILABLE` rendering is covered by the adapter/CLI tests and by + `webapp._dashboard_row`'s branch; there is no snapshot test of the rendered HTML row. diff --git a/docs/lanes/8zv-dolt-scan-dir/evidence/fail-before.txt b/docs/lanes/8zv-dolt-scan-dir/evidence/fail-before.txt new file mode 100644 index 0000000..0b9aafd --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/evidence/fail-before.txt @@ -0,0 +1,87 @@ +=== FAIL-BEFORE: new tests run against the PARENT commit's source (fix reverted) === +parent: 2468a6946ee7e04e82ad9d563af86d48a5d66355 +src/ + AGENTS.md reverted to parent; the three NEW test files kept. + +--- tests/unit/test_dolt_scan_dir.py + tests/unit/test_unavailable_not_absent.py +monkeypatch = <_pytest.monkeypatch.MonkeyPatch object at 0xe6d3198b3b30> + + def test_project_summary_real_read_failure_still_reports_ERROR(probe_workspace, monkeypatch): + """No-blurring guardrail, summary side: a database that IS reachable but + cannot be read is still an honest `ERROR`, not softened to 'unknown'.""" + + def domain_failure(*_a, **_k): + return subprocess.CompletedProcess( + ["dolt"], 1, "", "Error 1049: Unknown database 'probeproj'" + ) + + monkeypatch.setattr(A, "_dolt_sql", domain_failure) + monkeypatch.setattr(A, "_dolt_sql_json", domain_failure) + s = A.project_summary(probe_workspace, PROJECT) + assert s.status.startswith("ERROR:") +> assert not A.is_unavailable_status(s.status) + ^^^^^^^^^^^^^^^^^^^^^^^ +E AttributeError: module 'amplifier_work_tracker.adapter' has no attribute 'is_unavailable_status' + +tests/unit/test_unavailable_not_absent.py:193: AttributeError +=========================== short test summary info ============================ +FAILED tests/unit/test_dolt_scan_dir.py::test_scan_dir_exists_and_is_reused +FAILED tests/unit/test_dolt_scan_dir.py::test_scan_dir_is_not_the_process_cwd +FAILED tests/unit/test_dolt_scan_dir.py::test_conn_args_pin_the_data_dir - As... +FAILED tests/unit/test_dolt_scan_dir.py::test_dolt_sql_pins_cwd - assert None... +FAILED tests/unit/test_dolt_scan_dir.py::test_dolt_sql_json_pins_cwd - TypeEr... +FAILED tests/unit/test_dolt_scan_dir.py::test_lstat_race_is_classified_transient +FAILED tests/unit/test_dolt_scan_dir.py::test_a_real_domain_failure_is_not_classified_transient +FAILED tests/unit/test_dolt_scan_dir.py::test_direct_sql_retries_a_transient_failure_and_then_succeeds +FAILED tests/unit/test_dolt_scan_dir.py::test_direct_sql_retry_is_BOUNDED_and_surfaces_the_failure +FAILED tests/unit/test_unavailable_not_absent.py::test_get_readonly_under_transport_failure_does_not_claim_absence +FAILED tests/unit/test_unavailable_not_absent.py::test_get_readonly_transport_failure_is_a_distinct_TYPE +FAILED tests/unit/test_unavailable_not_absent.py::test_get_readonly_genuine_absence_is_UNCHANGED +FAILED tests/unit/test_unavailable_not_absent.py::test_get_readonly_wrong_project_prefix_is_UNCHANGED +FAILED tests/unit/test_unavailable_not_absent.py::test_claim_item_under_transport_failure_does_not_say_item_not_found +FAILED tests/unit/test_unavailable_not_absent.py::test_claim_item_genuine_absence_is_UNCHANGED +FAILED tests/unit/test_unavailable_not_absent.py::test_project_summary_under_transport_failure_is_UNAVAILABLE_not_ERROR +FAILED tests/unit/test_unavailable_not_absent.py::test_project_summary_unavailable_is_distinct_from_every_other_status +FAILED tests/unit/test_unavailable_not_absent.py::test_project_summary_real_read_failure_still_reports_ERROR +18 failed, 2 passed in 0.33s + +--- tests/cli/test_cli_unavailable_not_absent.py +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=104 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=105 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=106 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=106 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=107 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=108 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=107 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=108 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=109 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=109 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=110 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=111 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=110 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=111 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=112 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=112 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=113 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=113 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=114 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=114 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=115 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=115 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=116 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=116 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=117 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=118 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=117 +time="2026-09-02T22:40:21-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=119 +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=119 +time="2026-09-02T22:40:21-07:00" level=warning msg="error running query" connectTime="2026-09-02 22:40:21.639642618 -0700 PDT m=+18.240557502" connectionDb=proj906a90aeaaec connectionID=118 error="backup 'backup_export' not found" queryTime="2026-09-02 22:40:21.75500604 -0700 PDT m=+18.355920908" +time="2026-09-02T22:40:21-07:00" level=info msg=ConnectionClosed connectionID=118 +--------------------------- Captured stderr teardown --------------------------- +time="2026-09-02T22:40:22-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=120 +time="2026-09-02T22:40:22-07:00" level=info msg="stats stopped: context canceled" +time="2026-09-02T22:40:22-07:00" level=info msg=ConnectionClosed connectionID=120 +=========================== short test summary info ============================ +FAILED tests/cli/test_cli_unavailable_not_absent.py::test_list_id_on_an_existing_item_does_not_deny_it_when_the_db_is_unreachable +FAILED tests/cli/test_cli_unavailable_not_absent.py::test_claim_id_on_an_existing_item_does_not_say_item_not_found_when_unreachable +FAILED tests/cli/test_cli_unavailable_not_absent.py::test_instances_reports_UNAVAILABLE_not_ERROR_when_the_db_is_unreachable +3 failed, 3 passed in 22.41s diff --git a/docs/lanes/8zv-dolt-scan-dir/evidence/tier-cli.txt b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-cli.txt new file mode 100644 index 0000000..7356a33 --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-cli.txt @@ -0,0 +1,31 @@ +### make test-cli (-m cli tests/cli) +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2127 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2127 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2128 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2129 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2128 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2129 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2130 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2130 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2131 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2131 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2132 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2132 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2133 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2133 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2134 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2134 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2135 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2135 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2136 +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2136 +time="2026-09-02T22:45:36-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2137 +time="2026-09-02T22:45:36-07:00" level=warning msg="error running query" connectTime="2026-09-02 22:45:36.980678474 -0700 PDT m=+234.516177695" connectionID=2137 error="database not found: contract178841429598rm" queryTime="2026-09-02 22:45:36.984410787 -0700 PDT m=+234.519910008" +time="2026-09-02T22:45:36-07:00" level=info msg=ConnectionClosed connectionID=2137 +time="2026-09-02T22:45:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2138 +time="2026-09-02T22:45:37-07:00" level=info msg=ConnectionClosed connectionID=2138 +time="2026-09-02T22:45:37-07:00" level=info msg=NewConnection DisableClientMultiStatements=false connectionID=2139 +time="2026-09-02T22:45:37-07:00" level=info msg=ConnectionClosed connectionID=2139 +=========================== short test summary info ============================ +FAILED tests/cli/test_cli_surface.py::test_doctor_quick_succeeds_against_the_real_installed_bd +1 failed, 86 passed in 284.46s (0:04:44) diff --git a/docs/lanes/8zv-dolt-scan-dir/evidence/tier-integration.txt b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-integration.txt new file mode 100644 index 0000000..d36d4d7 --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-integration.txt @@ -0,0 +1,21 @@ +### make test-integration (-m integration tests/integration) +........................................................................ [ 22%] +........................................................................ [ 44%] +........................................................................ [ 66%] +..........................s............................................. [ 88%] +......ss............................. [100%] +=============================== warnings summary =============================== +tests/integration/test_observatory_web.py:20 + /home/bkrabach/dev/hw-model-performance/lanes/8zv-dolt-scan-dir/amplifier-work-tracker/tests/integration/test_observatory_web.py:20: StarletteDeprecationWarning: Using `httpx` with `starlette.testclient` is deprecated; install `httpx2` instead. + from starlette.testclient import TestClient # noqa: E402 + +.venv/lib/python3.12/site-packages/starlette/testclient.py:53 + /home/bkrabach/dev/hw-model-performance/lanes/8zv-dolt-scan-dir/amplifier-work-tracker/.venv/lib/python3.12/site-packages/starlette/testclient.py:53: DeprecationWarning: The anyio.abc.BlockingPortal alias is deprecated, use anyio.from_thread.BlockingPortal instead. + _PortalFactoryType = Callable[[], AbstractContextManager[anyio.abc.BlockingPortal]] + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +=========================== short test summary info ============================ +SKIPPED [1] tests/integration/test_web.py:699: bd set no `owner` on this item -- happens where the environment has no git identity (e.g. a bare CI container with no `git config user.email`). `owner` is an environment-provided value, not a code invariant; the environment-independent humanization guarantees are covered by test_humanize_identity_* in tests/unit. +SKIPPED [1] tests/integration/test_web_pwa.py:234: Pillow not installed (dev/build-only tool) +SKIPPED [1] tests/integration/test_web_pwa.py:249: Pillow not installed (dev/build-only tool) +322 passed, 3 skipped, 2 warnings in 840.41s (0:14:00) diff --git a/docs/lanes/8zv-dolt-scan-dir/evidence/tier-ledger.txt b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-ledger.txt new file mode 100644 index 0000000..80e3278 --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-ledger.txt @@ -0,0 +1,3 @@ +### make test-ledger (ledger/checks) +........................ [100%] +24 passed in 0.09s diff --git a/docs/lanes/8zv-dolt-scan-dir/evidence/tier-modules.txt b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-modules.txt new file mode 100644 index 0000000..6c7dd52 --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-modules.txt @@ -0,0 +1,26 @@ +### modules/tool-work-tracker/tests (NOT in root testpaths; separate package) +time="2026-09-02T23:02:43-07:00" level=warning msg="error running query" connectTime="2026-09-02 23:02:43.955050565 -0700 PDT m=+12.575233939" connectionDb=reapproj58d3725f1c connectionID=148 error="table not found: schema_migrations" queryTime="2026-09-02 23:02:43.956241985 -0700 PDT m=+12.576425343" +time="2026-09-02T23:02:43-07:00" level=warning msg="error running query" connectTime="2026-09-02 23:02:43.956689615 -0700 PDT m=+12.576873005" connectionDb=reapproj58d3725f1c connectionID=149 error="table not found: schema_migrations" queryTime="2026-09-02 23:02:43.957590395 -0700 PDT m=+12.577773753" +time="2026-09-02T23:02:43-07:00" level=warning msg="error running query" connectTime="2026-09-02 23:02:43.956689615 -0700 PDT m=+12.576873005" connectionDb=reapproj58d3725f1c connectionID=149 error="table not found: schema_migrations" queryTime="2026-09-02 23:02:43.959183653 -0700 PDT m=+12.579367027" +time="2026-09-02T23:02:43-07:00" level=warning msg="error running query" connectTime="2026-09-02 23:02:43.956689615 -0700 PDT m=+12.576873005" connectionDb=reapproj58d3725f1c connectionID=149 error="table not found: schema_migrations" queryTime="2026-09-02 23:02:43.960855982 -0700 PDT m=+12.581039340" +time="2026-09-02T23:02:45-07:00" level=warning msg="error running query" connectTime="2026-09-02 23:02:43.956689615 -0700 PDT m=+12.576873005" connectionDb=reapproj58d3725f1c connectionID=149 error="table not found: ignored_schema_migrations" queryTime="2026-09-02 23:02:45.52065395 -0700 PDT m=+14.140837308" +----------------------------- Captured stdout call ----------------------------- + +----------------------------- Captured stderr call ----------------------------- +time="2026-09-02T23:02:46-07:00" level=warning msg="error running query" connectTime="2026-09-02 23:02:46.842046777 -0700 PDT m=+15.462230151" connectionDb=reapproj58d3725f1c connectionID=165 error="backup 'backup_export' not found" queryTime="2026-09-02 23:02:46.930393999 -0700 PDT m=+15.550577341" +------------------------------ Captured log call ------------------------------- +ERROR amplifier_work_tracker.webpush:webpush.py:435 ntfy alarm unexpected failure for reclaimed reapproj58d3725f1c-00q: asyncio.run() cannot be called from a running event loop +--------------------------- Captured stderr teardown --------------------------- +=============================== warnings summary =============================== +modules/tool-work-tracker/tests/test_reap_recovery.py::test_explicit_resolve_refusal_after_reap_clears_held_and_allows_new_claim +modules/tool-work-tracker/tests/test_reap_recovery.py::test_explicit_declare_refusal_after_reap_clears_held_and_allows_new_claim +modules/tool-work-tracker/tests/test_reap_recovery.py::test_background_renew_loop_detects_reap_and_clears_held_state + /home/bkrabach/dev/hw-model-performance/lanes/8zv-dolt-scan-dir/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, 100 passed, 3 warnings in 313.32s (0:05:13) diff --git a/docs/lanes/8zv-dolt-scan-dir/evidence/tier-unit.txt b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-unit.txt new file mode 100644 index 0000000..2c0a480 --- /dev/null +++ b/docs/lanes/8zv-dolt-scan-dir/evidence/tier-unit.txt @@ -0,0 +1,24 @@ +### make test-unit (tests/unit) +........................................................................ [ 8%] +........................................................................ [ 17%] +........................................................................ [ 26%] +........................................................................ [ 35%] +........................................................................ [ 44%] +........................................................................ [ 53%] +........................................................................ [ 62%] +........................................................................ [ 71%] +........................................................................ [ 80%] +........................................................................ [ 88%] +........................................................................ [ 97%] +.................. [100%] +=============================== warnings summary =============================== +tests/unit/test_webapp_setup.py:29 + /home/bkrabach/dev/hw-model-performance/lanes/8zv-dolt-scan-dir/amplifier-work-tracker/tests/unit/test_webapp_setup.py:29: StarletteDeprecationWarning: Using `httpx` with `starlette.testclient` is deprecated; install `httpx2` instead. + from starlette.testclient import TestClient # noqa: E402 + +.venv/lib/python3.12/site-packages/starlette/testclient.py:53 + /home/bkrabach/dev/hw-model-performance/lanes/8zv-dolt-scan-dir/amplifier-work-tracker/.venv/lib/python3.12/site-packages/starlette/testclient.py:53: DeprecationWarning: The anyio.abc.BlockingPortal alias is deprecated, use anyio.from_thread.BlockingPortal instead. + _PortalFactoryType = Callable[[], AbstractContextManager[anyio.abc.BlockingPortal]] + +-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html +810 passed, 2 warnings in 42.62s diff --git a/src/amplifier_work_tracker/adapter.py b/src/amplifier_work_tracker/adapter.py index 8014794..8e0514f 100644 --- a/src/amplifier_work_tracker/adapter.py +++ b/src/amplifier_work_tracker/adapter.py @@ -24,6 +24,7 @@ import shutil import signal import subprocess +import tempfile import time import uuid from collections.abc import Callable @@ -186,6 +187,18 @@ def _map_status(raw: str | None) -> str: "invalid connection", "i/o timeout", "server has gone away", + # The dolt CLI enumerates its data directory and `lstat()`s every entry + # on EVERY invocation -- including pure client mode (`--host/--port` + # against an already-running shared server, where no local database is + # even relevant). If an entry vanishes between `readdir` and `lstat`, + # dolt aborts the whole query with this message. Measured (lane + # model_performance-rpz, `probes/rpz-dolt-error-misreport/repro.sh`): + # 6 failures in 25 attempts from a churning 40k-entry directory, 0 in + # 25 from a pinned one. `_dolt_scan_dir` now REMOVES the cause; this + # entry is the belt to that braces -- it is a filesystem-race + # signature that can never appear in a legitimate bd domain result, so + # riding through it can never turn a real failure into a false success. + "failed to load database names", ) # Connection retries are bounded MUCH tighter than serialization retries: a # transient blip clears in well under a second, whereas a genuinely-down @@ -418,10 +431,92 @@ def _bd_init_server_args() -> list[str]: return ["--shared-server"] +_DOLT_SCAN_DIR: Path | None = None + + +def _dolt_scan_dir() -> Path: + """A stable, empty, WE-OWN-IT directory for the `dolt` CLI to scan. + + THE fix for a measured intermittent failure, not a tidiness nicety. + + Mechanism (measured, lane `model_performance-rpz`, harness + `probes/rpz-dolt-error-misreport/repro.sh`): the `dolt` CLI enumerates + the entries of its data directory -- which, with no `--data-dir` given, + is its INHERITED CURRENT WORKING DIRECTORY -- and `lstat()`s each one on + EVERY invocation. This happens even in the pure client mode every + `_dolt_*` helper here uses (`--host/--port` against the already-running + shared server), where no local database is relevant at all. Two + consequences, both measured on this host with the SAME query against the + SAME server: + + - COST, proportional to entry count: 0.031s from a 2-entry directory, + 0.805s from `/tmp` (52,281 entries) -- 26x, paid on every one of the + 19 direct-SQL call sites in this module. + - FAILURE: if any entry vanishes between `readdir` and `lstat`, dolt + aborts the entire query with `failed to load database names: lstat + : no such file or directory`. Under a churning 40,000-entry + directory: 6 failures in 25 attempts. + + `_dolt_sql`/`_dolt_sql_json` passed no `cwd=` to `_run_bounded`, so the + directory dolt scanned was whatever directory the CALLING AGENT happened + to be in -- `/tmp` in both field reports. That is the whole defect: a + read failure whose probability is set by an unrelated process's litter. + + Both remedies were measured at 0/25 under identical load, and both are + applied here (they are independent, and the second survives a future + refactor that drops the first): `cwd=` this directory on the two hot + helpers, and `--data-dir` this directory on every `dolt` invocation via + `_dolt_conn_args`. + + Location: honours `AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR` (tests, and an + operator with an opinion), else `$XDG_CACHE_HOME`/`~/.cache` under this + tool's own name. Deliberately NOT the workspace root (it holds a + directory per project, and grows), NOT `~/.beads/shared-server/dolt` + (that is the live data directory, which churns as dolt writes), and NOT + a per-call temp directory (a fresh `mkdtemp` per query would reintroduce + a per-call cost and litter). Memoised: one `mkdir` per process, not one + per query. + + Never raises. A home directory that cannot be written (read-only, + unusual container) falls back to one process-lifetime temp directory + rather than breaking every SQL read in the module -- degrading to + today's behaviour is strictly better than a hard failure, and a temp + directory of our own is still quiet and stable. + """ + global _DOLT_SCAN_DIR + override = os.environ.get("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR") + if override: + # Not memoised: an override is what tests move around, and a cached + # first value would silently outlive the monkeypatch that set it. + d = Path(override) + try: + d.mkdir(parents=True, exist_ok=True) + return d + except OSError: + pass + if _DOLT_SCAN_DIR is not None and _DOLT_SCAN_DIR.is_dir(): + return _DOLT_SCAN_DIR + cache_root = os.environ.get("XDG_CACHE_HOME") or str(Path.home() / ".cache") + candidate = Path(cache_root) / "amplifier-work-tracker" / "dolt-scan" + try: + candidate.mkdir(parents=True, exist_ok=True) + except OSError: + candidate = Path(tempfile.mkdtemp(prefix="awt-dolt-scan-")) + _DOLT_SCAN_DIR = candidate + return candidate + + def _dolt_conn_args() -> list[str]: """Global `dolt` CLI flags to reach the shared server directly over SQL, bypassing any per-project `.beads` directory entirely. + `--data-dir` is here rather than only on the two hot helpers so EVERY + `dolt` invocation in this module (the `sql -q` reads, `DROP DATABASE`, + `SHOW CREATE`, the copy script) gets the pinned scan directory by + construction -- see `_dolt_scan_dir` for the measured failure this + removes, and why "remember to pass it at each call site" is exactly the + discipline that failed here in the first place. + This is the ONLY way to make a project's shared-server database actually disappear: `bd` has no command for it. Verified empirically against the installed bd 1.1.2 binary before writing this -- `bd delete` removes @@ -436,13 +531,59 @@ def _dolt_conn_args() -> list[str]: """ from . import supervisor as SV - return ["--host", SV.DEFAULT_DOLT_HOST, "--port", str(SV.DEFAULT_DOLT_PORT), "--no-tls"] + return [ + "--data-dir", + str(_dolt_scan_dir()), # pinned scan directory -- see `_dolt_scan_dir` + "--host", + SV.DEFAULT_DOLT_HOST, + "--port", + str(SV.DEFAULT_DOLT_PORT), + "--no-tls", + ] + + +def _run_dolt_sql_bounded(args: list[str]) -> subprocess.CompletedProcess: + """Run one direct-SQL `dolt` invocation, riding through a transient + CONNECTION-transport blip the same bounded way `Beads._run` already does + for `bd` subprocesses -- and, unlike every previous version of this code + path, with the scan directory pinned (`cwd=_dolt_scan_dir()`). + + Why this exists at all: the retry classification lived ONLY in + `Beads._run`, which wraps `bd`. The direct dolt-SQL path -- 19 call + sites in this module, including the single-item read behind + `get`/`get_readonly`/`claim_item` and the project read behind + `project_summary` -- had NO retry of any kind. Adding a transient + signature to `_RETRYABLE_CONNECTION` alone would land in a table this + code path never consulted. Putting the loop HERE, rather than at each + call site, is what makes all 19 benefit by construction. + + Same shape and the same budget as `Beads._run`'s connection leg + (`_MAX_CONNECTION_RETRIES`, short capped backoff, few-second ceiling), + for the same reason: a transient blip clears in well under a second, + whereas a genuinely-unreachable server must fail FAST rather than + hammer. On a spent budget this RETURNS the failed process unchanged -- + never a new exception type -- so every existing `p.returncode != 0` + call site behaves exactly as before, just a couple of seconds later. + + `cwd=` and `--data-dir` (via `_dolt_conn_args`) are deliberately both + applied: they are independent remedies, each measured at 0/25 failures + under the load that produced 6/25 unpinned. + """ + attempt = 0 + while True: + p = _run_bounded(args, env=_bd_env(), cwd=_dolt_scan_dir()) + if p.returncode == 0 or attempt >= _MAX_CONNECTION_RETRIES: + return p + if not _connection_retryable((p.stdout or "") + (p.stderr or "")): + return p + backoff = min(_CONNECTION_RETRY_BACKOFF_CAP, 0.1 * (2**attempt)) + time.sleep(backoff * (0.5 + os.urandom(1)[0] / 255)) + attempt += 1 def _dolt_sql(query: str) -> subprocess.CompletedProcess: - return _run_bounded( + return _run_dolt_sql_bounded( ["dolt", *_dolt_conn_args(), "sql", "-q", query, "-r", "csv"], - env=_bd_env(), # non-interactive: see `_bd_env`'s docstring ) @@ -476,9 +617,8 @@ def _dolt_sql_json(query: str) -> subprocess.CompletedProcess: `_dolt_show_create`'s own use of the same format) carries each field as a single JSON string with no such ambiguity. """ - return _run_bounded( + return _run_dolt_sql_bounded( ["dolt", *_dolt_conn_args(), "sql", "-q", query, "-r", "json"], - env=_bd_env(), # non-interactive: see `_bd_env`'s docstring ) @@ -688,15 +828,17 @@ def _summary_items_via_sql(db: str) -> list[Item]: cols = ", ".join(f"`{c}`" for c in _SUMMARY_ITEM_COLUMNS) p = _dolt_sql(f"SELECT {cols} FROM `{db}`.`issues`") if p.returncode != 0: - raise BeadsError( + raise _sql_failure( f"could not read items of database {db!r} over SQL: " - f"{_clean_bd_error(p.stderr or p.stdout)}" + f"{_clean_bd_error(p.stderr or p.stdout)}", + p, ) lp = _dolt_sql(f"SELECT `issue_id`, `label` FROM `{db}`.`labels`") if lp.returncode != 0: - raise BeadsError( + raise _sql_failure( f"could not read labels of database {db!r} over SQL: " - f"{_clean_bd_error(lp.stderr or lp.stdout)}" + f"{_clean_bd_error(lp.stderr or lp.stdout)}", + lp, ) tags_by_id: dict[str, list[str]] = {} for row in csv.reader((lp.stdout or "").splitlines()[1:]): # drop CSV header @@ -839,9 +981,10 @@ def _list_rows_via_sql(db: str, *, where_sql: str | None, limit: int) -> list[It query += f" LIMIT {int(limit)}" p = _dolt_sql_json(query) if p.returncode != 0: - raise BeadsError( + raise _sql_failure( f"could not read items of database {db!r} over SQL: " - f"{_clean_bd_error(p.stderr or p.stdout)}" + f"{_clean_bd_error(p.stderr or p.stdout)}", + p, ) try: rows = json.loads(p.stdout or "{}").get("rows", []) @@ -850,9 +993,10 @@ def _list_rows_via_sql(db: str, *, where_sql: str | None, limit: int) -> list[It lp = _dolt_sql(f"SELECT `issue_id`, `label` FROM `{db}`.`labels`") if lp.returncode != 0: - raise BeadsError( + raise _sql_failure( f"could not read labels of database {db!r} over SQL: " - f"{_clean_bd_error(lp.stderr or lp.stdout)}" + f"{_clean_bd_error(lp.stderr or lp.stdout)}", + lp, ) tags_by_id: dict[str, list[str]] = {} for row in csv.reader((lp.stdout or "").splitlines()[1:]): # drop CSV header @@ -1423,6 +1567,39 @@ class BeadsError(Exception): """A Beads operation failed. Never caught to degrade -- only to report.""" +class BeadsUnavailableError(BeadsError): + """The INFRASTRUCTURE could not be read -- so the answer is UNKNOWN, not + negative. Distinct from every other `BeadsError`, which reports a real + domain outcome bd actually computed. + + This exists because the two were indistinguishable, and the system said + the wrong one out loud. Measured (lane `model_performance-rpz`): under a + transient dolt read failure, `claim --id` on an item that EXISTS + reported "item not found" in 9 of 12 attempts; `list --id` on an item + the calling session HELD reported a bare "item 'X' not found in project + 'Y'" -- cause discarded entirely -- in 2 of 8; `instances` printed a + healthy project as `ERROR` with null counts in 5 of 10, interleaved with + correct `ok` rows seconds either side. + + A SUBSTRING is not the fix. Callers must not have to grep an error + message to learn whether absence was observed or merely assumed, so the + distinction is carried in the TYPE: `except BeadsUnavailableError` comes + before `except BeadsError` at each of the three sites that used to + flatten (`Beads.claim_item`, `Beads.get_readonly`, `project_summary`), + and the transient case is re-raised untouched, cause intact. + + What this deliberately does NOT do: widen. A genuinely absent item on a + healthy database still reports plain absence, in exactly the same words + as before -- see the `read.unavailable_not_absent` contract check, which + fences BOTH directions. Replacing "it does not exist" with "it might not + exist" everywhere would be a second lie, not a fix. + + Raised only where a `dolt`/`bd` read failed at the TRANSPORT layer -- + classified by `_connection_retryable`, the same conservative predicate + that decides what is safe to retry, applied in `_sql_failure`. + """ + + class AssumptionViolated(BeadsError): """The installed Beads no longer behaves the way we depend on.""" @@ -1816,9 +1993,10 @@ def _forward_active_blockers_via_sql(db: str, item_id: str) -> list[dict]: f"WHERE `dep`.`issue_id` = '{_sql_literal(item_id)}'" ) if p.returncode != 0: - raise BeadsError( + raise _sql_failure( f"could not read dependencies of {item_id!r} over SQL: " - f"{_clean_bd_error(p.stderr or p.stdout)}" + f"{_clean_bd_error(p.stderr or p.stdout)}", + p, ) try: rows = json.loads(p.stdout or "{}").get("rows", []) @@ -1882,9 +2060,10 @@ def _forward_dependency_links_via_sql(db: str, item_id: str) -> list[dict]: f"WHERE `dep`.`issue_id` = '{_sql_literal(item_id)}'" ) if p.returncode != 0: - raise BeadsError( + raise _sql_failure( f"could not read forward dependency links of {item_id!r} over SQL: " - f"{_clean_bd_error(p.stderr or p.stdout)}" + f"{_clean_bd_error(p.stderr or p.stdout)}", + p, ) try: rows = json.loads(p.stdout or "{}").get("rows", []) @@ -1913,6 +2092,27 @@ def _forward_dependency_links_via_sql(db: str, item_id: str) -> list[dict]: return links +def _sql_failure(message: str, p: subprocess.CompletedProcess) -> BeadsError: + """Build the right exception for a failed direct-SQL `dolt` read. + + ONE classifier, so the six SQL read sites cannot drift into six + different opinions about what a transport failure looks like. Returns a + `BeadsUnavailableError` (infrastructure unreachable -- the answer is + UNKNOWN) when `p`'s own output carries a transport signature, else a + plain `BeadsError` (a real, computed failure). + + Reuses `_connection_retryable` verbatim rather than inventing a second + signature list: "safe to retry" and "this was infrastructure, not an + answer" are the same judgement, and a second list would be a second + place for it to go stale. Conservative by construction -- a signature + that can never appear in a legitimate bd domain result -- so this can + never soften a genuine failure into "maybe transient". + """ + if _connection_retryable((p.stdout or "") + (p.stderr or "")): + return BeadsUnavailableError(message) + return BeadsError(message) + + def _retryable(blob: str) -> bool: low = blob.lower() return any(t.lower() in low for t in _RETRYABLE) @@ -3137,6 +3337,15 @@ def claim_item(self, item_id: str, *, actor: str) -> Item: """ try: self.get(item_id) # existence check only -- raises if missing + except BeadsUnavailableError: + # The existence check could not be PERFORMED -- the database was + # unreachable, so nothing was learned about whether this item + # exists. Re-raised untouched: relabelling it "item not found" + # is the fourth outcome this docstring promises never to + # conflate with the first, and it lied in 9 of 12 measured + # attempts against an item that existed. See + # `BeadsUnavailableError`. + raise except BeadsError as e: raise BeadsError(f"cannot claim {item_id}: item not found ({e})") from e @@ -3383,6 +3592,20 @@ def get_readonly(self, item_id: str, *, with_links: bool = False) -> Item: """ try: return self.get(item_id, with_links=with_links) + except BeadsUnavailableError: + # WORST of the three flattening sites, and the reason this one + # is fenced first. Both branches below assert ABSENCE, and the + # second discarded the cause outright -- a bare "item 'X' not + # found in project 'Y'" with no parenthetical, nothing an agent + # or a human could tell apart from real absence. Measured + # against an item the calling session HELD: 2 of 8 attempts + # denied its existence. This is also the exact path + # `context/awareness.md` hazard #6 tells agents to TRUST as the + # safe recovery after an ambiguous write ("re-read the item + # first ... a read-only path that cannot itself conflict"), so + # a lie here is a lie told to a caller who was following our + # own instructions. Re-raised untouched, cause intact. + raise except BeadsError as e: prefix = f"{self.project_name}-" if not item_id.startswith(prefix): @@ -4880,6 +5103,31 @@ def move_item(self, src: str, dst: str, item_id: str) -> MoveReport: STATUS_CREATING = "creating" # a `new` for this project is in progress right now STATUS_BROKEN = "broken" # a previous `new` never finished; heals on the next `new` +#: Prefix for the FOURTH state, added because `instances` had no vocabulary +#: between `ok` and `ERROR`: the database is fine, WE could not reach it. +#: `"ERROR: ..."` asserts the project's data is unreadable; measured (lane +#: `model_performance-rpz`), a healthy project printed exactly that in 5 of +#: 10 attempts, interleaved with correct `ok` rows for the same project +#: seconds either side. That is a claim about the project; this is a claim +#: about the connection, and they must not share a word. +#: +#: A PREFIX rather than a bare token, matching the existing `"ERROR: "` +#: convention, because the diagnostic text after it is the actionable part. +#: `is_unavailable_status` is the one place that recognises it -- callers +#: must not re-derive the test with their own `startswith`. +STATUS_UNAVAILABLE_PREFIX = "UNAVAILABLE: " + + +def is_unavailable_status(status: str | None) -> bool: + """True if `status` is a `ProjectSummary.status` reporting that the + database could not be REACHED (as opposed to read and found broken). + + One home for the test so the CLI table, the JSON rows, and the web + dashboard cannot drift into three different opinions about which + strings mean "unknown" -- the same reason `truncate_status` is shared. + """ + return bool(status) and str(status).startswith(STATUS_UNAVAILABLE_PREFIX) + @dataclass class ProjectSummary: @@ -4896,7 +5144,11 @@ class ProjectSummary: from `Workspace.creation_state`, consulted BEFORE any item read so a half-created project is never mistaken for a healthy empty one); or a truncated `"ERROR: ..."` string (see `truncate_status`) when the - database exists but could not be read at all. In EVERY non-`ok` case + database exists but could not be read at all; or a truncated + `"UNAVAILABLE: ..."` string (`STATUS_UNAVAILABLE_PREFIX`, + `is_unavailable_status`) when the database could not be REACHED, which + is a claim about the connection and not about the project. In EVERY + non-`ok` case every field below is `None`/empty, not zero, so a caller can never mistake "not healthy" for "read as empty." @@ -5128,9 +5380,19 @@ def project_summary(ws: Workspace, name: str) -> ProjectSummary: reported a healthy `ok` with 0 items. `webapp.py` calls this function directly, so putting the check HERE -- not only in `cli.cmd_instances` -- is what makes the web dashboard honest too. - 2. A database that then cannot be read reports `status="ERROR: ..."` - (truncated), again with every field `None`/empty. - 3. Otherwise `STATUS_OK`, with real counts. + 2. A database that could not be REACHED reports + `status="UNAVAILABLE: ..."` (truncated) -- distinct from both `ok` + and `ERROR`, because it is a claim about the connection, not about + the project. Measured (lane `model_performance-rpz`): under a + transient dolt read failure a healthy project printed as `ERROR` + with null counts in 5 of 10 attempts, interleaved with correct + `ok` rows for that same project. `_dolt_sql*` now retries a + transport blip first (`_run_dolt_sql_bounded`), so this state is + reached only PAST that bounded budget. + 3. A database that IS reachable but cannot be read reports + `status="ERROR: ..."` (truncated), again with every field + `None`/empty. + 4. Otherwise `STATUS_OK`, with real counts. On the healthy path, fetches items exactly ONCE (`ws.project(name).list(include_resolved=True)`) and derives every field @@ -5167,6 +5429,13 @@ def project_summary(ws: Workspace, name: str) -> ProjectSummary: return ProjectSummary(name=name, status=STATUS_BROKEN) try: items = _summary_items_via_sql(name) + except BeadsUnavailableError as e: + # The database was UNREACHABLE -- we learned nothing about this + # project. Reporting `ERROR:` here asserts its data is unreadable, + # which was false in 5 of 10 measured attempts against a healthy + # project. See `STATUS_UNAVAILABLE_PREFIX`. Ordered before the + # `BeadsError` arm because it is a subclass. + return ProjectSummary(name=name, status=truncate_status(f"{STATUS_UNAVAILABLE_PREFIX}{e}")) except BeadsError as e: return ProjectSummary(name=name, status=truncate_status(f"ERROR: {e}")) held_items = [i for i in items if i.status == "held"] diff --git a/src/amplifier_work_tracker/cli.py b/src/amplifier_work_tracker/cli.py index 3c07f1d..a6aced8 100644 --- a/src/amplifier_work_tracker/cli.py +++ b/src/amplifier_work_tracker/cli.py @@ -535,6 +535,21 @@ def cmd_instances(a): broken by one that never finished is reported as such -- `creating` or `broken` -- and `ok` is restored to actually meaning "writable." + Second measured misreport, 2026-09-02 (lane `model_performance-rpz`): + this table had no vocabulary between `ok` and `ERROR`, so a transient + dolt read failure printed a perfectly healthy project as + `ERROR: could not read items of database ...` with every count blank -- + 5 of 10 attempts, interleaved with correct `ok` rows for that same + project seconds either side. `ERROR` asserts the project's data is + unreadable; all that was actually known is that OUR read did not + arrive. `adapter.project_summary` now reports that fourth state as + `UNAVAILABLE: ...` (`adapter.STATUS_UNAVAILABLE_PREFIX`), distinct from + BOTH `ok` and `ERROR`, and only past the bounded transport retry + `_run_dolt_sql_bounded` added to the direct-SQL path. This table prints + `s.status` verbatim, so the distinction lands here for free -- there is + deliberately no second copy of the "which strings mean unknown" rule in + this file (see `adapter.is_unavailable_status`). + Counting logic beyond creation-state lives in `adapter.project_summary` -- shared with the web dashboard (see `webapp.py`) so the two can never silently disagree on what "ready"/"held"/"intake"/"blocked" mean, or on diff --git a/src/amplifier_work_tracker/contract.py b/src/amplifier_work_tracker/contract.py index d02c4b6..193b9a0 100644 --- a/src/amplifier_work_tracker/contract.py +++ b/src/amplifier_work_tracker/contract.py @@ -20,6 +20,7 @@ import json import os import shutil +import subprocess import sys import tempfile import time @@ -1316,8 +1317,166 @@ def check_block_refuses_resolved(p: Probe) -> Result: ) +_TRANSPORT_FAILURE_STDERR = ( + "failed to load database names: lstat /tmp/probe_vanished.sig: no such file or directory" +) + + +def check_unavailable_not_absent(p: Probe) -> Result: + """An infrastructure read failure must NEVER surface as "not found". + + THE regression fence for lane `model_performance-8zv`. Measured before + the fix (lane `model_performance-rpz`, harness + `probes/rpz-dolt-error-misreport/repro.sh`): with the `dolt` client + losing a race against its own churning working directory, `claim --id` + on an item that EXISTS reported "item not found" in 9 of 12 attempts, + and `list --id` on an item the calling session HELD reported a bare + "item 'X' not found in project 'Y'" -- cause discarded entirely -- in 2 + of 8. An agent following this project's own contention contract + (`context/awareness.md` hazard #6: re-read the item first) was told its + held item did not exist. + + Fenced in BOTH directions, because half a fix is a different lie: + + 1. UNDER a transport failure, on a REAL item: `get_readonly` and + `claim_item` must raise `A.BeadsUnavailableError` and must not + claim absence. + 2. On a HEALTHY database, a genuinely absent item must still report + plain absence, in the same words as before -- no "maybe + transient" hedge anywhere near it. + + The transport failure is INJECTED (`_dolt_sql`/`_dolt_sql_json` + temporarily replaced with one that returns dolt's real wording at + returncode 1) rather than provoked by churning a directory: this check + runs inside `doctor` on operators' machines, and a check that + manufactures a filesystem race to prove a point is a check that + occasionally breaks something else. Injecting at the helper also puts + the failure PAST `_run_dolt_sql_bounded`'s retry budget, which is the + condition the deliverable actually names. Everything above the helper + -- classification, the type, all three call sites -- is exercised for + real. Restored in a `finally`, so a failure here cannot leave the + process's SQL path patched. + """ + assert p.bd + real_id = p.bd.create("unavailable-vs-absent probe", tags=["lane:probe_unavailable"]) + absent_id = f"{p.name}-nosuchitem" + + # --- 2. HEALTHY database first: capture today's real absence wording, + # so direction (2) is asserted against observed behaviour rather than a + # string this check hard-codes and could drift from. + try: + p.bd.get_readonly(absent_id) + return Result( + "read.unavailable_not_absent", + False, + f"a genuinely absent item {absent_id!r} was READ successfully -- the probe " + f"cannot distinguish anything if absence itself is not reported", + ) + except A.BeadsUnavailableError as e: + return Result( + "read.unavailable_not_absent", + False, + f"a genuinely absent item on a HEALTHY database reported UNAVAILABLE ({e}) " + f"-- real absence has been blurred into 'maybe transient', which replaces " + f"one lie with another", + ) + except A.BeadsError as e: + healthy_absence = str(e) + if "not found" not in healthy_absence.lower(): + return Result( + "read.unavailable_not_absent", + False, + f"absence on a healthy database no longer reads as 'not found' " + f"({healthy_absence!r}) -- the two conditions can no longer be told apart", + ) + + # --- 1. Now the transport failure, against an item that EXISTS. + def _fail(*_a, **_k): + return subprocess.CompletedProcess(["dolt"], 1, "", _TRANSPORT_FAILURE_STDERR) + + real_sql, real_sql_json = A._dolt_sql, A._dolt_sql_json + A._dolt_sql, A._dolt_sql_json = _fail, _fail + try: + try: + p.bd.get_readonly(real_id) + return Result( + "read.unavailable_not_absent", + False, + "an unreachable database returned an item anyway -- the injection did " + "not reach the read path, so this check proves nothing", + ) + except A.BeadsUnavailableError as e: + if "not found" in str(e).lower(): + return Result( + "read.unavailable_not_absent", + False, + f"`get_readonly` raised the right TYPE but still says 'not found' " + f"({e}) -- a caller reading the message is still lied to", + ) + if "failed to load database names" not in str(e): + return Result( + "read.unavailable_not_absent", + False, + f"`get_readonly` discarded the underlying cause ({e}) -- this is the " + f"exact path the contention contract tells agents to trust", + ) + except A.BeadsError as e: + return Result( + "read.unavailable_not_absent", + False, + f"AN INFRASTRUCTURE READ FAILURE SURFACED AS A PLAIN BeadsError ({e}) -- " + f"`list --id` on an existing item denies its existence again", + ) + + try: + p.bd.claim_item(real_id, actor="probe-unavailable") + return Result( + "read.unavailable_not_absent", + False, + "an unreachable database CLAIMED an item anyway -- the injection did not " + "reach the claim path", + ) + except A.BeadsUnavailableError as e: + if "item not found" in str(e).lower(): + return Result( + "read.unavailable_not_absent", + False, + f"`claim_item` still reports 'item not found' under an infrastructure " + f"failure ({e})", + ) + except A.BeadsError as e: + return Result( + "read.unavailable_not_absent", + False, + f"`claim_item` flattened an infrastructure failure into a plain " + f"BeadsError ({e}) -- 9 of 12 measured attempts said 'item not found' " + f"about an item that existed", + ) + + summary = A.project_summary(p.ws, p.name) + if not A.is_unavailable_status(summary.status): + return Result( + "read.unavailable_not_absent", + False, + f"`project_summary` reported {summary.status!r} for an UNREACHABLE " + f"database -- `instances` asserts the project's data is unreadable when " + f"only the connection failed", + ) + finally: + A._dolt_sql, A._dolt_sql_json = real_sql, real_sql_json + + return Result( + "read.unavailable_not_absent", + True, + "an infrastructure read failure raises BeadsUnavailableError with its cause " + "intact on read/claim and reports UNAVAILABLE (not ERROR) per project, while " + "genuine absence on a healthy database still reports plain 'not found'", + ) + + CHECKS = [ ("capabilities", check_capabilities), + ("read.unavailable_not_absent", check_unavailable_not_absent), ("resolve.fenced", check_resolve_fenced), ("resolve.divergent_text_refused", check_resolve_divergent_text_refused), ("resolve.identical_text_idempotent", check_resolve_identical_text_idempotent), diff --git a/src/amplifier_work_tracker/webapp.py b/src/amplifier_work_tracker/webapp.py index b1cf484..c8ad8cc 100644 --- a/src/amplifier_work_tracker/webapp.py +++ b/src/amplifier_work_tracker/webapp.py @@ -2069,17 +2069,33 @@ def _dashboard_row(s: A.ProjectSummary) -> str: # alarm without depending on a dedicated token landing first. st = s.status creating = st.lower().startswith(("creating", "provisioning")) + # A project we could not REACH is not a broken project -- painting it + # crimson "Broken" asserts its data is bad when all we know is that + # our own read did not arrive. Measured (lane `model_performance-rpz`) + # 5 of 10 attempts against a healthy project. Amber "Unavailable" + # says the true thing: unknown, not bad. + unavailable = A.is_unavailable_status(st) if creating: kind, word, accent = "warn", "Provisioning", "var(--amber)" tint = "var(--alarm-surface)" detail = "Being created \u2014 counts appear once its database is ready." + elif unavailable: + kind, word, accent = "warn", "Unavailable", "var(--amber)" + tint = "var(--alarm-surface)" + detail = st # "UNAVAILABLE: ..." (already truncated by the adapter) else: kind, word, accent = "bad", "Broken", "var(--crimson)" tint = "var(--blocked-surface)" detail = st # e.g. "ERROR: ..." (already truncated by the adapter) # keep the reading width sane: one legible line, full text on hover shown = detail if len(detail) <= 120 else detail[:119] + "\u2026" - key = f"{s.name} {'provisioning' if creating else 'broken'} {st}".lower() + if creating: + state_word = "provisioning" + elif unavailable: + state_word = "unavailable" + else: + state_word = "broken" + key = f"{s.name} {state_word} {st}".lower() row_style = f"background:{tint};box-shadow:inset 4px 0 0 {accent}" return ( f'' diff --git a/src/amplifier_work_tracker/webbrowse.py b/src/amplifier_work_tracker/webbrowse.py index d9e5f50..4920feb 100644 --- a/src/amplifier_work_tracker/webbrowse.py +++ b/src/amplifier_work_tracker/webbrowse.py @@ -296,6 +296,13 @@ async def project_view(request: Request, name: str): # type: ignore[no-untyped- A.STATUS_CREATING: "This project is still being created.", A.STATUS_BROKEN: "This project's creation never finished.", }.get(summary.status, summary.status) + if A.is_unavailable_status(summary.status): + # Say what is actually known: the read did not arrive. The + # bare status text alone reads like a verdict on the project. + heading = ( + "This project's database could not be reached just now " + f"\u2014 its data is unknown, not broken. {summary.status}" + ) body = ( f"{_observatory_icon_sprite_html()}" '
' diff --git a/tests/cli/test_cli_unavailable_not_absent.py b/tests/cli/test_cli_unavailable_not_absent.py new file mode 100644 index 0000000..0ce7e9e --- /dev/null +++ b/tests/cli/test_cli_unavailable_not_absent.py @@ -0,0 +1,159 @@ +"""Tier 3 -- the real CLI surface, end to end, under a REAL unreachable server. + +The three verbs named in lane `model_performance-8zv`, exercised as a coding +agent actually runs them: a real `amplifier-work-tracker` subprocess, a real +`dolt` binary, a real item that really exists -- and a dolt port that is +genuinely closed, so the transport failure is real rather than injected and +lands PAST `_run_dolt_sql_bounded`'s retry budget. + +Measured before the fix (lane `model_performance-rpz`), under a transient +dolt read failure: + + claim --id -> "item not found" 9 of 12 + list --id -> "item 'X' not found in project 'Y'" 2 of 8 + (cause discarded entirely) + instances -> healthy project printed as ERROR 5 of 10 + +Every unreachable-server assertion below is paired with a healthy-server one +asserting today's absence wording is UNCHANGED. That pairing is the point: +a fix that makes every "not found" say "maybe transient" has replaced one lie +with another, and would pass the first half of this file while failing the +second. +""" + +from __future__ import annotations + +import json +import os +import socket + +import pytest + +from amplifier_work_tracker import adapter as A + +pytestmark = pytest.mark.cli + + +def _closed_port() -> int: + """A TCP port with nothing listening on it -- bind, read, release.""" + s = socket.socket() + s.bind(("127.0.0.1", 0)) + port = s.getsockname()[1] + s.close() + return port + + +@pytest.fixture +def unreachable_env(): + """The real environment, with the dolt port pointed at a closed one. + + Not a mock: `dolt` really runs, really fails to connect, and the CLI + really burns its bounded transport-retry budget before reporting. This + is the condition every deliverable in this lane is phrased against + ("past the retry budget"). + """ + env = dict(os.environ) + env["AMPLIFIER_WORK_TRACKER_DOLT_PORT"] = str(_closed_port()) + return env + + +@pytest.fixture +def live_item(workspace, unique_project_name, unique_lane): + """A project and an item that genuinely EXIST on the healthy server.""" + name = unique_project_name + workspace.create(name) + bd = workspace.project(name) + item_id = bd.create("unavailable-vs-absent CLI probe", tags=[unique_lane], priority=1) + return name, item_id + + +# ============================================== list --id (get_readonly) + + +def test_list_id_on_an_existing_item_does_not_deny_it_when_the_db_is_unreachable( + run_cli, live_item, unreachable_env +): + """The worst of the three: `list --id` is the exact path + `context/awareness.md` hazard #6 tells agents to trust as the safe + recovery after an ambiguous write. It used to answer a bare "not found" + -- cause discarded -- for an item the caller HELD.""" + name, item_id = live_item + r = run_cli(["list", "--project", name, "--id", item_id], env=unreachable_env) + out = (r.stdout or "") + (r.stderr or "") + assert r.returncode != 0, "an unreachable database must not report success" + assert "not found in project" not in out, out + assert "connection refused" in out.lower() or "unreachable" in out.lower(), ( + f"the underlying cause was discarded: {out!r}" + ) + + +def test_list_id_on_a_genuinely_absent_item_is_UNCHANGED(run_cli, live_item): + """No-blurring guardrail. Healthy server, item genuinely absent -- the + same words as before, with no 'maybe transient' hedge.""" + name, _ = live_item + absent = f"{name}-nosuchid" + r = run_cli(["list", "--project", name, "--id", absent]) + out = (r.stdout or "") + (r.stderr or "") + assert r.returncode != 0 + assert f"item '{absent}' not found in project '{name}'" in out, out + assert "unavailable" not in out.lower(), out + + +# ================================================= claim --id (claim_item) + + +def test_claim_id_on_an_existing_item_does_not_say_item_not_found_when_unreachable( + run_cli, live_item, unreachable_env +): + """`claim_item`'s docstring promises three outcomes "deliberately never + conflated"; infrastructure-unavailable is a fourth, and it was folded + into the first.""" + name, item_id = live_item + r = run_cli( + ["claim", "--project", name, "--actor", "probe-unavail", "--id", item_id], + env=unreachable_env, + ) + out = (r.stdout or "") + (r.stderr or "") + assert r.returncode != 0 + assert "item not found" not in out.lower(), out + assert "connection refused" in out.lower() or "unreachable" in out.lower(), out + + +def test_claim_id_on_a_genuinely_absent_item_is_UNCHANGED(run_cli, live_item): + """No-blurring guardrail, claim side.""" + name, _ = live_item + absent = f"{name}-nosuchid" + r = run_cli(["claim", "--project", name, "--actor", "probe-absent", "--id", absent]) + out = (r.stdout or "") + (r.stderr or "") + assert r.returncode != 0 + assert f"cannot claim {absent}: item not found" in out, out + + +# ======================================================== instances + + +def test_instances_reports_UNAVAILABLE_not_ERROR_when_the_db_is_unreachable( + run_cli, live_item, unreachable_env +): + """`ERROR` asserts the project's data is unreadable. A distinct status -- + neither `ok` nor `ERROR` -- is what this table was missing.""" + name, _ = live_item + r = run_cli(["instances", "--json"], env=unreachable_env) + rows = json.loads(r.stdout) + row = next(row for row in rows if row["project"] == name) + status = row["status"] + assert A.is_unavailable_status(status), status + assert not status.startswith("ERROR:"), status + assert status != A.STATUS_OK + assert "total" not in row or row.get("total") is None + + +def test_instances_on_a_healthy_server_is_UNCHANGED(run_cli, live_item): + """No-blurring guardrail, summary side: a reachable project still reads + plainly `ok`, with real counts.""" + name, _ = live_item + r = run_cli(["instances", "--json"]) + rows = json.loads(r.stdout) + row = next(row for row in rows if row["project"] == name) + assert row["status"] == A.STATUS_OK + assert row["total"] is not None diff --git a/tests/unit/test_dolt_scan_dir.py b/tests/unit/test_dolt_scan_dir.py new file mode 100644 index 0000000..856a04f --- /dev/null +++ b/tests/unit/test_dolt_scan_dir.py @@ -0,0 +1,183 @@ +"""Tier 1 -- the pinned dolt scan directory and the direct-SQL retry. + +THE root-cause half of lane `model_performance-8zv`. Diagnosed by lane +`model_performance-rpz` (harness `probes/rpz-dolt-error-misreport/repro.sh`): +the `dolt` CLI enumerates its data directory and `lstat()`s every entry on +EVERY invocation -- including pure client mode against an already-running +shared server -- and with no `--data-dir` given, that directory is whatever +the CALLING AGENT's working directory happened to be. If an entry vanishes +between `readdir` and `lstat`, dolt aborts the whole query. + +Measured, identical load, 25 attempts each: + + cwd = churning dir (the behaviour these tests fence out) ... 6/25 FAIL + cwd pinned to a stable dir ................................. 0/25 + dolt --data-dir , cwd left churning ................ 0/25 + +Both remedies are applied and both are pinned here, because they are +independent: a future refactor that drops one must not silently reopen the +defect via the other. + +Everything here is a pure function of `_run_bounded`'s recorded arguments -- +no `bd`, no dolt server, no network, no real subprocess. +""" + +from __future__ import annotations + +import subprocess +from pathlib import Path + +from amplifier_work_tracker import adapter as A + +TRANSPORT_FAILURE = ( + "failed to load database names: lstat /tmp/churn_7473.sig: no such file or directory" +) + + +def _proc(returncode: int = 0, stdout: str = "", stderr: str = "") -> subprocess.CompletedProcess: + return subprocess.CompletedProcess(["dolt"], returncode, stdout, stderr) + + +def _record(monkeypatch, results): + """Replace `_run_bounded` with one that returns `results` in order and + records every call. Returns the call list.""" + calls: list[dict] = [] + seq = list(results) + + def fake(args, *, env=None, cwd=None, timeout=None): + calls.append({"args": list(args), "env": env, "cwd": cwd}) + return seq.pop(0) if seq else _proc() + + monkeypatch.setattr(A, "_run_bounded", fake) + return calls + + +# ------------------------------------------------------- the pin itself + + +def test_scan_dir_exists_and_is_reused(monkeypatch, tmp_path): + """The pinned directory is real (dolt is handed a path that exists, not + one it will fail to open) and stable across calls -- a fresh directory + per query would reintroduce the per-call cost the pin exists to remove.""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + first = A._dolt_scan_dir() + second = A._dolt_scan_dir() + assert first == second + assert first.is_dir() + + +def test_scan_dir_is_not_the_process_cwd(monkeypatch, tmp_path): + """The whole defect in one assertion: the directory dolt scans must not + be the caller's own working directory, whatever that happens to be.""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + assert A._dolt_scan_dir().resolve() != Path.cwd().resolve() + + +def test_conn_args_pin_the_data_dir(monkeypatch, tmp_path): + """`--data-dir` is on EVERY dolt invocation (it lives in + `_dolt_conn_args`, not on the two hot helpers), which is what makes + `DROP DATABASE`/`SHOW CREATE`/the copy script benefit by construction + rather than by remembering. This is measured fix B: 0/25 with the cwd + left churning.""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + args = A._dolt_conn_args() + assert "--data-dir" in args + assert args[args.index("--data-dir") + 1] == str(tmp_path / "scan") + + +def test_dolt_sql_pins_cwd(monkeypatch, tmp_path): + """Measured fix A: `cwd=` is passed to `_run_bounded`, so the child + `dolt` never inherits the caller's directory. Before this change both + helpers passed no `cwd` at all (`_run_bounded`'s `cwd=None` default -> + `Popen` inherits the parent's).""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + calls = _record(monkeypatch, [_proc(0, "ok\n")]) + A._dolt_sql("SELECT 1") + assert calls[0]["cwd"] is not None + assert Path(calls[0]["cwd"]) == tmp_path / "scan" + + +def test_dolt_sql_json_pins_cwd(monkeypatch, tmp_path): + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + calls = _record(monkeypatch, [_proc(0, '{"rows": []}')]) + A._dolt_sql_json("SELECT 1") + assert Path(calls[0]["cwd"]) == tmp_path / "scan" + + +# ------------------------------------------------- the transport retry + + +def test_lstat_race_is_classified_transient(): + """dolt's own wording for the race. Before this change it appeared in no + retry table at all, and `_RETRYABLE_CONNECTION` was consulted only by + `Beads._run` (which wraps `bd`), never by the direct-SQL path.""" + assert A._connection_retryable(TRANSPORT_FAILURE) + assert A._sql_failure("boom", _proc(1, "", TRANSPORT_FAILURE)).__class__ is ( + A.BeadsUnavailableError + ) + + +def test_a_real_domain_failure_is_not_classified_transient(): + """The other half of the classifier, and the reason it is conservative: + a genuine bd/SQL failure must stay a plain `BeadsError`, or the fix + would soften every real error into 'maybe transient'.""" + p = _proc(1, "", "Error 1064: syntax error near 'SELCT'") + assert not A._connection_retryable((p.stdout or "") + (p.stderr or "")) + err = A._sql_failure("boom", p) + assert isinstance(err, A.BeadsError) + assert not isinstance(err, A.BeadsUnavailableError) + + +def test_direct_sql_retries_a_transient_failure_and_then_succeeds(monkeypatch, tmp_path): + """The 19 direct-SQL call sites had NO retry of any kind. One blip now + rides through instead of surfacing as a read failure.""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + monkeypatch.setattr(A, "time", _NoSleep(A.time)) + calls = _record( + monkeypatch, + [ + _proc(1, "", TRANSPORT_FAILURE), + _proc(1, "", TRANSPORT_FAILURE), + _proc(0, '{"rows": []}'), + ], + ) + p = A._dolt_sql_json("SELECT 1") + assert p.returncode == 0 + assert len(calls) == 3 + + +def test_direct_sql_retry_is_BOUNDED_and_surfaces_the_failure(monkeypatch, tmp_path): + """A persistent outage must fail FAST and surface the SAME non-zero + process every existing call site already handles -- never a new + exception type, and never an unbounded hammer.""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + monkeypatch.setattr(A, "time", _NoSleep(A.time)) + calls = _record(monkeypatch, [_proc(1, "", TRANSPORT_FAILURE)] * 50) + p = A._dolt_sql("SELECT 1") + assert p.returncode == 1 + assert TRANSPORT_FAILURE in p.stderr + assert len(calls) == A._MAX_CONNECTION_RETRIES + 1 + + +def test_direct_sql_does_not_retry_a_real_domain_failure(monkeypatch, tmp_path): + """A syntax error is not a blip. Retrying it would burn seconds and + change nothing.""" + monkeypatch.setenv("AMPLIFIER_WORK_TRACKER_DOLT_SCAN_DIR", str(tmp_path / "scan")) + calls = _record(monkeypatch, [_proc(1, "", "Error 1064: syntax error")] * 10) + p = A._dolt_sql("SELCT 1") + assert p.returncode == 1 + assert len(calls) == 1 + + +class _NoSleep: + """`A.time` with `sleep` neutered -- the retry budget is asserted by call + count, so the test must not actually wait out the backoff.""" + + def __init__(self, real): + self._real = real + + def sleep(self, _seconds): + return None + + def __getattr__(self, name): + return getattr(self._real, name) diff --git a/tests/unit/test_unavailable_not_absent.py b/tests/unit/test_unavailable_not_absent.py new file mode 100644 index 0000000..9935542 --- /dev/null +++ b/tests/unit/test_unavailable_not_absent.py @@ -0,0 +1,201 @@ +"""Tier 1 -- an infrastructure read failure must never be reported as absence. + +The reporting half of lane `model_performance-8zv`. Measured before the fix +(lane `model_performance-rpz`, harness +`probes/rpz-dolt-error-misreport/repro.sh`), under a transient dolt read +failure on a healthy database: + + - `claim --id` on an item that EXISTS said "item not found" .... 9 of 12 + - `list --id` on an item the session HELD said a bare + "item 'X' not found in project 'Y'", cause discarded ......... 2 of 8 + - `instances` printed a healthy project as ERROR, null counts .. 5 of 10 + +`list --id` is the worst of the three: it is the exact path this project's +own `context/awareness.md` hazard #6 tells agents to TRUST as the safe +recovery after an ambiguous write. + +Both directions are fenced here. Every "the infrastructure failed" test has a +paired "the database is healthy and the item really is absent" test asserting +the message is UNCHANGED, byte for byte, from what it says today -- because a +fix that makes every "not found" say "maybe transient" has replaced one lie +with another. + +The failure is injected at `_dolt_sql`/`_dolt_sql_json`, which is also PAST +`_run_dolt_sql_bounded`'s retry budget -- the condition the deliverable names. +No `bd`, no dolt server, no network. +""" + +from __future__ import annotations + +import subprocess + +import pytest + +from amplifier_work_tracker import adapter as A + +TRANSPORT_FAILURE = ( + "failed to load database names: lstat /tmp/churn_22301.sig: no such file or directory" +) + +PROJECT = "probeproj" +REAL_ID = f"{PROJECT}-abcd" +ABSENT_ID = f"{PROJECT}-nosuchid" + + +@pytest.fixture +def probe_workspace(tmp_path): + """A workspace whose project directory exists (so `creation_state` is + `None` -- not creating, not abandoned) and whose database reads are + entirely under this test's control.""" + (tmp_path / PROJECT / ".beads").mkdir(parents=True) + return A.Workspace(tmp_path) + + +@pytest.fixture +def bd(probe_workspace): + return A.Beads(probe_workspace.path(PROJECT) / ".beads", actor="probe") + + +def _unreachable(monkeypatch): + """Every direct-SQL read fails the way dolt really fails when it loses + the race against its own scanned directory.""" + + def fail(*_a, **_k): + return subprocess.CompletedProcess(["dolt"], 1, "", TRANSPORT_FAILURE) + + monkeypatch.setattr(A, "_dolt_sql", fail) + monkeypatch.setattr(A, "_dolt_sql_json", fail) + + +def _healthy_but_empty(monkeypatch): + """A perfectly reachable database that genuinely holds no such item.""" + + def csv_ok(*_a, **_k): + return subprocess.CompletedProcess(["dolt"], 0, "issue_id,label\n", "") + + def json_ok(*_a, **_k): + return subprocess.CompletedProcess(["dolt"], 0, '{"rows": []}', "") + + monkeypatch.setattr(A, "_dolt_sql", csv_ok) + monkeypatch.setattr(A, "_dolt_sql_json", json_ok) + + +# ===================================================== get_readonly / list --id + + +def test_get_readonly_under_transport_failure_does_not_claim_absence(bd, monkeypatch): + """WORST of the three sites: line-for-line, this branch used to discard + the cause entirely and emit a bare "not found" for an item that exists.""" + _unreachable(monkeypatch) + with pytest.raises(A.BeadsUnavailableError) as ei: + bd.get_readonly(REAL_ID) + msg = str(ei.value) + assert "not found" not in msg.lower() + assert "failed to load database names" in msg, "the underlying cause was discarded again" + + +def test_get_readonly_transport_failure_is_a_distinct_TYPE(bd, monkeypatch): + """Structural, not a substring: a caller must not have to grep an error + message to learn whether absence was observed or merely assumed.""" + _unreachable(monkeypatch) + with pytest.raises(A.BeadsError) as ei: + bd.get_readonly(REAL_ID) + assert isinstance(ei.value, A.BeadsUnavailableError) + + +def test_get_readonly_genuine_absence_is_UNCHANGED(bd, monkeypatch): + """THE no-blurring guardrail. Healthy database, item genuinely absent -- + the wording must be exactly what it is today, with no hedge.""" + _healthy_but_empty(monkeypatch) + with pytest.raises(A.BeadsError) as ei: + bd.get_readonly(ABSENT_ID) + assert not isinstance(ei.value, A.BeadsUnavailableError) + assert str(ei.value) == f"item {ABSENT_ID!r} not found in project {PROJECT!r}" + + +def test_get_readonly_wrong_project_prefix_is_UNCHANGED(bd, monkeypatch): + """The other healthy-database branch of the same method, likewise + untouched.""" + _healthy_but_empty(monkeypatch) + with pytest.raises(A.BeadsError) as ei: + bd.get_readonly("someotherproject-abcd") + assert not isinstance(ei.value, A.BeadsUnavailableError) + assert "does not look like it belongs to project" in str(ei.value) + + +# =========================================================== claim_item / claim + + +def test_claim_item_under_transport_failure_does_not_say_item_not_found(bd, monkeypatch): + """`claim_item`'s own docstring promises three outcomes "deliberately + never conflated". Infrastructure-unavailable is a fourth, and it was + folded into the first in 9 of 12 measured attempts.""" + _unreachable(monkeypatch) + with pytest.raises(A.BeadsUnavailableError) as ei: + bd.claim_item(REAL_ID, actor="probe") + msg = str(ei.value) + assert "item not found" not in msg.lower() + assert "failed to load database names" in msg + + +def test_claim_item_genuine_absence_is_UNCHANGED(bd, monkeypatch): + """No-blurring guardrail, claim side.""" + _healthy_but_empty(monkeypatch) + with pytest.raises(A.BeadsError) as ei: + bd.claim_item(ABSENT_ID, actor="probe") + assert not isinstance(ei.value, A.BeadsUnavailableError) + assert str(ei.value).startswith(f"cannot claim {ABSENT_ID}: item not found (") + + +# ======================================================= project_summary / instances + + +def test_project_summary_under_transport_failure_is_UNAVAILABLE_not_ERROR( + probe_workspace, monkeypatch +): + """`ERROR:` asserts the project's data is unreadable. All that was + actually known is that our own read did not arrive -- and the project was + healthy, reporting `ok` seconds either side, in 5 of 10 attempts.""" + _unreachable(monkeypatch) + s = A.project_summary(probe_workspace, PROJECT) + assert A.is_unavailable_status(s.status) + assert not s.status.startswith("ERROR:") + assert s.status != A.STATUS_OK + assert "failed to load database names" in s.status + assert s.total is None, "an unreachable project must never report counts" + + +def test_project_summary_unavailable_is_distinct_from_every_other_status( + probe_workspace, monkeypatch +): + """Distinct from BOTH `ok` and `ERROR`, and from the two creation + states -- the vocabulary `instances` did not have.""" + _unreachable(monkeypatch) + s = A.project_summary(probe_workspace, PROJECT) + assert s.status not in (A.STATUS_OK, A.STATUS_CREATING, A.STATUS_BROKEN) + assert not A.is_unavailable_status(A.STATUS_OK) + assert not A.is_unavailable_status("ERROR: could not read items") + + +def test_project_summary_real_read_failure_still_reports_ERROR(probe_workspace, monkeypatch): + """No-blurring guardrail, summary side: a database that IS reachable but + cannot be read is still an honest `ERROR`, not softened to 'unknown'.""" + + def domain_failure(*_a, **_k): + return subprocess.CompletedProcess( + ["dolt"], 1, "", "Error 1049: Unknown database 'probeproj'" + ) + + monkeypatch.setattr(A, "_dolt_sql", domain_failure) + monkeypatch.setattr(A, "_dolt_sql_json", domain_failure) + s = A.project_summary(probe_workspace, PROJECT) + assert s.status.startswith("ERROR:") + assert not A.is_unavailable_status(s.status) + + +def test_project_summary_healthy_is_UNCHANGED(probe_workspace, monkeypatch): + """And a reachable, readable, empty project is still plainly `ok`.""" + _healthy_but_empty(monkeypatch) + s = A.project_summary(probe_workspace, PROJECT) + assert s.status == A.STATUS_OK + assert s.total == 0