156 lines
15 KiB
Markdown
156 lines
15 KiB
Markdown
# Phase 1 re-check: headless forks (fix pass `7b9b748`)
|
||
|
||
- **Reviewer model id**: `claude-opus-5-5[1m]`. Fresh: did not plan, build, review or fix this phase.
|
||
- **Date**: 2026-10-16 16:39 +0200 (`date`)
|
||
- **Scope**: only the findings named in the brief: I1, I2, I3, M1, M2, M3, M4, M5, M9 from `reports/2026-10-16-16-headless-forks-phase1-review.md`. Diff `20b049e..HEAD` (`7b9b748` code and tests; `4515dbb`, `e60f94c` run log). Run-log sections "Phase 1 fix pass" and "Phase 1 fix pass — Athanor check and deferred Minors", including the builder's re-check flags.
|
||
- **Verdict**: all nine resolved. No Critical or Important finding survives. The residual flags are Minor. One new Minor residual comes from the M1 reorder (R1 below).
|
||
|
||
## Gates I ran
|
||
|
||
| Gate | Result |
|
||
|---|---|
|
||
| G-unit `uv run plugins/spire/skills/forks/tests/test_forks.py` | exit 0, `Ran 86 tests in 66.347s`, `OK`, none skipped (16:30:37–16:31:44) |
|
||
| G-where `uv run plugins/spire/skills/forks/forks.py where` | exit 0. stdout is one line holding one JSON object: `ok: true`, `spawn: cim-hidden`, binary 2.1.299, `warnings: []` |
|
||
| New tests against the unfixed helper | Scratch copy: `forks.py` from `20b049e`, plus the current `tests/test_forks.py`, `preamble.md` and `templates/`. I ran the 26 new or changed tests: **20 failures, 14 errors, 0 unexpected passes** (counted per subtest). Details below. |
|
||
| Dead-root tree walk, old vs new | Probe `recheck_tree_probe.py` on the fake table that `ProcessTreeTests` uses. Old `process_tree(rec)` → `[A, A_KID, C, C_KID]` (it claims the reused pid's child A). New, with `alive_until=hb` → `[C, C_KID]`. |
|
||
| Leftover processes | `tasklist` python.exe: none |
|
||
| Commit hygiene | `20b049e..HEAD` touches only `forks.py`, `test_forks.py` and the run log. No attribution trailers. |
|
||
|
||
No live `claude` calls were made.
|
||
|
||
## Findings, one by one
|
||
|
||
### I1: an error before the model answers was reported as `model_refused`. **Resolved.**
|
||
|
||
- **The fix.** At `forks.py:1356`, `substituted = bool(models_used) and requested not in models_used`. An empty delta can no longer count as a refusal. The order of the checks is at `:1358-1372`: refused/substituted, then no result, then API error, then `is_error`, then exit code.
|
||
- **New classifier.** `api_error_reason` (`:1200-1233`) uses the status code first, then the text. `reason_detail` carries the status plus the first 200 characters of the text.
|
||
- **Check against real results.** All 45 result events in the Phase 0 raw streams have `"api_error_status": null`. A successful run is therefore never classified as an API error. The only two `is_error: true` lines in that data are tool results, not result events.
|
||
- **Tests that fail on the old helper:**
|
||
- `test_api_errors_are_not_model_refused`: 6 of 7 cases fail on the old helper. All of them read `model_refused`. The substitution case still passes, which is correct.
|
||
- `test_failures_flags_and_drift` fails on the old helper (`model_refused != is_error`). It now runs the empty-delta path.
|
||
- `RuleTests.test_api_error_reason` fails on the old helper with an AttributeError, because the function did not exist yet.
|
||
- **Builder flag: the text patterns are a heuristic.** Acceptable as Minor. The patterns only apply when `is_error` is true or a status is present, and the status code wins. The worst misclassification is one error reason swapped for another, never `ok` turned into `failed`.
|
||
- **Coverage shift (not a weakening).** The stub's `error` directive used to bill three turns. So "is_error after the requested model billed" (a mid-run error) has no test of its own any more. It reaches the same `is_error` branch through `substituted=False`. Minor.
|
||
|
||
### I2: walking a dead root's tree could claim and kill unrelated processes. **Resolved.**
|
||
|
||
- **The fix.** `process_tree(rec, alive_until)` (`:739-771`) takes a dead root's direct children only when `root_ctime < child_ctime <= epoch_to_ctime(alive_until + 1 s)`. With no recorded ctime, or no `alive_until`, a dead root claims nothing. Below a child that has been claimed and verified live, the old rule applies, and it is safe there because that parent pid is live, so it cannot have been reused.
|
||
- **Where the bound comes from:**
|
||
- `reap_lost` (`:1547`) and `kill_job` (`:1574`) pass `last_alive_at(rt)`, the later of `heartbeat_at` and `ended_at`.
|
||
- The supervisor's own calls pass `time.time()` (`:2396`, `:2399`, `:2417`, `:2428`, `:2463`). At those points `claude` exited only just now, or is still alive.
|
||
- **The review's scenario.** Reboot or crash, then a reap: every process created after the reboot is newer than the pre-reboot heartbeat, so nothing is claimed.
|
||
- **Units.** Windows FILETIME is UTC on both sides, so the conversion is consistent.
|
||
- **Tests.** The four `ProcessTreeTests` error on the old helper through the new API. My probe above shows the behaviour itself differs. `test_dead_root_claims_only_children_from_its_lifetime` and `test_dead_root_without_bounds_claims_nothing` would also fail behaviourally on the old walk. `test_reap_lost_bounds_by_heartbeat` would fail too, because the old helper passed no bound. `test_live_root_unchanged` is a regression guard and is meant to pass on both.
|
||
- **Builder flag: a child created in the last heartbeat interval is not claimed** (up to `HEARTBEAT_S` = 10 s, less while turns are moving). Acceptable as Minor. The failure mode is now a leaked process, not killing an unrelated one, which is the right trade. One variant of the same gap: when `kill_job` finds the supervisor alive but `claude` already dead, the kill pre-empts the supervisor's own `time.time()` sweep. Children `claude` started in its last ≤ 10 s can then leak. Same class, also Minor.
|
||
- **Builder flag: POSIX without `/proc/stat`.** A dead root claims nothing there. Acceptable, since POSIX is out of tested scope (M14 is deferred).
|
||
|
||
### I3: a `continue` moved the base's `last_hit` forward. **Resolved.**
|
||
|
||
- **In the supervisor**, `hit_written = e["kind"] != "fork"` (`:2379`). Only a fork bumps the base in the loop (`:2405-2408`).
|
||
- **In `_conclude`** (`:1440-1446`), only `train` (its last event) and `fork` (its first event) set `hit_t`. A `continue` sets neither, which matches design §5.
|
||
- **Test.** `test_continue_leaves_base_last_hit` fails on the old helper (the base's `last_hit` moved). It also checks that a later fork still refreshes it.
|
||
|
||
### M1: a kill during finalisation could leave a duplicate ledger line. **Resolved** (the duplicate). One residual window (R1).
|
||
|
||
- **The fix.**
|
||
- `finalize_job` (`:1470-1474`) now writes the result, then the registry, then the ledger.
|
||
- `ledger_append` (`:542-555`) skips a job that already has a line.
|
||
- A torn last line gets a leading newline.
|
||
- **Test.** `test_ledger_append_dedupes_by_job` fails on the old helper.
|
||
- **R1 (new, Minor).** The reorder turns the race's outcome from a duplicate line into a missing one.
|
||
- *Scenario:* `taskkill` lands between `write_registry` and `ledger_append`. The registry is final. `kill_job`'s `finalize_job` then sees a final entry and returns `None`.
|
||
- *Result:* the job never gets a ledger line. Its result file exists, but Phase 2's `usage` would under-count that job's cost.
|
||
- The window is still milliseconds. The review offered this order itself.
|
||
- *For Phase 2:* `usage` should reconcile the ledger against `results/*.json`, or `kill_job` should append the missing line when `finalize_job` returns `None` and no line exists.
|
||
|
||
### M2: the stale-lock break had a race and a hot loop. **Resolved.**
|
||
|
||
- **Hot loop.** A failed `_break` now falls through to the deadline check and the sleep (`:468-480`).
|
||
- `test_unbreakable_stale_lock_respects_deadline` fails on the old helper: "acquire spins…, hot loop, no deadline".
|
||
- **Staleness.** A lock is stale when its holder's pid + ctime is dead (`_is_stale`, `:421-429`), or when it is older than `LOCK_ABANDONED_S` = 300 s.
|
||
- `_try_create` writes the holder's pid and ctime (`:386-388`).
|
||
- A lock caught empty or half-written reads as garbage. It is aged by mtime, so a lock being created is never judged stale.
|
||
- "Access denied" still counts as alive, which is conservative.
|
||
- **Break mechanism.** The waiter renames the lock aside, compares its content, and either deletes it or puts it back with a no-overwrite rename/link (`:431-462`).
|
||
- `test_fresh_lock_taken_during_break_survives` fails on the old helper, but for a different reason: the old age rule never judged that fresh, dead-holder lock stale, so the break was never attempted.
|
||
- Against the new mechanism the test is still meaningful. A check-then-remove variant would delete the swapped-in fresh lock and fail its token assertion.
|
||
- **Builder flag: residual put-back race.** Acceptable as Minor.
|
||
- *How it happens:* while a lock is renamed aside, the path is free. A third waiter can create its lock in that window, and the put-back then fails. Two processes then believe they hold the lock.
|
||
- *Preconditions, all at once:* a stale lock (holder died mid-section), a second waiter who already re-took it, and a third waiter's 50 ms poll landing inside the milliseconds of the aside window.
|
||
- *Damage:* one lost read-modify-write on `registry.json`. The file is written by atomic replace, so it cannot be corrupted.
|
||
- *Compared with before:* strictly narrower than the old two-waiter delete. The case is logged (`_diag`) and leaves a named `.broken.lock`.
|
||
- `release` is still check-then-remove. With a live holder, though, only the 300 s rule can make its lock stale, so in practice no waiter breaks it.
|
||
|
||
### M3: a host suspend killed running forks as `orphaned`. **Resolved.**
|
||
|
||
- **The fix.** `SupClock` (`:2255-2289`):
|
||
- A tick gap over `CLOCK_JUMP_S` = 60 s is excluded from `max_minutes`.
|
||
- It re-arms the orphan watchdog.
|
||
- It flags `clock_jump` and logs it.
|
||
- **Legitimate gaps stay below 60 s.** The longest normal loop-body stall is a lock wait of at most `LOCK_WAIT_S` = 45 s plus a few seconds of retries.
|
||
- **Tests.**
|
||
- `test_clock_jump_not_orphaned_or_timed_out` fails on the old helper (`timeout != ok`). It runs a real `Supervisor` with a 2 h jump injected one second into the run.
|
||
- `test_sup_clock_jump` errors on the old helper, because the class did not exist.
|
||
- **Builder flags.** All acceptable as Minor:
|
||
- **`stalled` still uses the wall clock.** A suspend sets the flag, but nothing in Phase 1 kills on it. The Phase 3 text must not treat `stalled` combined with `clock_jump` as a hung fork.
|
||
- **`wall_s` includes the suspend.** This only affects reporting.
|
||
- **A backwards clock jump is not detected.** It delays the orphan or timeout check by the size of the jump. It happens only on a manual clock change, since `time.time()` is UTC and DST does not move it.
|
||
- **`kill`/`expire` do not refresh the orchestrator stamp.** This belongs in the Phase 3 text, as the review said.
|
||
|
||
### M4: N3 left two gaps. **Resolved.**
|
||
|
||
- **The fix.**
|
||
- `CHILD_REFUSED` (`:127`) now includes `kill`, `expire` and `init`. The refusal is in the dispatch at `:2627`.
|
||
- `stamp_orchestrator`/`touch_orchestrator` (`:1494-1512`) do nothing under `SPIRE_FORKS_CHILD`. By grep, all stamp sites go through them: `train` `:2107`, `fork` `:2156`, `continue` `:2225`, `wait` `:2526`, and `touch_orchestrator` (`:1511`, called at `:2493` and `:2547`).
|
||
- **Tests.** `test_child_refuses_kill_expire_init` and `test_child_does_not_stamp_orchestrator` both fail on the old helper. The marker cannot leak into other tests, because `Base.setUp` patches `os.environ` per test and pops the marker.
|
||
- **Outside M4, on record only.** `_supervise` (internal) and `tick` (Phase 2) are not refused inside a fork either.
|
||
|
||
### M5: the `--permission-mode` value set was stale against 2.1.299. **Resolved.**
|
||
|
||
- **The fix.** At `:69`, the set matches the 2.1.299 `--help` list. `plan` is still refused, and `default` is now "unknown". The `allowed` list leaves out `plan` (`:1826-1827`).
|
||
- **Test.** `test_permission_modes_match_2_1_299` fails on the old helper: it accepted `default`.
|
||
|
||
### M9: `ANTHROPIC_BASE_URL` sat on neither scrub list. **Resolved.**
|
||
|
||
- **The fix.** The variable is on `SCRUB_KEEP` (`:114`). `where` always returns a `warnings` list, and warns when the value, trailing slash and case ignored, is not `https://api.anthropic.com` (`:1778-1793`). The exit code stays 0.
|
||
- **Tests.** `test_where_warns_on_base_url` errors on the old helper (KeyError `warnings`). `ScrubTests.test_unknown` fails on the old helper.
|
||
- **Not done.** The review's optional "record the value per base" was not built. It was optional.
|
||
- **Builder flag: an empty value warns.** Acceptable as Minor. The output is a cosmetic false warning (`ok: true`, exit 0), and the empty value passes through to the child unchanged.
|
||
|
||
## Weakened checks and tests that cannot fail
|
||
|
||
I diffed `20b049e..HEAD` on `test_forks.py`. Every removed line is accounted for:
|
||
|
||
- **`scrub_unknown`** expected `["ANTHROPIC_BASE_URL", "CLAUDE_CODE_NEW_THING"]` and now expects `["CLAUDE_CODE_NEW_THING"]`. This is M9's intended change. The fix pass also added `scrub_class("ANTHROPIC_BASE_URL") == "keep"`.
|
||
- **`test_stale_lock_broken` became `test_dead_holder_lock_broken_at_once`.** The new test is stricter: it adds a time bound under 1.5 s and checks that no `.lock` file is left. Breaking by age is still covered, by `test_abandoned_lock_broken_by_age` and `test_garbage_stale_lock_broken_by_mtime`.
|
||
- **`LOCK_STALE_S` became `LOCK_ABANDONED_S`** in the garbage-lock test and the injected-clock test. This is M2's intended change. The assertions are unchanged.
|
||
- **`test_fresh_lock_not_broken` is stronger.** It now uses a live holder aged 60 s (older than the old 30 s threshold) and adds a fresh garbage lock.
|
||
- **The stub's `error` directive** now bills nothing. The expectations in `test_failures_flags_and_drift` are unchanged, and the test now runs the more realistic path. See the coverage note under I1.
|
||
|
||
Other checks:
|
||
|
||
- **Skip guard.** The only `skipTest` added (`ProcessTreeTests`, when there is no epoch→ctime conversion) cannot trigger on Windows. The suite reported no skips.
|
||
- **Tests that cannot fail.** None found. Every new test either fails on the unfixed helper or is a stated regression guard (`test_live_root_unchanged`, `test_abandoned_lock_broken_by_age`).
|
||
|
||
## Surviving Critical / Important
|
||
|
||
None.
|
||
|
||
## Residual Minors for the record (not re-check failures)
|
||
|
||
- **I1:** the text heuristic; no test for "error after billing the requested model".
|
||
- **I2:** a child started in the last heartbeat interval is not claimed (also through `kill_job` when the supervisor is alive and `claude` is dead); POSIX without `/proc/stat` claims nothing.
|
||
- **M1 / R1:** a kill between the registry write and the ledger append leaves the job with no ledger line. Phase 2 `usage` should reconcile against `results/`.
|
||
- **M2:** the three-waiter put-back race; `release` is still check-then-remove.
|
||
- **M3:** `stalled` and `wall_s` count the suspend; backwards jumps are not detected; `kill`/`expire` do not stamp (Phase 3 text).
|
||
- **M9:** an empty value warns.
|
||
|
||
## Unplanned additions in the fix pass (on record)
|
||
|
||
- New failure reasons: `usage_limit`, `overloaded`, `prompt_too_long`, `api_error`. The review asked only that API errors stop reading `model_refused` and suggested carrying the status in the detail. The Phase 3 text needs to list these reasons.
|
||
- New `clock_jump` flag and the `sup.log` jump line.
|
||
- `where` always carries `warnings`, even when the list is empty.
|
||
- `ledger_append` repairs a torn last line, and now returns a bool.
|
||
- The stub directives `apierr=` and `errtext=`.
|
||
- The `.broken.lock` leftover naming (matched by `.gitignore`'s `*.lock`).
|