diff --git a/CHANGELOG.md b/CHANGELOG.md index 299f2360c..00372c283 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,20 @@ # Changelog +## v1.0.16 (2026-09-27) +### Features +- Projects now take turns getting work done, and urgent tasks jump to the front. (WL-0MTJ7IEI80055V2V) +- Downtime tasks now run two at a time, so more work gets done overnight. (WL-0MT50LKAK001EF5Q) +- Sync now protects your completed work from being silently reset by stale data. (WL-0MSOYWZTH003JFVD) +- Query worklogs faster with smaller, focused results. (WL-0MSLW8GHQ0092PJK) +- Answer interview questions in one guided step instead of searching through notes. (WL-0MU55UDBJ008DJ67) +- Stale in-progress items now return to the queue automatically when no agent is working on them. (WL-0MSOJLZD9004P8PI) +- Ship mode now blocks if any work is still in progress, preventing half-finished releases. (WL-0MUD6DDZC007ZSIW) +- Project setup now uses your global agent guidance instead of duplicating it. (WL-0MSIXMKOX0052514) +### Bug Fixes +- Stalled tasks now retry automatically instead of getting stuck forever. (WL-0MU6UL0RJ008IHGT) +- Agents no longer clash over the same files when work is dispatched twice. (WL-0MUBEZ6PE002WLP4) +- Overnight jobs now keep running instead of stalling when one task is active. (WL-0MU87ZGPP0029V28) + ## v1.0.15 (2026-09-24) ### Features - Import and export help now clearly warns that import replaces your entire database. (WL-0MTD0IVNN003WCOB) diff --git a/CLI.md b/CLI.md index f4d852de5..a65d811a0 100644 --- a/CLI.md +++ b/CLI.md @@ -1170,22 +1170,37 @@ wl --json status ### `interview` [options] -Walk through outstanding interview questions on a work item interactively, capturing -answers and clearing the `needsProducerReview` flag. Interview questions are set by -producers when reviewing work items to request clarification or changes. This command -presents each question in sequence, allowing you to provide answers or dismiss questions -that are no longer relevant. +Walk through the outstanding clarifying questions on a work item interactively, +capturing answers and clearing the `needsProducerReview` flag. + +The command reads the work item's clarifying-questions appendix (written by the +`intake` and `plan` skills) and prompts for every question that is still +outstanding — that is, questions with no answer or an explicit +`*(awaiting producer)*` placeholder. Answers are written back into the +appendix in place, so surrounding markup (`Source:` lines, attribution, +quotes, bold markers) is preserved. + +Both appendix styles are recognised: + +- the canonical bullet appendix (`## Appendix: Clarifying questions` with + `- Q: "…" — Answer (user): "…"` entries), and +- the legacy numbered form (`1. **Q:** …` / `**A:** …`). + +Answers are persisted after each response, so an interrupted session can be +resumed by re-running the command: only the questions that remain outstanding +are asked. `needsProducerReview` is cleared once every question has an answer. Options: - `--prefix ` — Operate on a specific prefix (optional). -- `--json` — Output machine-readable JSON (optional). + +> The command requires interactive (TTY) input; it cannot be used with +> `--json`. Examples: ```sh wl interview WL-ABC123 -wl interview WL-ABC123 --json ``` ### `help` [command] diff --git a/docs/design/mode-switch-worker.md b/docs/design/mode-switch-worker.md index 52005e05b..b35874c45 100644 --- a/docs/design/mode-switch-worker.md +++ b/docs/design/mode-switch-worker.md @@ -49,12 +49,33 @@ On plugin/pane restart the idle clock resets to "active now" (construction time), so the proxy stays fast until a fresh full idle window passes (fail-safe). +### Leader-only cheap switching + shared activity (WL-0MU6MXCZZ007ZXT9) + +The mode-switch worker reuses the machine-wide downtime leader +(`DowntimeWorker.isLeader`) — there is no separate election: + +- Only the leader runs the `tick()` cheap-switch logic. Non-leaders skip the + tick entirely, so an idle pane can no longer flip the shared proxy to cheap + while another pane is active (the flip-flop this fixed). +- Every instance (leader and non-leader alike) broadcasts its latest + operator-command timestamp to `mode-activity.json` in the coordination + directory (`getMachineCoordinationDir()`, the same dir as the leader lease). +- The leader's idle evaluation uses `max(localClock, sharedTimestamp)`, so the + proxy stays fast while *any* pane has recent activity. +- The fast switch still fires on the pane that received the command + (fail-open, idempotent) — the active pane may not be the leader. +- The leader probe is read live each tick, so a leadership handover is honoured + on the next tick: the new leader reads the shared activity and continues + from the correct state (no spurious switch during the election). +- **Fail-closed:** if the shared file cannot be read or written, the worker + falls back to its local clock (never a premature cheap switch). + ## 3. Settings (re-read every tick — apply without plugin restart) | Setting | Default | Clamp | |---|---|---| | `modeSwitchEnabled` | `true` | — (disabled ⇒ no scheduler task, no-op hook) | -| `modeSwitchIdleThresholdMs` | `1800000` (30 min) | floor `60000` | +| `modeSwitchIdleThresholdMs` | `3600000` (60 min) | floor `60000` | | `modeSwitchPollIntervalMs` | `10000` | `[5000, 60000]` | The proxy URL is **not** a new setting — it reuses `downtimeProxyUrl`. @@ -71,7 +92,8 @@ time-based plan. ## 5. Key files - `packages/herdr/src/mode-switch-worker.ts` — worker core (idle clock, - admin API client, tick logic, clamps) + leader-gated tick, shared `mode-activity.json` read/write, admin API + client, clamps) - `packages/herdr/src/mode-switch-worker.test.ts` — worker core tests - `packages/herdr/src/mode-switch-integration.test.ts` — wiring tests (settings → worker, route classification, scheduler interval constants) diff --git a/docs/dev/downtime-dispatcher.md b/docs/dev/downtime-dispatcher.md index 461168943..3de255b93 100644 --- a/docs/dev/downtime-dispatcher.md +++ b/docs/dev/downtime-dispatcher.md @@ -428,6 +428,15 @@ leader path equally skips review-gated entries (retaining them for later re-offe flag is cleared). The filter report is "no candidate" (not a `wl-error` strike) and the no-candidate cooldown is not triggered while review-gated work exists. +**Live Herdr-head thread (WL-0MU72WJ8C0005GIE).** The flag reaches +`classifyItemForDispatch` on BOTH dispatch paths. The normal scan in +`dispatchFromHerdrList` builds its `DowntimeItemInfo` field-by-field from the Herdr +head item, so it must thread `needsProducerReview` explicitly; the offer path +(`computeMostImportantItem`) passes the item object directly, so it always honoured +the flag. Before the threading fix (`022f1b24`) the two paths disagreed and the live +path auto-dispatched a `needsProducerReview: true` item — the regression suite +(`needsProducerReview === true blocks a non-critical item…`) pins the agreement. + ### Review-queue depth gate — producer review policy (WL-0MT2UQWOR007CYY9; live-path rewire WL-0MTTSWC1X005P4VD) The **producer review policy**: while the root-only `completed`/`in_review` queue is deep @@ -720,18 +729,47 @@ an agent on a tool call (wl, bash, tests) left the slot "free", so multiple 1. **Owner-lease gate (AC2)** — a non-null Local Proxy owner lease (`local_owner_session_id` / `local_owner_lease_remaining_seconds`) counts as "slot busy" for the dispatch decision when the worker has a live - dispatch pane; only a truly unowned slot is dispatchable. The lease - signal **self-heals**: proxy dispatch leases carry an `expires_at` - (~180 s, `_get_lease_timeout_seconds`) refreshed on activity, are marked - inactive when a stream ends, and expired records are cleaned up — so an - idle-but-open pane stops holding a slot. + dispatch pane; only a truly unowned slot is dispatchable. Dispatch outcome reason: `slot-owned`. + + **Lease contract (WL-0MU8809SZ0022VZG; cross-repo dependency: + `llm-manager`).** The lease is **adaptive**, NOT a fixed ~180 s. The + implementation lives in `llm-manager` (`proxy/proxy/router_helpers.py`): + it extends a static base in proportion to the generation and caps it at + `local_dispatch_lease_max_seconds` (**default 1500 s**), with chunk/prefill + refresh buffers keeping it alive while a stream is active. A long agent + generation therefore holds the lease for its **whole run** — the RCA + observed a dispatched-pane lease run 836 s → 0 (WL-0MU87ZGPP0029V28). + The dispatcher does **not** wait out a lease: it dispatches into genuinely + free **unowned** slots via the per-slot gate (WL-0MU8807BI008C9ME), and a + lease held by a dispatched pane (which already owns its own slot) does not + block the OTHER free unowned slots. Only the **count-based single-slot** + path treats a held lease as blocking (a truly owned sole slot stays + protected). The maximum is pinned in code as + `LOCAL_DISPATCH_LEASE_MAX_SECONDS`; if `llm-manager` changes the default, + revisit that constant and this section so the assumption cannot drift + silently again. 2. **Per-slot owner tracking (AC5)** — `LlamaSlot` carries an optional `owner_session_id`; `countFreeUnownedSlots` excludes owned slots from the free count and the per-slot idle tracker resets an owned slot's timer, so a slot with a live lease is never considered available for a new pane. A single idle-but-owned slot (count-based path) fails closed via the derived `local_lease_active`. + + **Stale/empty per-slot data (WL-0MUFP30T2003OX1F).** The proxy serves + `slots: []` together with `slots_stale: true` when its fresh `/slots` + query fails: the slot COUNTS come from the last-known cache but the + per-slot detail is unavailable. An empty array is **not** "zero free + slots", so the worker treats stale OR empty `slots` as "no per-slot + identity" and falls back to the count-based path. In that path, with a + multi-slot config (`0 < N < total`) a held lease no longer blocks + dispatch into the proxy-reported spare capacity: the count-based gate + uses `available_slots`, reserving one slot per lease only when the owner + may be idle (`local_active_query !== true` — an active query's slot is + already processing and excluded from the count). A single-slot + (`total_slots = 1`) or `N <= 0` / `N >= total` setup keeps the strict + fail-closed gate. The proxy-side improvement (serve cached per-slot + detail when stale) is tracked separately in `llm-manager`. 3. **Contention feedback (AC6)** — the proxy's LIVE `contention_queue_depth` is parsed; while > 0 the dispatcher backs off with outcome reason `proxy-contention` until the queue drains. The sibling diff --git a/docs/dev/memory-monitoring.md b/docs/dev/memory-monitoring.md new file mode 100644 index 000000000..f9228c18b --- /dev/null +++ b/docs/dev/memory-monitoring.md @@ -0,0 +1,293 @@ +# Memory Pressure Monitoring & Alerting + +**Work Item:** WL-0MT1KJNGA006EEHU — Set up memory pressure monitoring and alerting +**Date:** 2026-09-25 +**Status:** Installed and verified + +--- + +## 1. Summary + +| Component | Mechanism | Status | +|-----------|-----------|--------| +| Live memory pressure check | `scripts/memwatch.sh` via `/etc/cron.d/memwatch` (every minute) | ✅ Installed | +| Alert delivery | journald via `logger -p user.warning` (prefix `MEMWATCH:`) | ✅ Verified | +| Historical memory trend data | sysstat `sar -r` (10-minute interval, 7-day retention) | ✅ Active | +| Log-noise control | State-file deduplication (one alert per level change) | ✅ Verified | + +**Why:** During the 2026-08-20 system hang, the kernel logged *"Under memory +pressure, flushing caches"* 10+ times between 13:27 and 13:40 with no alert and +no early warning. The system had run for 21 days with accumulating memory +pressure and no monitoring to catch it before it became unresponsive. + +**What is monitored:** `/proc/meminfo` `MemAvailable` — the kernel's own estimate +of how much memory is available for new applications without swapping. This is +the standard metric for headroom (it accounts for reclaimable page cache, unlike +`MemFree`). + +--- + +## 2. Monitoring script — `scripts/memwatch.sh` + +The script reads `MemAvailable` (and `MemTotal`) from `/proc/meminfo`, compares +the result against two configurable thresholds, and writes a structured alert to +journald when the pressure level changes. + +### 2.1 Levels + +| Level | Condition (default) | Exit code | Meaning | +|-------|--------------------|-----------|---------| +| `OK` | `MemAvailable` ≥ 4096 MB | 0 | Normal headroom | +| `WARN` | 2048 MB ≤ `MemAvailable` < 4096 MB | 1 | Memory pressure building — investigate | +| `CRIT` | `MemAvailable` < 2048 MB | 2 | Imminent exhaustion — intervene now | +| `ERR` | `MemAvailable` unreadable | 2 | Monitoring failure — check `/proc/meminfo` access | + +Thresholds are absolute MB values (not percentages) so behaviour is predictable +regardless of total RAM. The defaults correspond to ~17% (warning) and ~8% +(critical) of a 24 GB system. + +### 2.2 Log-line format + +One line per level change, written to journald through `logger`: + +``` +MEMWATCH: 2026-09-25 19:00:01 available=3072MB / total=30970MB (9%) level=WARN +``` + +The line contains the timestamp, the available memory value, the total RAM, the +percentage, and the threshold status — satisfying the AC requirement for a +single structured line per interval. + +### 2.3 Deduplication (log-noise control) + +The script records the last reported level in `MEMWATCH_STATE_FILE` (default +`/run/memwatch-state`). A line is emitted **only when the level changes** from the +previous interval: + +``` +OK → WARN → one line (WARN) +WARN → WARN → no line (deduplicated) +WARN → CRIT → one line (CRIT) +CRIT → CRIT → no line (deduplicated) +CRIT → OK → one line (OK) +``` + +This means sustained pressure produces exactly one alert, not one per minute, +bounding log volume even through a long incident. The exit code still reflects +the current level on every run, so external callers can always poll status. + +### 2.4 Configuration + +All settings are file-level variables at the top of the script, each overridable +by an environment variable: + +| Variable | Default | Purpose | +|----------|---------|---------| +| `MEMWATCH_WARNING_MB` | `4096` | Warning threshold (MB) | +| `MEMWATCH_CRITICAL_MB` | `2048` | Critical threshold (MB) | +| `MEMWATCH_MEMINFO` | `/proc/meminfo` | MemAvailable source (tests override this) | +| `MEMWATCH_STATE_FILE` | `/run/memwatch-state` | Deduplication state file | +| `MEMWATCH_LOG_PREFIX` | `MEMWATCH` | Log line prefix | +| `MEMWATCH_LOGGER` | `logger -p user.warning` | Alert delivery command | +| `MEMWATCH_DRY_RUN` | *(unset)* | Log to stdout instead of journald | +| `MEMWATCH_JSON` | *(unset)* | Emit machine-readable JSON | + +### 2.5 Manual use + +```bash +# Production (logs to journald) +scripts/memwatch.sh + +# Dry run — print the alert line to stdout instead of journald +scripts/memwatch.sh --dry-run + +# Machine-readable output +scripts/memwatch.sh --json + +# Custom thresholds +MEMWATCH_WARNING_MB=8192 MEMWATCH_CRITICAL_MB=4096 scripts/memwatch.sh --dry-run +``` + +--- + +## 3. Installation + +`scripts/install-memwatch.sh` deploys the cron job (requires root): + +```bash +sudo scripts/install-memwatch.sh +# Custom thresholds: +sudo scripts/install-memwatch.sh --warning 8192 --critical 4096 +# Preview without installing: +scripts/install-memwatch.sh --dry-run +# Remove it again: +sudo scripts/install-memwatch.sh --uninstall +``` + +Installation has two parts: + +1. The script is **copied to a root-owned location** `/usr/local/sbin/memwatch` + (`root:root`, mode `0755`). This is deliberate: the cron job runs as root, + so the executed script must not be writable by a non-root user — pointing + root cron at a script inside a user-writable checkout would be a + privilege-escalation vector. +2. `/etc/cron.d/memwatch` is written (`root:root`, mode `0644`): + +``` +SHELL=/bin/bash +PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin + +* * * * * root /usr/local/sbin/memwatch +``` + +Only root can modify either file, so a non-root process cannot alter what the +root cron job executes. + +> **Updating the script:** after changing `scripts/memwatch.sh` in the repo, +> re-run `sudo scripts/install-memwatch.sh` to refresh the installed copy. +> The repo is the source of truth; the installed copy is a deploy artefact. + +--- + +## 4. Querying alerts + +```bash +# Recent memory alerts (logger -t MEMWATCH sets the syslog tag) +journalctl -t MEMWATCH --since '1 hour ago' + +# All warning-or-worse entries carrying the MEMWATCH message prefix +journalctl -p warning --since today | grep MEMWATCH + +# Follow live +journalctl -f -t MEMWATCH +``` + +--- + +## 5. Historical trend analysis (sysstat) + +sysstat is active and collecting memory statistics every 10 minutes. The +`sysstat-collect.timer` drives collection; `sysstat-rotate.timer` rotates daily +and `sysstat-summary.timer` builds daily summaries. + +### 5.1 Verified configuration (2026-09-25) + +``` +$ dpkg -l sysstat | tail -1 +ii sysstat 12.7.7-0ubuntu2 amd64 system performance tools for Linux + +$ systemctl status sysstat-collect.timer +● sysstat-collect.timer - Run system activity accounting tool every 10 minutes + Loaded: loaded (/usr/lib/systemd/system/sysstat-collect.timer; enabled) + Active: active (waiting) + +$ grep HISTORY /etc/sysstat/sysstat +HISTORY=7 + +$ ls /var/log/sysstat/ +sa17 sa18 sa19 sa20 sa21 sa22 sa23 sa24 sa25 ... +``` + +- **Collection interval:** 10 minutes (`sysstat-collect.timer`) +- **Raw retention:** 7 days (`HISTORY=7`) +- **Data location:** `/var/log/sysstat/` (daily files `sa
`) + +### 5.2 Example query — memory trends + +```bash +# Today's memory usage, 10-minute samples +sar -r + +# Specific date (day-of-month form) +sar -r -f /var/log/sysstat/sa24 + +# Time-windowed (13:00–14:00 on the 20th — the 2026-08-20 incident) +sar -r -f /var/log/sysstat/sa20 -s 13:00:00 -e 14:00:00 + +# Percentage-used only, sorted to spot peak pressure +sar -r | awk 'NR>3 {print $4, $5}' | sort -k2 -n | tail -20 +``` + +`kbavail` in `sar -r` output is the same `MemAvailable` metric memwatch alerts on, +so the historical data and live alerts are directly comparable. + +### 5.3 Retention extension + +If 7 days is insufficient for long-term trend analysis, raise `HISTORY` in +`/etc/sysstat/sysstat` (e.g. `HISTORY=30`) and reload sysstat. Disk cost is +roughly 1 MB per day per host for the memory-relevant data. + +--- + +## 6. Verification (operator runbook) + +```bash +# 1. Script works against current system state (no journald write) +scripts/memwatch.sh --dry-run + +# 2. Cron file is installed +cat /etc/cron.d/memwatch + +# 3. End-to-end alert emission (writes one real journald line) +logger -p user.warning "MEMWATCH: $(date '+%Y-%m-%d %H:%M:%S') available=0MB level=SELFTEST" +journalctl -t MEMWATCH --since '1 minute ago' | tail -1 + +# 4. Confirm the cron job has run (a MEMWATCH line per level change) +journalctl -t MEMWATCH --since '5 minutes ago' | tail -5 + +# 5. Historical data is queryable +sar -r | tail -5 + +# 6. Automated tests +npx vitest run tests/memwatch.test.ts +``` + +Expected: step 3 prints the `SELFTEST` line; step 4 shows real `level=OK` lines; +step 6 reports 22 passing tests. + +--- + +## 7. False-positive and limitation notes + +- **`MemAvailable` notionally excludes swap pressure.** A system can be swapping + heavily while `MemAvailable` still looks acceptable. Swap monitoring and PSI + (`/proc/pressure/memory`) are **out of scope** for this work item and are + candidates for follow-up work. +- **Warning threshold is intentionally conservative** (4 GB on a 30 GB host). + Sustained `WARN` without `CRIT` indicates memory is being consumed by + reclaimable cache/workloads that the kernel can recover — useful early signal, + not necessarily an emergency. +- **The state file (`/run/memwatch-state`) is cleared on reboot.** After a reboot the first + interval always emits one line (level change from unknown), which is desirable: + it records the post-reboot memory state. +- **Cron granularity is one minute.** The system can exhaust memory faster than + that; memwatch is an early-warning system, not a hard OOM guard. `systemd-oomd` + or `earlyoom` would be the reactive counterpart (out of scope). + +--- + +## 8. Tests + +`tests/memwatch.test.ts` (22 tests) runs the real script with a fixture +`/proc/meminfo` supplied through `MEMWATCH_MEMINFO` and captures output via +`--dry-run`. It covers: + +- OK/WARN/CRIT level classification and exact threshold boundaries +- Per-level deduplication (repeated intervals produce no second line) +- Level-transition logging (OK→WARN, WARN→CRIT, CRIT→OK) +- Configurable thresholds and log prefix +- Unreadable-meminfo error handling (exit 2, `level=ERR`) +- JSON output shape and `--help` + +--- + +## 9. References + +- `/etc/cron.d/memwatch` — installed cron job (this work item) +- `scripts/memwatch.sh` — monitoring script +- `scripts/install-memwatch.sh` — installer +- `tests/memwatch.test.ts` — automated tests +- `/proc/meminfo`, `/proc/pressure/memory` — kernel memory signals +- `/etc/sysstat/sysstat`, `/var/log/sysstat/` — sysstat configuration and data +- `docs/dev/crash-reporting.md` — related host-health monitoring precedent +- `docs/dev/wl-process-spawning-investigation.md` — `wl-process-healthcheck.sh` precedent diff --git a/package.json b/package.json index 626801a2f..39c95fbbe 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "worklog", - "version": "1.0.15", + "version": "1.0.16", "description": "A simple experimental issue tracker for AI agents", "main": "dist/index.js", "type": "module", diff --git a/packages/herdr/README.md b/packages/herdr/README.md index 1adf0a543..062ba4786 100644 --- a/packages/herdr/README.md +++ b/packages/herdr/README.md @@ -505,17 +505,30 @@ makes the item dispatchable again on the next idle poll. > var (legacy fallback, integer ≥ 1): > > - **`AUDIT_PHASE2_PARALLELISM=1`** (safe default): fast mode, cheap mode -> with full dispatch budget, or config absent. Children run strictly -> sequentially — the skill's documented historical mode. A parent audit -> needs exactly **2 local slots** (parent + at most one child). -> - **`AUDIT_PHASE2_PARALLELISM=2`**: cheap mode AND a second slot is free -> AND the concurrent dispatch budget allows (≤ 1 concurrent dispatch). -> Up to 2 Phase 2 children run in parallel. Since the parent already -> completed Phase 1, the max concurrent streams per audit is 2 — the -> children — which fits cheap mode's 2-slot pool. This is only enabled -> when the combined dispatch budget would not exceed the slot capacity -> (e.g., with concurrent-dispatch cap ≥ 2, PARALLELISM stays at 1 to -> prevent multiple audits × 2 children from exceeding the 2-slot budget). +> without a genuinely free second slot, a non-single-flight dispatch budget, +> or config absent. Children run strictly sequentially — the skill's +> documented historical mode. A parent audit needs exactly **2 local +> slots** (parent + at most one child). +> - **`AUDIT_PHASE2_PARALLELISM=2`**: cheap mode AND a second slot is +> GENUINELY free at dispatch time AND the dispatch is single-flight. Up to +> 2 Phase 2 children run in parallel. Since the parent already completed +> Phase 1, the max concurrent streams per audit is 2 — the children — +> which fits cheap mode's 2-slot pool. +> +> The operative availability signal is the **free-slot count**, never the +> total slot budget: a mode can have a 2-slot pool with only one slot free. +> An unbounded dispatch budget (`concurrentDispatchCap = 0`) or a budget of +> ≥ 2 keeps `PARALLELISM` at `1` — a second audit could otherwise run and +> two audits × 2 children would exceed the cheap pool. Only a single-flight +> budget (`1`, the default pipeline bound) enables `'2'`. +> +> Production wiring (WL-0MT50S9JW001DHME): the downtime worker passes a +> `DowntimeSpawnConfig` — the current proxy mode (from the mode-switch +> worker's last observed mode; unknown until polled, which conservatively +> keeps `'1'`), the genuine free-slot snapshot, the mode's total slot +> budget, and the single-flight pipeline cap — through `spawnAgentPane` to +> `buildDowntimeSpawnOptions`, so dispatched audits no longer fall back to +> the serial default when a second slot is truly free. > > A parent audit therefore needs at most **2 local slots** (the two > parallel children), fitting cheap mode's full capacity (2 × 262144 ctx) @@ -675,6 +688,20 @@ proxy idle state: is treated as busy (fail-closed) so the proxy is never switched cheap while real work might be in flight. The single-flight task means a hung tick can never wedge the task; the proxy URL reuses `downtimeProxyUrl`. +- **Leader-only cheap switching + shared activity (WL-0MU6MXCZZ007ZXT9)** — + only the machine-wide downtime leader (`DowntimeWorker.isLeader`, the + existing election — no separate election) runs the idle cheap-switch logic; + non-leader panes skip it entirely. Every pane broadcasts its latest + operator-command timestamp to `mode-activity.json` in the machine + coordination directory (`getMachineCoordinationDir()` — the same directory + as the downtime leader lease), and the leader evaluates idleness against the + **max** of its local clock and that shared timestamp. The proxy therefore + stays fast while *any* pane has recent activity, and idle panes can no + longer flip the shared proxy to cheap behind an active pane's back (the + flip-flop this fixed). Fast switching still fires on whichever pane received + the command (fail-open, idempotent); only the cheap idle switch is + leader-gated. If the shared file cannot be read or written the worker falls + back to its local clock (fail-closed). - **Restart resets to active now** — on plugin/pane restart the idle clock starts from the worker's construction time, so a fresh pane begins with a full idle window before any cheap switch is eligible. @@ -692,7 +719,7 @@ New settings (all optional): when `false` the scheduler registers no mode-switch task and the agent-route hook is a no-op) - `modeSwitchIdleThresholdMs` — Operator-inactivity window before a cheap - switch is considered (default: `1800000` = 30 minutes, hard floor `60000`) + switch is considered (default: `3600000` = 60 minutes, hard floor `60000`) - `modeSwitchPollIntervalMs` — Poll interval for the proxy idle check when evaluating the idle window (default: `10000`, clamped to `[5000, 60000]`) diff --git a/packages/herdr/src/build-guard.test.ts b/packages/herdr/src/build-guard.test.ts new file mode 100644 index 000000000..74ccab34b --- /dev/null +++ b/packages/herdr/src/build-guard.test.ts @@ -0,0 +1,43 @@ +/** + * Build-guard regression test (WL-0MUFSQMH90086I7W). + * + * The herdr plugin is not compiled by the root `tsc` — the root tsconfig + * includes only the repo-root `src/**`, and `packages/herdr` has its own + * build. A missing type import in the plugin therefore shipped to `dev` + * unnoticed: `downtime-worker.ts` referenced the `PaneLifecycleKind` type in + * its `closePane` dependency signature without importing it, so + * `npm run build` inside `packages/herdr` failed with TS2304 while the root + * build stayed green. + * + * This guard compiles the plugin's own tsconfig and asserts it produces no + * diagnostics, so any future type error in `packages/herdr` fails the suite + * instead of reaching `dev`. + */ + +import { describe, it, expect } from 'vitest'; +import { execFileSync } from 'node:child_process'; +import path from 'node:path'; +import { fileURLToPath } from 'node:url'; + +const packageDir = path.resolve(path.dirname(fileURLToPath(import.meta.url)), '..'); + +describe('herdr plugin build guard', () => { + it('type-checks with tsc --noEmit and reports no errors', () => { + let failed = false; + let diagnostics = ''; + + try { + execFileSync('npx', ['tsc', '--noEmit'], { + cwd: packageDir, + encoding: 'utf8', + stdio: ['ignore', 'pipe', 'pipe'], + }); + } catch (error) { + failed = true; + const e = error as { stdout?: string; stderr?: string }; + diagnostics = `${e.stdout ?? ''}${e.stderr ?? ''}`; + } + + expect(failed, `tsc reported type errors:\n${diagnostics}`).toBe(false); + }, 120_000); +}); diff --git a/packages/herdr/src/downtime-log.test.ts b/packages/herdr/src/downtime-log.test.ts index b8d67443d..9d8884158 100644 --- a/packages/herdr/src/downtime-log.test.ts +++ b/packages/herdr/src/downtime-log.test.ts @@ -23,6 +23,7 @@ import { join } from 'node:path'; import { appendDowntimeLogEntry, appendCoordinationLogEntry, + appendPaneCloseLogEntry, auditDispatchedItemIds, implementDispatchedItemIds, riskEffortDispatchedItemIds, @@ -699,3 +700,84 @@ describe('post-spawn enrichment preserves marker semantics (WL-0MUBVL251006JAQ0 expect(markerStillExcludes(after.get('WL-ENR')!, 'plan_complete', Date.now(), 24 * 60 * 60 * 1000, 'id-guard')).toBe(true); }); }); + +// ── Pane-close lifecycle entries (WL-0MU308WSF0002JWN) ──────────────── +// +// The rolling log gains a `pane-close` entry type recording WHY a dispatched +// pane was closed (intake complete / plan complete / audit passed / audit +// failed / requires-attention). Pane-close entries must be ignored by every +// dispatched-marker reader so the existing change-guard semantics are +// unchanged (backward compatible). +describe('pane-close lifecycle entries (WL-0MU308WSF0002JWN)', () => { + it('appends a pane-close entry with every AC1 field and round-trips it', async () => { + const cwd = makeTempCwd(); + await appendPaneCloseLogEntry(cwd, { + entryType: 'pane-close', + timestamp: '2026-01-02T00:00:00.000Z', + itemId: 'WL-1', + itemTitle: 'Auto close me', + paneId: 'w1:p1', + kind: 'plan', + outcome: 'closed-as-plan-complete', + reason: 'item advanced to plan_complete', + closed: true, + }); + + const entries = await readDowntimeLogEntries(cwd); + expect(entries).toHaveLength(1); + expect(entries[0]).toMatchObject({ + entryType: 'pane-close', + timestamp: '2026-01-02T00:00:00.000Z', + itemId: 'WL-1', + itemTitle: 'Auto close me', + paneId: 'w1:p1', + kind: 'plan', + outcome: 'closed-as-plan-complete', + closed: true, + }); + }); + + it('never throws when the worklog dir is unwritable (fail-closed, AC7)', async () => { + const cwd = '/nonexistent/path/' + Math.random().toString(36).slice(2); + await expect( + appendPaneCloseLogEntry(cwd, { + entryType: 'pane-close', + timestamp: '2026-01-02T00:00:00.000Z', + itemId: 'WL-1', + itemTitle: 'x', + paneId: 'w1:p1', + kind: 'plan', + outcome: 'requires-attention', + closed: true, + }), + ).resolves.toBeUndefined(); + }); + + it('a pane-close entry never contaminates the dispatched-marker readers', async () => { + const cwd = makeTempCwd(); + // A standing implement discharge marker for WL-IMP + a pane-close entry + // that reuses the SAME itemId/kind — the marker readers must see only the + // standing marker (the pane-close entry carries entryType, not a marker). + await appendDowntimeLogEntry( + cwd, + JSON.stringify({ itemId: 'WL-IMP', kind: 'implement', stage: 'plan_complete', dispatchedAt: '2026-01-01T00:00:00.000Z' }), + ); + await appendPaneCloseLogEntry(cwd, { + entryType: 'pane-close', + timestamp: '2026-01-02T00:00:00.000Z', + itemId: 'WL-IMP', + itemTitle: 'Implement me', + paneId: 'w1:p9', + kind: 'implement', + outcome: 'requires-attention', + closed: false, + }); + + const entries = await readDowntimeLogEntries(cwd); + expect([...implementDispatchedItemIds(entries)]).toEqual(['WL-IMP']); + expect(dispatchedItemMarkers(entries, 'implement').get('WL-IMP')?.stage).toBe('plan_complete'); + // The enrichment-less pane-close entry must NOT be reconstructed as a + // dispatched pane (only dispatch/enrichment entries carry a paneId). + expect(entries.filter((e) => e.entryType === 'pane-close')).toHaveLength(1); + }); +}); diff --git a/packages/herdr/src/downtime-log.ts b/packages/herdr/src/downtime-log.ts index ae7f0b254..6ef2eff0c 100644 --- a/packages/herdr/src/downtime-log.ts +++ b/packages/herdr/src/downtime-log.ts @@ -52,6 +52,19 @@ export interface CoordinationLogEntry { workItemId?: string | null; /** Number of entries removed by a prune operation. */ prunedCount?: number; + /** + * No-dispatch decision fields (WL-0MU8808ZY0091JIA): recorded on a + * `kind: 'decision'` / `operation: 'no-dispatch'` entry so the reason a + * tick refused to dispatch is observable from the log alone. All optional + * so coordination check-in/election entries are unchanged (additive + * schema). + */ + reason?: string; + freeSlots?: number; + totalSlots?: number; + ownerPresent?: boolean; + runningPanes?: number | null; + contentionDepth?: number; at?: string; } @@ -76,6 +89,78 @@ export async function appendCoordinationLogEntry( /** Rolling bound: keep at most this many entries in the log file. */ export const DOWNTIME_LOG_MAX_ENTRIES = 100; +// ── Pane-close lifecycle entries (WL-0MU308WSF0002JWN) ───────────────── + +/** + * Outcome for a pane-lifecycle close event, capturing WHY the pane was + * closed (or, for `requires-attention`, why it was flagged). + */ +export type PaneLifecycleOutcome = + | 'closed-as-intake-complete' + | 'closed-as-plan-complete' + | 'audit-passed' + | 'audit-failed' + | 'requires-attention'; + +/** + * The dispatch kind that spawned the pane (plan / intake / audit / + * risk-effort / implement). Re-exports the worker's `DowntimeSkillKind` + * for the pane-lifecycle module so the worker and log share the same set. + */ +export type PaneLifecycleKind = 'plan' | 'intake' | 'audit' | 'risk-effort' | 'implement'; + +/** + * A pane-close lifecycle event recorded in the rolling dispatch log + * (WL-0MU308WSF0002JWN). These entries are keyed by pane id + outcome so + * the lifecycle collector can track which outcomes have already been + * logged and avoid duplicate entries. + * + * This entry type uses `entryType: 'pane-close'` as a discriminator so + * dispatched-marker readers (which filter by `kind === `) ignore + * pane-close entries entirely. + */ +export interface PaneCloseLogEntry { + /** Discriminator — ensures dispatched-marker readers ignore this entry. */ + entryType: 'pane-close'; + /** ISO-8601 UTC timestamp of the pane-close/log event. */ + timestamp: string; + /** Work item id of the dispatched item. */ + itemId: string; + /** Work item title at the time the pane was closed. */ + itemTitle: string; + /** Pane id (unique per pane, e.g. "w2T:p3"). */ + paneId: string; + /** The dispatch kind that spawned this pane. */ + kind: PaneLifecycleKind; + /** Why the pane was closed (or flagged). */ + outcome: PaneLifecycleOutcome; + /** Human-readable reason (required for `requires-attention`). */ + reason?: string; + /** + * Stable machine-readable reason code (part of the monitor's idempotency + * key — see `pane-lifecycle.ts`). `'none'` for clean terminal outcomes. + */ + reasonCode?: string; + /** Whether the pane was actually closed (false for informational log-only). */ + closed: boolean; +} + +/** + * Append one pane-close lifecycle entry to the rolling dispatch log. + * Fail-closed: never throws — the lifecycle logger must never crash the + * worker. + */ +export async function appendPaneCloseLogEntry( + cwd: string, + entry: PaneCloseLogEntry, +): Promise { + try { + await appendRollingJsonl(cwd, DOWNTIME_LOG_FILE, JSON.stringify(entry)); + } catch { + // fail-closed: pane-close logging must never crash the worker + } +} + /** * One parsed line of the downtime dispatch log: either a dispatch event * (itemId/kind/dispatchedAt/title), a spawn-failure trace @@ -111,6 +196,27 @@ export interface DowntimeLogEntry { error?: string; /** send-to-pi.sh exit code (non-zero spawn-failed trace; null = signal). */ exitCode?: number | null; + /** + * Entry-type discriminator (WL-0MU308WSF0002JWN): `'pane-close'` marks a + * pane-lifecycle close event. Absent on dispatch markers, spawn-failure + * traces, and error entries (backward compatible — marker readers ignore + * unknown fields). + */ + entryType?: string; + /** + * Resolved pane id for a dispatch (post-spawn enrichment entry, + * WL-0MUBVL251006JAQ0) or the pane id a pane-close entry refers to. Absent + * when the pane could not be resolved (backward compatible). + */ + paneId?: string | null; + /** Discriminator for a post-spawn enrichment entry. */ + enrichment?: boolean; + /** + * Stable machine-readable reason code for a pane-close entry + * (WL-0MU308WSF0002JWN) — part of the monitor's idempotency key. Absent on + * legacy/other entries. + */ + reasonCode?: string; } /** @@ -146,6 +252,49 @@ export async function readDowntimeLogEntries(cwd: string): Promise/.worklog/downtime-coordination.log` (WL-0MU8808ZY0091JIA). Same + * FAIL-SAFE contract as `readDowntimeLogEntries`: a missing or unreadable + * log yields `[]`, malformed JSONL lines are skipped, and the function never + * throws. Used by the decision-log tests and any observer that wants the + * dispatcher's refusal reasons without parsing the file by hand. + */ +export async function readCoordinationLogEntries(cwd: string): Promise { + const file = join(cwd, '.worklog', COORDINATION_LOG_FILE); + let raw: string; + try { + raw = await readFile(file, 'utf8'); + } catch { + return []; // missing or unreadable → empty (fail-safe) + } + const entries: CoordinationLogEntry[] = []; + for (const line of raw.split('\n')) { + if (line.trim() === '') continue; + try { + const parsed = JSON.parse(line) as unknown; + if (typeof parsed === 'object' && parsed !== null) { + entries.push(parsed as CoordinationLogEntry); + } + } catch { + // malformed line → skip (fail-safe) + } + } + return entries; +} + +/** + * True for a rolling-log line that participates in the dispatched-marker + * readers. Pane-lifecycle close entries (`entryType: 'pane-close'`, + * WL-0MU308WSF0002JWN) reuse `itemId`/`kind` but are NOT dispatch markers — + * without this guard their missing `stage`/`dispatchedAt` would clobber a + * standing marker (last-entry-wins). Any future typed entry is likewise + * excluded; dispatch markers and enrichment entries (no `entryType`) pass. + */ +function isDispatchMarkerEntry(e: DowntimeLogEntry): boolean { + return e.entryType === undefined; +} + /** * Build the set of itemIds the downtime worker has already dispatched for * the given kind (kind-scoped). Entries without an itemId (e.g. @@ -158,6 +307,7 @@ export async function readDowntimeLogEntries(cwd: string): Promise { const ids = new Set(); for (const e of entries) { + if (!isDispatchMarkerEntry(e)) continue; // pane-close/lifecycle entries are not markers // Spawn-failed entries are non-excluding (WL-0MT32F908002YFFA AC2). if (e.outcome === 'spawn-failed') continue; if (e.kind === kind && typeof e.itemId === 'string' && e.itemId.length > 0) { @@ -199,6 +349,7 @@ export function recentDispatchedItemIds( const cutoff = now - windowMs; const ids = new Set(); for (const e of entries) { + if (!isDispatchMarkerEntry(e)) continue; // pane-close/lifecycle entries are not markers // Spawn-failed entries are non-excluding (WL-0MT32F908002YFFA AC2): a // failed spawn is NOT an active run — the pane never appeared, so a new // dispatch must not be blocked by it. @@ -277,6 +428,7 @@ export function dispatchedItemMarkers( ): Map { const markers = new Map(); for (const e of entries) { + if (!isDispatchMarkerEntry(e)) continue; // pane-close/lifecycle entries are not markers // Spawn-failed entries are non-excluding (WL-0MT32F908002YFFA AC2). if (e.outcome === 'spawn-failed') continue; if (e.kind !== kind || typeof e.itemId !== 'string' || e.itemId.length === 0) continue; @@ -368,6 +520,7 @@ export function riskEffortDispatchedItemIds(entries: DowntimeLogEntry[]): Set { const stages = new Map(); for (const e of entries) { + if (!isDispatchMarkerEntry(e)) continue; // pane-close/lifecycle entries are not markers // Spawn-failed entries are non-excluding (WL-0MT32F908002YFFA AC2). if (e.outcome === 'spawn-failed') continue; if (e.kind === kind && typeof e.itemId === 'string' && e.itemId.length > 0) { diff --git a/packages/herdr/src/downtime-worker.fixtures.ts b/packages/herdr/src/downtime-worker.fixtures.ts index e64dc1ca7..7c19069de 100644 --- a/packages/herdr/src/downtime-worker.fixtures.ts +++ b/packages/herdr/src/downtime-worker.fixtures.ts @@ -22,6 +22,9 @@ export const idleAllSlotsFree: LlamaStatus = { available_slots: 4, total_slots: 4, current_model: 'qwen3-8b', + // Normalised owner-session list (WL-0MU88086A0089US4): always present on + // the parsed status, empty when the proxy reports no owner. + local_owner_session_ids: [], }; export const busyActiveQuery: LlamaStatus = { ...idleAllSlotsFree, local_active_query: true }; diff --git a/packages/herdr/src/downtime-worker.test.ts b/packages/herdr/src/downtime-worker.test.ts index ea1a9db9a..c3b6aa165 100644 --- a/packages/herdr/src/downtime-worker.test.ts +++ b/packages/herdr/src/downtime-worker.test.ts @@ -84,6 +84,7 @@ import { parseCriticalCandidatesOutput, parseDepListBlockersOutput, parseShownWorkItem, + parseShowItemOutput, selectCriticalCandidate, criticalSkillKind, resolveDependencyFrontier, @@ -106,9 +107,12 @@ import { parseHerdrPaneListOutput, countRunningDowntimePanes, paneLabelItemId, + isSafeDowntimePaneToClose, runningDowntimePaneItemIds, evaluateCriticalFirstGuard, resolveInFlightPanes, + monitorDispatchedPanes, + DOWNTIME_PANE_LIFECYCLE_INTERVAL_MS, DOWNTIME_POLL_INTERVAL_FLOOR_MS, DEFAULT_DOWNTIME_POLL_INTERVAL_MS, DEFAULT_DOWNTIME_IDLE_THRESHOLD_MS, @@ -138,6 +142,9 @@ import { MIN_BROWSE_ITEM_COUNT, MAX_BROWSE_ITEM_COUNT, DOWNTIME_DISPATCH_EXTEND_MAX, + DOWNTIME_DECISION_LOG_MIN_INTERVAL_MS, + decisionHeaderToken, + LOCAL_DISPATCH_LEASE_MAX_SECONDS, } from './downtime-worker.js'; import { clampBrowseItemCount, @@ -152,7 +159,10 @@ import { createRoundRobinRegistry } from './downtime-round-robin.js'; import { DOWNTIME_LOG_FILE, appendDowntimeLogEntry, + appendPaneCloseLogEntry, readDowntimeLogEntries, + readCoordinationLogEntries, + type CoordinationLogEntry, } from './downtime-log.js'; import { LEASE_FILE, @@ -3902,41 +3912,52 @@ describe('downtime pane spawn (send-to-pi.sh)', () => { expect(optionsWithEmptyConfig.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); }); - it('buildDowntimeSpawnOptions returns PARALLELISM=1 in fast mode', () => { + it('buildDowntimeSpawnOptions returns PARALLELISM=1 in fast mode even with free slots', () => { const options = buildDowntimeSpawnOptions('/repo', { - config: { mode: 'fast', slotBudget: 3, concurrentDispatchCap: 1 }, + config: { mode: 'fast', slotBudget: 3, freeSlots: 3, concurrentDispatchCap: 1 }, }); expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); }); - it('buildDowntimeSpawnOptions returns PARALLELISM=2 for cheap mode with free second slot and dispatch budget allows', () => { - // Cheap mode, 2 slots, only 1 concurrent dispatch allowed → 2 children = 2 streams total + it('buildDowntimeSpawnOptions returns PARALLELISM=2 for cheap mode with a genuinely free second slot (single-flight)', () => { + // Cheap mode, 2 slots, both genuinely free, single dispatch at a time → + // 2 children = 2 streams total, fitting the 2-slot pool. const options = buildDowntimeSpawnOptions('/repo', { - config: { mode: 'cheap', slotBudget: 2, concurrentDispatchCap: 0 }, + config: { mode: 'cheap', slotBudget: 2, freeSlots: 2, concurrentDispatchCap: 1 }, }); expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('2'); }); - it('buildDowntimeSpawnOptions returns PARALLELISM=2 for cheap mode with dispatch cap = 1', () => { - // Single dispatch at a time in cheap mode → 2 children = 2 streams total + it('buildDowntimeSpawnOptions returns PARALLELISM=1 when the second slot is NOT genuinely free', () => { + // The operative signal is freeSlots, never the total slotBudget: a 2-slot + // pool with only 1 free slot cannot run 2 children. const options = buildDowntimeSpawnOptions('/repo', { - config: { mode: 'cheap', slotBudget: 2, concurrentDispatchCap: 1 }, + config: { mode: 'cheap', slotBudget: 2, freeSlots: 1, concurrentDispatchCap: 1 }, }); - expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('2'); + expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); + }); + + it('buildDowntimeSpawnOptions returns PARALLELISM=1 when the dispatch budget is unbounded (cap 0)', () => { + // 0 = unbounded → a second audit could run → 2 audits × 2 children would + // exceed the 2-slot cheap pool. Only cap === 1 is single-flight-safe. + const options = buildDowntimeSpawnOptions('/repo', { + config: { mode: 'cheap', slotBudget: 2, freeSlots: 2, concurrentDispatchCap: 0 }, + }); + expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); }); it('buildDowntimeSpawnOptions returns PARALLELISM=1 when concurrent dispatch budget would exceed slot capacity', () => { // 2+ concurrent dispatches × 2 children each = 4 streams, exceeds 2-slot budget const options = buildDowntimeSpawnOptions('/repo', { - config: { mode: 'cheap', slotBudget: 2, concurrentDispatchCap: 2 }, + config: { mode: 'cheap', slotBudget: 2, freeSlots: 2, concurrentDispatchCap: 2 }, }); expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); }); it('buildDowntimeSpawnOptions returns PARALLELISM=1 when cheap mode slot budget is insufficient', () => { - // Only 1 slot available — cannot run 2 children + // Only 1 slot in the pool — cannot run 2 children const options = buildDowntimeSpawnOptions('/repo', { - config: { mode: 'cheap', slotBudget: 1, concurrentDispatchCap: 1 }, + config: { mode: 'cheap', slotBudget: 1, freeSlots: 1, concurrentDispatchCap: 1 }, }); expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); }); @@ -3944,10 +3965,30 @@ describe('downtime pane spawn (send-to-pi.sh)', () => { it('buildDowntimeSpawnOptions returns PARALLELISM=1 for cheap mode with high dispatch cap', () => { // 3+ concurrent dispatches × 2 children = 6 streams, far exceeds budget const options = buildDowntimeSpawnOptions('/repo', { - config: { mode: 'cheap', slotBudget: 2, concurrentDispatchCap: 3 }, + config: { mode: 'cheap', slotBudget: 2, freeSlots: 2, concurrentDispatchCap: 3 }, }); expect(options.env.AUDIT_PHASE2_PARALLELISM).toBe('1'); }); + + it('spawnDowntimePane forwards the spawn config to the spawn boundary (WL-0MT50S9JW001DHME)', async () => { + const handle = { + unref: vi.fn(), + once: vi.fn((event: string, listener: (arg: unknown) => void) => { + if (event === 'exit') listener(0); + }), + }; + const spawnFn = vi.fn(() => handle) as unknown as DowntimeSpawn; + const config = { + mode: 'cheap' as const, + slotBudget: 2, + freeSlots: 2, + concurrentDispatchCap: 1, + }; + + await spawnDowntimePane('/path/to/send-to-pi.sh', [], { cwd: '/repo', config }, spawnFn); + + expect(spawnFn).toHaveBeenCalledWith('/path/to/send-to-pi.sh', [], { cwd: '/repo', config }); + }); }); // ── Worker orchestrator (AC1/AC5) ───────────────────────────────────── @@ -3959,6 +4000,8 @@ describe('downtime worker orchestrator (createDowntimeWorker)', () => { cooldownMs?: number; status?: unknown; deps?: Partial; + mode?: 'cheap' | 'fast'; + concurrentDispatchCap?: number; } = {}) { const cfg = { enabled: overrides.enabled ?? true, @@ -3967,6 +4010,11 @@ describe('downtime worker orchestrator (createDowntimeWorker)', () => { model: 'plan', cwd: '/repo', noCandidateCooldownMs: overrides.cooldownMs ?? 3_600_000, + // Mode-aware spawn config inputs (WL-0MT50S9JW001DHME). + ...(overrides.mode !== undefined ? { mode: overrides.mode } : {}), + ...(overrides.concurrentDispatchCap !== undefined + ? { concurrentDispatchCap: overrides.concurrentDispatchCap } + : {}), }; const fetcher = vi .fn() @@ -4048,6 +4096,38 @@ describe('downtime worker orchestrator (createDowntimeWorker)', () => { expect(worker.lastDispatchAt).toBe(start + cfg.thresholdMs); }); + it('tick forwards a mode-aware spawnConfig with the genuine free-slot snapshot (WL-0MT50S9JW001DHME)', async () => { + const { worker, deps, cfg } = makeWorker({ mode: 'cheap' }); + const start = 1_000_000; + vi.setSystemTime(start); + await worker.tick(); + + vi.setSystemTime(start + cfg.thresholdMs); + await worker.tick(); + + // idleAllSlotsFree: 4 of 4 slots free, total 4 → forwarded verbatim so + // the spawn boundary never has to reach back into the worker. + expect(deps.spawnAgentPane).toHaveBeenCalledWith( + expect.any(String), + expect.objectContaining({ + spawnConfig: { mode: 'cheap', slotBudget: 4, freeSlots: 4, concurrentDispatchCap: 1 }, + }), + ); + }); + + it('tick omits spawnConfig when the proxy mode is unknown (conservative serial default)', async () => { + const { worker, deps, cfg } = makeWorker(); + const start = 1_000_000; + vi.setSystemTime(start); + await worker.tick(); + + vi.setSystemTime(start + cfg.thresholdMs); + await worker.tick(); + + const call = (deps.spawnAgentPane as ReturnType).mock.calls[0]; + expect(call[1]).not.toHaveProperty('spawnConfig'); + }); + it('requires a fresh full idle period after a dispatch (AC5)', async () => { const { worker, deps, cfg } = makeWorker(); const start = 1_000_000; @@ -6383,6 +6463,36 @@ describe('parseShownWorkItem', () => { }); }); +describe('parseShowItemOutput audit verdict (WL-0MU308WSF0002JWN)', () => { + it('reads the TOP-LEVEL auditResult verdict and timestamp', () => { + const info = parseShowItemOutput( + JSON.stringify({ + success: true, + workItem: { id: 'WL-AUD', status: 'completed', stage: 'in_review' }, + auditResult: { + workItemId: 'WL-AUD', + readyToClose: false, + auditedAt: '2026-01-02T00:00:00.000Z', + }, + }), + ); + expect(info).toMatchObject({ + id: 'WL-AUD', + status: 'completed', + stage: 'in_review', + auditedAt: '2026-01-02T00:00:00.000Z', + auditResult: false, + }); + }); + + it('leaves the verdict absent when auditResult is null (no audit recorded)', () => { + const info = parseShowItemOutput( + JSON.stringify({ success: true, workItem: { id: 'WL-AUD2', stage: 'in_review' }, auditResult: null }), + ); + expect(info!.auditResult).toBeUndefined(); + }); +}); + // ── Critical-first: tier wiring (F4, decisions Q1/Q2/Q3) ───────────── describe('dispatch critical-first tier', () => { @@ -7977,6 +8087,21 @@ describe('paneLabelItemId / runningDowntimePaneItemIds / evaluateCriticalFirstGu expect(paneLabelItemId(undefined)).toBeNull(); }); + it('isSafeDowntimePaneToClose only accepts the downtime pane for the SAME item (AC7)', () => { + const live = [ + pane({ paneId: 'w1:p1', label: 'Downtime triggered implement Some item - WL-ABC' }), + pane({ paneId: 'w1:p2', label: 'pi - my operator session' }), + ]; + // Matching downtime pane for the item → safe. + expect(isSafeDowntimePaneToClose(live, 'w1:p1', 'WL-ABC')).toBe(true); + // A different item's downtime pane (id collision) → NOT safe. + expect(isSafeDowntimePaneToClose(live, 'w1:p1', 'WL-OTHER')).toBe(false); + // A non-downtime (operator) pane → NOT safe. + expect(isSafeDowntimePaneToClose(live, 'w1:p2', 'WL-ABC')).toBe(false); + // The pane is already gone → NOT safe (nothing to close). + expect(isSafeDowntimePaneToClose(live, 'w1:p9', 'WL-ABC')).toBe(false); + }); + it('runningDowntimePaneItemIds returns only WORKING downtime panes, keyed by item id', () => { const ids = runningDowntimePaneItemIds([ pane({ paneId: 'w1:p1', label: 'Downtime triggered implement A - WL-A', agentStatus: 'working' }), @@ -8716,6 +8841,127 @@ describe('critical-first scan on Herdr-head path (WL-0MU6UL3XY001M3VT)', () => { }); }); +// ── Herdr-head dispatch threads needsProducerReview (WL-0MU72WJ8C0005GIE) ── +// +// The live Herdr-head dispatch path (`dispatchFromHerdrList` → normal scan) +// builds its `classifyItemForDispatch` input from the Herdr item fields. Before +// the fix (022f1b24) it OMITTED `needsProducerReview`, so a non-critical item +// flagged for producer review was dispatched anyway — even though the offer +// path (`computeMostImportantItem`, which passes the item object directly) +// already honoured the flag. These tests pin AC1–AC3: the flag blocks a +// non-critical plan_complete / idea candidate, the direct path agrees with the +// offer path, and clearing the flag restores dispatchability. + +describe('Herdr-head dispatch threads needsProducerReview (WL-0MU72WJ8C0005GIE)', () => { + const implementItem = (id: string, overrides: Partial = {}): DowntimeHerdrItem => ({ + id, + title: `Non-critical ${id}`, + status: 'open', + stage: 'plan_complete', + priority: 'medium', + risk: 'Low', + effort: 'S', + sortIndex: 10, + ...overrides, + }); + + const intakeItem = (id: string, overrides: Partial = {}): DowntimeHerdrItem => ({ + id, + title: `Idea ${id}`, + status: 'open', + stage: 'idea', + priority: 'medium', + sortIndex: 10, + ...overrides, + }); + + const dispatchDeps = (items: DowntimeHerdrItem[]): DowntimeWorkerDeps => makeDeps({ + getHerdrListHead: vi.fn().mockResolvedValue({ ok: true, items }), + claimItem: vi.fn().mockResolvedValue({ ok: true }), + spawnAgentPane: vi.fn().mockResolvedValue({ ok: true }), + recordDispatch: vi.fn().mockResolvedValue(true), + }); + + describe('AC2 — the flag blocks a non-critical candidate on dispatchDowntimeWork', () => { + it('blocks a plan_complete item (implement) and dispatches the next eligible item', async () => { + const deps = dispatchDeps([ + implementItem('NPR-GATED', { needsProducerReview: true, sortIndex: 1 }), + implementItem('NPR-ALLOWED', { needsProducerReview: false, sortIndex: 2 }), + ]); + + const outcome = await dispatchDowntimeWork(deps, { model: 'plan', cwd: '/repo' }); + + expect(outcome.dispatched).toBe(true); + expect(outcome.kind).toBe('implement'); + expect(outcome.candidate?.id).toBe('NPR-ALLOWED'); + // The gated item was never claimed. + expect(deps.claimItem).not.toHaveBeenCalledWith('NPR-GATED', expect.any(Object), '/repo'); + }); + + it('blocks an idea item (intake) and dispatches the next eligible item', async () => { + const deps = dispatchDeps([ + intakeItem('NPR-IDEA-GATED', { needsProducerReview: true, sortIndex: 1 }), + intakeItem('NPR-IDEA-ALLOWED', { needsProducerReview: false, sortIndex: 2 }), + ]); + + const outcome = await dispatchDowntimeWork(deps, { model: 'plan', cwd: '/repo' }); + + expect(outcome.dispatched).toBe(true); + expect(outcome.kind).toBe('intake'); + expect(outcome.candidate?.id).toBe('NPR-IDEA-ALLOWED'); + expect(deps.claimItem).not.toHaveBeenCalledWith('NPR-IDEA-GATED', expect.any(Object), '/repo'); + }); + + it('dispatches nothing when every candidate is review-gated', async () => { + const deps = dispatchDeps([ + implementItem('NPR-ONLY', { needsProducerReview: true }), + ]); + + const outcome = await dispatchDowntimeWork(deps, { model: 'plan', cwd: '/repo' }); + + expect(outcome.dispatched).toBe(false); + expect(deps.claimItem).not.toHaveBeenCalled(); + expect(deps.spawnAgentPane).not.toHaveBeenCalled(); + }); + + it('clearing the flag restores dispatchability (same item shape)', async () => { + const gated = implementItem('NPR-CLEAR', { needsProducerReview: true }); + const blocked = await dispatchDowntimeWork(dispatchDeps([gated]), { model: 'plan', cwd: '/repo' }); + expect(blocked.dispatched).toBe(false); + + gated.needsProducerReview = false; + const released = await dispatchDowntimeWork(dispatchDeps([gated]), { model: 'plan', cwd: '/repo' }); + expect(released.dispatched).toBe(true); + expect(released.candidate?.id).toBe('NPR-CLEAR'); + }); + }); + + describe('AC3 — direct and offer paths agree on the producer-review gate', () => { + it('both the direct dispatch and the offer skip the gated item and pick the same next item', async () => { + const items = [ + implementItem('NPR-PARITY-GATED', { needsProducerReview: true, sortIndex: 1 }), + implementItem('NPR-PARITY-ALLOWED', { needsProducerReview: false, sortIndex: 2 }), + ]; + + const direct = await dispatchDowntimeWork(dispatchDeps(items), { model: 'plan', cwd: '/repo' }); + const offer = await computeMostImportantItem(dispatchDeps(items), '/repo'); + + expect(direct.dispatched).toBe(true); + expect(direct.candidate?.id).toBe('NPR-PARITY-ALLOWED'); + expect(offer).toMatchObject({ ok: true, candidate: { id: 'NPR-PARITY-ALLOWED' } }); + }); + + it('the offer reports no candidate when every candidate is review-gated', async () => { + const offer = await computeMostImportantItem( + dispatchDeps([implementItem('NPR-OFFER-ONLY', { needsProducerReview: true })]), + '/repo', + ); + + expect(offer).toMatchObject({ ok: true, noCandidate: true }); + }); + }); +}); + // ── RCA: duplicate re-dispatch of a critical in-flight item ───────────── // Parent WL-0MUBEZ6PE002WLP4 / F1 WL-0MUBVKPLP006RRDJ (AC1.1). // @@ -9062,10 +9308,10 @@ describe('one dispatch per in-flight critical item (WL-0MUBVKS5I007LSWB / AC5)', // // Blocking is done by CLASSIFICATION SHAPE (a non-dispatchable stage for // open items, out-of-recency for completed/in_review) rather than by the -// `needsProducerReview` flag: on the current `dev` the live Herdr-head -// dispatcher builds its `classifyItemForDispatch` input WITHOUT threading -// `needsProducerReview`, so that flag does not block on this path yet (a -// separate defect tracked as a discovered-from work item). +// `needsProducerReview` flag: the window-extension tests deliberately isolate +// the window mechanism from the review gate. (The flag now blocks on this +// path too — the field is threaded into `classifyItemForDispatch` as of +// WL-0MU72WJ8C0005GIE / 022f1b24.) describe('dispatch-window extension — head-cap starvation (WL-0MU6UL3GQ0015AA5)', () => { const OLD = new Date(Date.now() - 30 * 24 * 60 * 60 * 1000).toISOString(); @@ -9733,6 +9979,72 @@ describe('parseLlamaStatus: array local_owner_session_id (WL-0MU88086A0089US4)', }); }); +describe('parseLlamaStatus: local_owner_session_ids normalization (WL-0MU88086A0089US4)', () => { + function makeBase(): Record { + return { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 3, + total_slots: 3, + contention_queue_depth: 0, + contention_queued_count: 0, + }; + } + + it('captures every session in the array and drops the proxy URL element', () => { + const result = parseLlamaStatus({ + ...makeBase(), + local_owner_session_id: ['http://localhost:8080', 'session-a', 'session-b'], + }); + expect(result).not.toBeNull(); + expect(result!.local_owner_session_ids).toEqual(['session-a', 'session-b']); + expect(result!.local_owner_session_id).toBe('session-a'); + }); + + it('normalises a legacy string owner to a single-element array', () => { + const result = parseLlamaStatus({ + ...makeBase(), + local_owner_session_id: 'legacy-session', + }); + expect(result).not.toBeNull(); + expect(result!.local_owner_session_ids).toEqual(['legacy-session']); + expect(result!.local_owner_session_id).toBe('legacy-session'); + }); + + it('yields an empty owner list for malformed input (fail-closed, no throw)', () => { + const malformedInputs: unknown[] = [ + 42, + { id: 'bad' }, + [], + ['http://localhost:8080'], + [42], + ['http://localhost:8080', 42], + ]; + for (const malformed of malformedInputs) { + const result = parseLlamaStatus({ + ...makeBase(), + local_owner_session_id: malformed, + }); + expect(result).not.toBeNull(); + expect(result!.local_owner_session_ids).toEqual([]); + expect(result!.local_owner_session_id).toBeUndefined(); + } + }); + + it('marks local_lease_active from a multi-session array even without lease seconds', () => { + const result = parseLlamaStatus({ + ...makeBase(), + local_lease_active: undefined, + local_owner_session_id: ['http://localhost:8080', 'session-a', 'session-b'], + }); + expect(result).not.toBeNull(); + expect(result!.local_lease_active).toBe(true); + }); +}); + // ── Per-slot owner-lease gate in tick() (WL-0MU8807BI008C9ME AC1-AC4) ── describe('tick(): owner-lease gate must be per-slot (WL-0MU8807BI008C9ME)', () => { @@ -10036,3 +10348,901 @@ describe('tick(): owner-lease gate must be per-slot (WL-0MU8807BI008C9ME)', () = } }); }); + +// ── Pane-lifecycle monitor (WL-0MU308WSF0002JWN, child WL-0MU4URK4H006OFCE) ── +// +// The monitor inspects every dispatched pane recorded in the rolling log +// (marker + post-spawn enrichment), classifies its lifecycle outcome, logs a +// pane-close entry, and closes the pane — EXCEPT `implement` panes, which are +// never auto-closed (AC6). Every boundary is fail-closed (AC7). +describe('pane-lifecycle monitor (WL-0MU308WSF0002JWN)', () => { + const roots: string[] = []; + + function makeRoot(): string { + const root = mkdtempSync(join(tmpdir(), 'pane-lifecycle-')); + roots.push(root); + return root; + } + + afterEach(() => { + for (const root of roots.splice(0)) rmSync(root, { recursive: true, force: true }); + }); + + /** Seed a dispatch marker + its post-spawn enrichment (paneId) entry. */ + async function seedDispatch( + root: string, + opts: { itemId: string; kind: string; paneId: string; stage?: string; title?: string }, + ): Promise { + const marker = { + itemId: opts.itemId, + kind: opts.kind, + dispatchedAt: '2026-01-01T00:00:00.000Z', + cwd: root, + title: opts.title ?? opts.itemId, + stage: opts.stage ?? 'idea', + }; + await appendDowntimeLogEntry(root, JSON.stringify(marker)); + await appendDowntimeLogEntry(root, JSON.stringify({ ...marker, paneId: opts.paneId, enrichment: true })); + } + + /** Deps with a real (rolling-log-appending) recordPaneClose so idempotency works. */ + function monitorDeps(overrides: Partial = {}): DowntimeWorkerDeps { + return makeDeps({ + recordPaneClose: vi.fn(async (entry, cwd) => { + await appendPaneCloseLogEntry(cwd, entry); + }), + ...overrides, + }); + } + + async function paneCloseEntries(root: string) { + return (await readDowntimeLogEntries(root)).filter((e) => e.entryType === 'pane-close'); + } + + it('closes an intake pane and logs closed-as-intake-complete when the item reaches intake_complete', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-1', kind: 'intake', paneId: 'w1:p1', stage: 'idea', title: 'Intake me' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-1', title: 'Intake me', stage: 'intake_complete' }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ ok: true, count: 1, records: [{ paneId: 'w1:p1' }] }), + closePane, + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ checked: 1, logged: 1, closed: 1, errors: 0 }); + expect(closePane).toHaveBeenCalledWith('w1:p1', root, { itemId: 'WL-1', kind: 'intake' }); + const pc = await paneCloseEntries(root); + expect(pc).toHaveLength(1); + expect(pc[0]).toMatchObject({ + entryType: 'pane-close', + itemId: 'WL-1', + itemTitle: 'Intake me', + paneId: 'w1:p1', + kind: 'intake', + outcome: 'closed-as-intake-complete', + closed: true, + }); + }); + + it('closes a plan pane and logs closed-as-plan-complete when the item reaches plan_complete', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-2', kind: 'plan', paneId: 'w1:p2', stage: 'intake_complete' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-2', stage: 'plan_complete' }), + closePane, + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ logged: 1, closed: 1 }); + expect(closePane).toHaveBeenCalledWith('w1:p2', root, { itemId: 'WL-2', kind: 'plan' }); + expect((await paneCloseEntries(root))[0]).toMatchObject({ outcome: 'closed-as-plan-complete', closed: true }); + }); + + it('closes an audit pane and records the pass/fail verdict (AC5)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-3', kind: 'audit', paneId: 'w1:p3', stage: 'in_review' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ + id: 'WL-3', stage: 'in_review', auditedAt: '2026-01-02T00:00:00.000Z', auditResult: false, + }), + closePane, + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ logged: 1, closed: 1 }); + expect(closePane).toHaveBeenCalledWith('w1:p3', root, { itemId: 'WL-3', kind: 'audit' }); + expect((await paneCloseEntries(root))[0]).toMatchObject({ outcome: 'audit-failed', closed: true }); + }); + + it('NEVER closes an implement pane but still logs its in_review completion (AC4/AC6)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-4', kind: 'implement', paneId: 'w1:p4', stage: 'plan_complete' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-4', stage: 'in_review' }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ ok: true, count: 1, records: [{ paneId: 'w1:p4' }] }), + closePane, + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ logged: 1, closed: 0 }); + expect(closePane).not.toHaveBeenCalled(); + expect((await paneCloseEntries(root))[0]).toMatchObject({ + outcome: 'requires-attention', + reasonCode: 'reached-in-review', + closed: false, + }); + }); + + it('is idempotent: a second pass with no state change writes no duplicate entry', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-5', kind: 'plan', paneId: 'w1:p5', stage: 'intake_complete' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-5', stage: 'plan_complete' }), + closePane, + }); + + const first = await monitorDispatchedPanes(deps, root); + const second = await monitorDispatchedPanes(deps, root); + + expect(first).toMatchObject({ logged: 1, closed: 1 }); + expect(second).toMatchObject({ logged: 0, closed: 0 }); + expect(closePane).toHaveBeenCalledTimes(1); + expect(await paneCloseEntries(root)).toHaveLength(1); + }); + + it('logs a NEW entry when the item changes state again (agent-ended → plan_complete)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-6', kind: 'plan', paneId: 'w1:p6', stage: 'intake_complete' }); + const noLivePanes = vi.fn().mockResolvedValue({ ok: true, count: 0, paneIds: [], records: [] }); + // First pass: the agent session has ended but the item is NOT terminal. + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-6', stage: 'intake_complete' }), + getRunningDowntimePanes: noLivePanes, + closePane: vi.fn().mockResolvedValue(true), + }); + await monitorDispatchedPanes(deps, root); + + // The item then advances — a second outcome must be recorded. + deps.getItemLifecycleState = vi.fn().mockResolvedValue({ id: 'WL-6', stage: 'plan_complete' }); + await monitorDispatchedPanes(deps, root); + + const outcomes = (await paneCloseEntries(root)).map((e) => e.outcome); + expect(outcomes).toEqual(['requires-attention', 'closed-as-plan-complete']); + }); + + it('does NOT act on unknown liveness when the item has not reached a terminal (fail-open)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-7', kind: 'plan', paneId: 'w1:p7', stage: 'intake_complete' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-7', stage: 'intake_complete' }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ ok: false, error: 'herdr down' }), + closePane, + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ checked: 1, logged: 0, closed: 0, errors: 0 }); + expect(closePane).not.toHaveBeenCalled(); + expect(await paneCloseEntries(root)).toEqual([]); + }); + + it('is fail-closed: a throwing closePane still logs the outcome (closed:false) and never throws (AC7)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-8', kind: 'intake', paneId: 'w1:p8', stage: 'idea' }); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-8', stage: 'intake_complete' }), + closePane: vi.fn().mockRejectedValue(new Error('herdr: pane not found')), + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ checked: 1, logged: 1, closed: 0, errors: 0 }); + expect((await paneCloseEntries(root))[0]).toMatchObject({ closed: false }); + }); + + it('is fail-closed: a throwing item lookup counts an error and never throws (AC7)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-9', kind: 'plan', paneId: 'w1:p9' }); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockRejectedValue(new Error('wl exploded')), + closePane: vi.fn().mockResolvedValue(true), + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ checked: 1, logged: 0, errors: 1 }); + }); + + it('continues past a bad pane so later panes still process (AC7)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-BAD', kind: 'plan', paneId: 'w1:pA' }); + await seedDispatch(root, { itemId: 'WL-GOOD', kind: 'intake', paneId: 'w1:pB' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn(async (itemId: string) => { + if (itemId === 'WL-BAD') throw new Error('wl exploded'); + return { id: itemId, stage: 'intake_complete' }; + }), + closePane, + }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ checked: 2, logged: 1, closed: 1, errors: 1 }); + expect(closePane).toHaveBeenCalledTimes(1); + expect(closePane).toHaveBeenCalledWith('w1:pB', root, { itemId: 'WL-GOOD', kind: 'intake' }); + }); + + it('is a no-op when the item-state dep is absent (legacy callers)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-10', kind: 'plan', paneId: 'w1:p10', stage: 'intake_complete' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = makeDeps({ closePane }); + + const res = await monitorDispatchedPanes(deps, root); + + expect(res).toMatchObject({ checked: 0, logged: 0, closed: 0, errors: 0 }); + expect(closePane).not.toHaveBeenCalled(); + }); + + it('logs requires-attention for an item awaiting producer review (AC3)', async () => { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-11', kind: 'plan', paneId: 'w1:p11', stage: 'intake_complete' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ + id: 'WL-11', stage: 'intake_complete', needsProducerReview: true, + }), + closePane, + }); + + await monitorDispatchedPanes(deps, root); + + expect(closePane).toHaveBeenCalledWith('w1:p11', root, { itemId: 'WL-11', kind: 'plan' }); + expect((await paneCloseEntries(root))[0]).toMatchObject({ + outcome: 'requires-attention', + reasonCode: 'producer-review', + closed: true, + }); + }); + + // ── Warn-level observability (WL-0MU4USJ07009JYL8 AC2/AC6) ────────── + // Every fail-closed catch must emit a stderr warn (never silent) so a + // production failure is diagnosable without a debugger. + function stderrMessages(spy: ReturnType): string { + return spy.mock.calls.map((c) => String(c[0])).join('\n'); + } + + it('warns on a failed pane close (AC2)', async () => { + const spy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + try { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-W1', kind: 'intake', paneId: 'w1:pW1' }); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-W1', stage: 'intake_complete' }), + closePane: vi.fn().mockRejectedValue(new Error('herdr: boom')), + }); + await monitorDispatchedPanes(deps, root); + expect(stderrMessages(spy)).toContain('pane close failed for w1:pW1'); + } finally { + spy.mockRestore(); + } + }); + + it('warns on a failed item lookup (AC2)', async () => { + const spy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + try { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-W2', kind: 'plan', paneId: 'w1:pW2' }); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockRejectedValue(new Error('wl exploded')), + }); + await monitorDispatchedPanes(deps, root); + expect(stderrMessages(spy)).toContain('item lookup failed for WL-W2'); + } finally { + spy.mockRestore(); + } + }); + + it('warns on a failed pane-close log write (AC2)', async () => { + const spy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + try { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-W3', kind: 'plan', paneId: 'w1:pW3' }); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-W3', stage: 'plan_complete' }), + closePane: vi.fn().mockResolvedValue(true), + recordPaneClose: vi.fn().mockRejectedValue(new Error('disk full')), + }); + const res = await monitorDispatchedPanes(deps, root); + expect(res).toMatchObject({ logged: 0, errors: 1 }); + expect(stderrMessages(spy)).toContain('pane-close log write failed for w1:pW3'); + } finally { + spy.mockRestore(); + } + }); + + it('warns when the live-pane query fails (AC2) and still fails open', async () => { + const spy = vi.spyOn(process.stderr, 'write').mockImplementation(() => true); + try { + const root = makeRoot(); + await seedDispatch(root, { itemId: 'WL-W4', kind: 'plan', paneId: 'w1:pW4' }); + const closePane = vi.fn().mockResolvedValue(true); + const deps = monitorDeps({ + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-W4', stage: 'plan_complete' }), + getRunningDowntimePanes: vi.fn().mockRejectedValue(new Error('herdr down')), + closePane, + }); + const res = await monitorDispatchedPanes(deps, root); + // The terminal-stage close still happens (liveness is only needed for + // agent-done detection) — fail-open, not fail-closed, on liveness. + expect(res).toMatchObject({ logged: 1, closed: 1 }); + expect(stderrMessages(spy)).toContain('live-pane query threw'); + } finally { + spy.mockRestore(); + } + }); +}); + +// ── Worker tick ↔ pane-lifecycle integration (WL-0MU4US5MP001JFEN) ──── +// +// The worker tick invokes the pane-lifecycle monitor (fire-and-forget, so it +// never perturbs the dispatch single-flight ordering). These tests pin the +// end-to-end auto-close path and the mandatory implement exception (AC6). +describe('worker tick pane-lifecycle integration (WL-0MU4US5MP001JFEN)', () => { + const roots: string[] = []; + + afterEach(() => { + for (const root of roots.splice(0)) rmSync(root, { recursive: true, force: true }); + }); + + function makeRoot(): string { + const root = mkdtempSync(join(tmpdir(), 'pane-monitor-tick-')); + roots.push(root); + return root; + } + + async function seedDispatch(root: string, itemId: string, kind: string, paneId: string): Promise { + const marker = { + itemId, kind, dispatchedAt: new Date().toISOString(), cwd: root, title: itemId, stage: 'intake_complete', + }; + await appendDowntimeLogEntry(root, JSON.stringify(marker)); + await appendDowntimeLogEntry(root, JSON.stringify({ ...marker, paneId, enrichment: true })); + } + + function makeMonitorWorker(root: string, deps: Partial) { + const fetcher = vi.fn().mockResolvedValue(jsonResponseFixture(idleAllSlotsFree)); + const poller = createDowntimePoller('http://proxy:8000', fetcher); + const worker = createDowntimeWorker({ + poller, + deps: makeDeps({ getNextItem: vi.fn().mockResolvedValue({ ok: true, candidate: null }), ...deps }), + config: () => ({ + enabled: true, + thresholdMs: 1, + requiredFreeSlots: 0, + model: 'plan', + cwd: root, + noCandidateCooldownMs: 3_600_000, + paneLifecycleIntervalMs: 0, + }), + }); + return worker; + } + + it('closes a completed non-implement pane from the worker tick (AC1/AC2)', async () => { + const root = makeRoot(); + await seedDispatch(root, 'WL-TICK', 'plan', 'w9:p1'); + const closePane = vi.fn().mockResolvedValue(true); + const worker = makeMonitorWorker(root, { + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-TICK', stage: 'plan_complete' }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ ok: true, count: 1, records: [{ paneId: 'w9:p1' }] }), + closePane, + }); + + await worker.tick(); + + await vi.waitFor(() => expect(closePane).toHaveBeenCalledWith( + 'w9:p1', root, { itemId: 'WL-TICK', kind: 'plan' }, + )); + const pc = (await readDowntimeLogEntries(root)).filter((e) => e.entryType === 'pane-close'); + expect(pc).toHaveLength(1); + expect(pc[0]).toMatchObject({ outcome: 'closed-as-plan-complete', closed: true }); + }); + + it('never auto-closes an implement pane from the worker tick (AC6)', async () => { + const root = makeRoot(); + await seedDispatch(root, 'WL-IMPL', 'implement', 'w9:p2'); + const closePane = vi.fn().mockResolvedValue(true); + const worker = makeMonitorWorker(root, { + getItemLifecycleState: vi.fn().mockResolvedValue({ id: 'WL-IMPL', stage: 'in_review' }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ ok: true, count: 1, records: [{ paneId: 'w9:p2' }] }), + closePane, + }); + + await worker.tick(); + + // Wait for the (fire-and-forget) monitor to record the in_review event. + await vi.waitFor(async () => { + const pc = (await readDowntimeLogEntries(root)).filter((e) => e.entryType === 'pane-close'); + expect(pc).toHaveLength(1); + }); + expect(closePane).not.toHaveBeenCalled(); + const pc = (await readDowntimeLogEntries(root)).filter((e) => e.entryType === 'pane-close'); + expect(pc[0]).toMatchObject({ outcome: 'requires-attention', reasonCode: 'reached-in-review', closed: false }); + }); +}); + +// ── No-dispatch decision log + header (WL-0MU8808ZY0091JIA) ────────── + +describe('downtime no-dispatch decision log (WL-0MU8808ZY0091JIA)', () => { + function makeDecisionWorker(opts: { + status: LlamaStatus; + root: string; + requiredFreeSlots?: number; + thresholdMs?: number; + runningPanes?: () => { ok: true; count: number } | { ok: false; error?: string }; + recordDecision?: (entry: CoordinationLogEntry, cwd: string) => Promise; + }) { + const cfg = { + enabled: true, + thresholdMs: opts.thresholdMs ?? 0, + requiredFreeSlots: opts.requiredFreeSlots ?? 0, + model: 'plan', + cwd: opts.root, + noCandidateCooldownMs: 3_600_000, + browseItemCount: 20, + }; + const poller = createDowntimePoller( + 'http://proxy:8000', + vi.fn().mockResolvedValue(jsonResponseFixture(opts.status)), + ); + const deps = makeDeps({ + getNextItem: vi.fn().mockResolvedValue({ ok: true, candidate: null }), + getRunningDowntimePanes: vi + .fn() + .mockImplementation(async () => (opts.runningPanes ?? (() => ({ ok: true, count: 0 })))()), + ...(opts.recordDecision ? { recordDecision: opts.recordDecision } : {}), + }); + const worker = createDowntimeWorker({ poller, deps, config: () => ({ ...cfg }) }); + return { worker, deps }; + } + + it('maps internal reasons to stable header tokens', () => { + expect(decisionHeaderToken('slot-owned')).toBe('slot-owner'); + expect(decisionHeaderToken('proxy-contention')).toBe('contention'); + expect(decisionHeaderToken('review-queue-hold')).toBe('review-queue'); + expect(decisionHeaderToken('code-freeze')).toBe('code-freeze'); + }); + + it('AC1: a slot-owned refusal writes one decision line with reason + slot/owner fields', async () => { + const root = mkdtempSync(join(tmpdir(), 'herdr-decision-slot-')); + try { + // Count-based (no `slots`), idle (local_lease_active=false) but the + // global owner session id is present and a downtime pane is alive → + // slotOwned. + const status: LlamaStatus = { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 1, + total_slots: 1, + local_owner_session_id: 'session-live-pane', + contention_queue_depth: 0, + contention_queued_count: 0, + }; + const { worker } = makeDecisionWorker({ + status, + root, + runningPanes: () => ({ ok: true, count: 1 }), + }); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(false); + expect(worker.blockReason).toBe('slot-owner'); + await vi.waitFor(async () => { + const entries = (await readCoordinationLogEntries(root)).filter( + (e) => e.kind === 'decision', + ); + expect(entries).toHaveLength(1); + expect(entries[0]).toMatchObject({ + kind: 'decision', + operation: 'no-dispatch', + reason: 'slot-owned', + freeSlots: 1, + totalSlots: 1, + ownerPresent: true, + runningPanes: 1, + contentionDepth: 0, + }); + expect(typeof entries[0].at).toBe('string'); + }); + } finally { + rmSync(root, { recursive: true, force: true }); + } + }); + + it('AC2: a contention refusal writes the reason and the observed depth', async () => { + const root = mkdtempSync(join(tmpdir(), 'herdr-decision-contention-')); + try { + const status: LlamaStatus = { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 1, + total_slots: 1, + contention_queue_depth: 3, + contention_queued_count: 3, + }; + const { worker } = makeDecisionWorker({ status, root }); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(false); + expect(worker.blockReason).toBe('contention'); + await vi.waitFor(async () => { + const entries = (await readCoordinationLogEntries(root)).filter( + (e) => e.kind === 'decision', + ); + expect(entries).toHaveLength(1); + expect(entries[0]).toMatchObject({ + reason: 'proxy-contention', + contentionDepth: 3, + ownerPresent: false, + }); + }); + } finally { + rmSync(root, { recursive: true, force: true }); + } + }); + + it('AC3: repeated identical refusals are rate-limited, then logged again after the window', async () => { + const root = mkdtempSync(join(tmpdir(), 'herdr-decision-rate-')); + vi.useFakeTimers(); + try { + const status: LlamaStatus = { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 1, + total_slots: 1, + contention_queue_depth: 3, + contention_queued_count: 3, + }; + const recordDecision = vi.fn().mockResolvedValue(undefined); + const { worker } = makeDecisionWorker({ status, root, recordDecision }); + const start = 1_000_000; + vi.setSystemTime(start); + await worker.tick(); // first refusal → logged + expect(recordDecision).toHaveBeenCalledTimes(1); + vi.setSystemTime(start + 60_000); // 1 min later, same reason → suppressed + await worker.tick(); + expect(recordDecision).toHaveBeenCalledTimes(1); + // Past the rate-limit window → logged again (≤ 6 identical lines/hour). + vi.setSystemTime(start + DOWNTIME_DECISION_LOG_MIN_INTERVAL_MS + 1); + await worker.tick(); + expect(recordDecision).toHaveBeenCalledTimes(2); + } finally { + vi.useRealTimers(); + rmSync(root, { recursive: true, force: true }); + } + }); +}); + +// ── Local dispatch-lease TTL + own-pane leases (WL-0MU8809SZ0022VZG) ── + +describe('local dispatch-lease TTL + own-pane leases (WL-0MU8809SZ0022VZG)', () => { + function makeLeaseWorker(opts: { + status: LlamaStatus; + requiredFreeSlots: number; + thresholdMs?: number; + runningPanes: number; + }) { + const cfg = { + enabled: true, + thresholdMs: opts.thresholdMs ?? 0, + requiredFreeSlots: opts.requiredFreeSlots, + model: 'plan', + cwd: '/repo', + noCandidateCooldownMs: 3_600_000, + browseItemCount: 20, + }; + const poller = createDowntimePoller( + 'http://proxy:8000', + vi.fn().mockResolvedValue(jsonResponseFixture(opts.status)), + ); + const deps = makeDeps({ + getNextItem: vi.fn().mockResolvedValue({ + ok: true, + candidate: { id: 'WL-ABC', title: 'Some task', stage: 'intake_complete' }, + }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ + ok: true, + count: opts.runningPanes, + paneIds: [], + records: [], + }), + }); + const worker = createDowntimeWorker({ poller, deps, config: () => ({ ...cfg }) }); + return { worker, deps }; + } + + it('AC1: pins the proxy adaptive lease maximum (llm-manager default 1500 s)', () => { + // The proxy lease is adaptive and capped at local_dispatch_lease_max_seconds + // (default 1500 s) — NOT the historical ~180 s the code used to assume. + expect(LOCAL_DISPATCH_LEASE_MAX_SECONDS).toBe(1500); + }); + + it('AC1/AC3: a max-TTL unknown/operator lease on a count-based single slot still refuses dispatch', async () => { + // The dispatcher must not optimistically assume the lease expired: a lease + // at the proxy MAX on a count-based single-slot setup (an unknown/operator + // owner) keeps blocking while a downtime pane is alive. local_lease_active + // is false so the idle gate passes and the slot-owned gate is the blocker. + const status: LlamaStatus = { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 1, + total_slots: 1, + local_owner_session_id: 'operator-session', + local_owner_lease_remaining_seconds: LOCAL_DISPATCH_LEASE_MAX_SECONDS, + contention_queue_depth: 0, + contention_queued_count: 0, + }; + const { worker, deps } = makeLeaseWorker({ + status, + requiredFreeSlots: 0, + runningPanes: 1, + }); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(false); + expect(worker.blockReason).toBe('slot-owner'); + expect(deps.spawnAgentPane).not.toHaveBeenCalled(); + }); + + it('AC2: a max-TTL lease held by a dispatched pane does not block the free unowned slots (per-slot)', async () => { + // Self-blocking case (RCA WL-0MU87ZGPP0029V28): the dispatched pane owns + // slot-1; slots 2 and 3 are free and unowned. Even with the lease at the + // proxy MAX and the worker's own pane alive, dispatch into the free slots + // MUST proceed — the per-slot gate ignores the global lease when unowned + // slots remain. + vi.useFakeTimers(); + try { + const ownSession = 'dispatched-pane-session'; + const status: LlamaStatus = { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: true, + available_slots: 2, + total_slots: 3, + local_owner_session_id: ['http://localhost:8080', ownSession], + local_owner_session_ids: [ownSession], + local_owner_lease_remaining_seconds: LOCAL_DISPATCH_LEASE_MAX_SECONDS, + slots: [ + { slot_id: 'slot-1', is_processing: true, owner_session_id: ownSession }, + { slot_id: 'slot-2', is_processing: false }, + { slot_id: 'slot-3', is_processing: false }, + ], + contention_queue_depth: 0, + contention_queued_count: 0, + }; + const { worker, deps } = makeLeaseWorker({ + status, + requiredFreeSlots: 2, + thresholdMs: 1_000, + runningPanes: 1, + }); + const start = 1_000_000; + vi.setSystemTime(start); + await worker.tick(); // baseline — start the per-slot idle timers + vi.setSystemTime(start + 5_000); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(true); + expect(deps.spawnAgentPane).toHaveBeenCalledTimes(1); + } finally { + vi.useRealTimers(); + } + }); +}); + +// ── Stale/empty slots fallback + count-based spare capacity ─────────── +// (WL-0MUFP30T2003OX1F) + +describe('stale/empty slots fallback + count-based spare capacity (WL-0MUFP30T2003OX1F)', () => { + function makeRaw(overrides: Record = {}): Record { + return { + llama_server_running: true, + active_query: true, + local_active_query: true, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 1, + total_slots: 3, + slots: [], + slots_stale: true, + local_owner_session_id: ['http://localhost:8080', 'audit-pane-session'], + local_owner_lease_remaining_seconds: 645.5, + contention_queue_depth: 0, + contention_queued_count: 0, + ...overrides, + }; + } + + function makeStaleWorker(opts: { + status: LlamaStatus; + requiredFreeSlots: number; + thresholdMs?: number; + runningPanes: number; + }) { + const cfg = { + enabled: true, + thresholdMs: opts.thresholdMs ?? 0, + requiredFreeSlots: opts.requiredFreeSlots, + model: 'plan', + cwd: '/repo', + noCandidateCooldownMs: 3_600_000, + browseItemCount: 20, + }; + const poller = createDowntimePoller( + 'http://proxy:8000', + vi.fn().mockResolvedValue(jsonResponseFixture(opts.status)), + ); + const deps = makeDeps({ + getNextItem: vi.fn().mockResolvedValue({ + ok: true, + candidate: { id: 'WL-ABC', title: 'Some task', stage: 'intake_complete' }, + }), + getRunningDowntimePanes: vi.fn().mockResolvedValue({ + ok: true, + count: opts.runningPanes, + paneIds: [], + records: [], + }), + }); + const worker = createDowntimeWorker({ poller, deps, config: () => ({ ...cfg }) }); + return { worker, deps }; + } + + it('AC4: parses slots_stale and preserves the empty slots array', () => { + const status = parseLlamaStatus(makeRaw()); + expect(status).not.toBeNull(); + expect(status!.slots).toEqual([]); + expect(status!.slots_stale).toBe(true); + // The array owner form still normalises (child WL-0MU88086A0089US4). + expect(status!.local_owner_session_ids).toEqual(['audit-pane-session']); + expect(status!.local_owner_session_id).toBe('audit-pane-session'); + }); + + it('AC4: a malformed slots_stale fails closed (null)', () => { + expect(parseLlamaStatus(makeRaw({ slots_stale: 'yes' }))).toBeNull(); + expect(parseLlamaStatus(makeRaw({ slots_stale: 1 }))).toBeNull(); + }); + + it('AC4: empty/stale slots are NOT per-slot identity — evaluateIdle falls back to the count', () => { + // Active local query → the leased slot is processing, not reserved → 2 free >= N=2. + const active = parseLlamaStatus(makeRaw({ available_slots: 2 }))!; + expect(evaluateIdle(active, 2)).toBe(true); + // Idle-but-leased (no active query) → reserve the leased slot → 1 < 2. + const idleLease = parseLlamaStatus( + makeRaw({ available_slots: 2, local_active_query: false, active_query: false }), + )!; + expect(evaluateIdle(idleLease, 2)).toBe(false); + }); + + it('AC1: live payload (stale/empty slots, lease, live pane) dispatches into the free slot', async () => { + vi.useFakeTimers(); + try { + // The exact live shape: total=3, available=1, slots:[], slots_stale:true, + // an owner lease held by a dispatched pane. N=1 (single-pane dispatch). + const status: LlamaStatus = { + llama_server_running: true, + active_query: true, + local_active_query: true, + model_switch_in_progress: false, + local_lease_active: true, + available_slots: 1, + total_slots: 3, + slots: [], + slots_stale: true, + local_owner_session_id: 'audit-pane-session', + local_owner_session_ids: ['audit-pane-session'], + local_owner_lease_remaining_seconds: 645.5, + contention_queue_depth: 0, + contention_queued_count: 0, + }; + const { worker, deps } = makeStaleWorker({ + status, + requiredFreeSlots: 1, + thresholdMs: 1_000, + runningPanes: 1, + }); + const start = 1_000_000; + vi.setSystemTime(start); + await worker.tick(); // baseline + vi.setSystemTime(start + 5_000); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(true); + expect(deps.spawnAgentPane).toHaveBeenCalledTimes(1); + } finally { + vi.useRealTimers(); + } + }); + + it('AC2: count-based multi-slot with spare capacity and a held lease dispatches', async () => { + vi.useFakeTimers(); + try { + // 3 slots, 2 free, N=2, an active local query holding the lease: the RCA + // window shape. The machine-wide lease must not block the spare capacity. + const status: LlamaStatus = { + llama_server_running: true, + active_query: true, + local_active_query: true, + model_switch_in_progress: false, + local_lease_active: true, + available_slots: 2, + total_slots: 3, + local_owner_session_id: 'dispatched-pane-session', + local_owner_session_ids: ['dispatched-pane-session'], + local_owner_lease_remaining_seconds: 840, + contention_queue_depth: 0, + contention_queued_count: 0, + }; + const { worker, deps } = makeStaleWorker({ + status, + requiredFreeSlots: 2, + thresholdMs: 1_000, + runningPanes: 1, + }); + const start = 2_000_000; + vi.setSystemTime(start); + await worker.tick(); + vi.setSystemTime(start + 5_000); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(true); + expect(deps.spawnAgentPane).toHaveBeenCalledTimes(1); + } finally { + vi.useRealTimers(); + } + }); + + it('AC3: count-based single-slot with a held lease still refuses', async () => { + const status: LlamaStatus = { + llama_server_running: true, + active_query: false, + local_active_query: false, + model_switch_in_progress: false, + local_lease_active: false, + available_slots: 1, + total_slots: 1, + local_owner_session_id: 'operator-session', + local_owner_session_ids: ['operator-session'], + contention_queue_depth: 0, + contention_queued_count: 0, + }; + const { worker, deps } = makeStaleWorker({ + status, + requiredFreeSlots: 1, + runningPanes: 1, + }); + const outcome = await worker.tick(); + expect(outcome.dispatched).toBe(false); + expect(worker.blockReason).toBe('slot-owner'); + expect(deps.spawnAgentPane).not.toHaveBeenCalled(); + }); +}); diff --git a/packages/herdr/src/downtime-worker.ts b/packages/herdr/src/downtime-worker.ts index 2357a3b10..4aea01702 100644 --- a/packages/herdr/src/downtime-worker.ts +++ b/packages/herdr/src/downtime-worker.ts @@ -141,13 +141,24 @@ import { cleanupStaleElection, DEFAULT_LEASE_TTL_SECONDS, } from './leader-election.js'; -import { appendCoordinationLogEntry } from './downtime-log.js'; +import { appendCoordinationLogEntry, type CoordinationLogEntry } from './downtime-log.js'; import { readDowntimeLogEntries as _readDowntimeEntries, dispatchedItemMarkers as _dispatchedMarkers, markerStillExcludes as _markerStillExcludes, + appendPaneCloseLogEntry as _appendPaneCloseLogEntry, type DispatchMarker, + type PaneCloseLogEntry, + type PaneLifecycleKind, } from './downtime-log.js'; +import { + classifyPaneLifecycle, + collectDispatchedPanes, + loggedPaneLifecycleKeys, + paneLifecycleKey, + type DispatchedPane, + type PaneItemState, +} from './pane-lifecycle.js'; import { buildDowntimePaneTitle, MAX_PANE_TITLE_LENGTH } from './pane-title.js'; import type { DispatcherAnchor, DispatcherTabAnchorEntry } from './dispatcher-anchor.js'; @@ -201,6 +212,34 @@ export const DOWNTIME_AUDIT_MIN_FREE_SLOTS = 2; */ export const DOWNTIME_PANE_MIN_FREE_SLOTS = 1; +/** + * Minimum interval between identical no-dispatch decision-log entries + * (WL-0MU8808ZY0091JIA AC3): a healthy idle/gate-blocked loop must not flood + * `.worklog/downtime-coordination.log`. A repeated refusal with the SAME + * reason is suppressed until this window elapses; a reason CHANGE is always + * logged immediately. 10 minutes → at most 6 identical lines per hour. + */ +export const DOWNTIME_DECISION_LOG_MIN_INTERVAL_MS = 10 * 60_000; + +/** + * Short, stable header token for a no-dispatch reason (WL-0MU8808ZY0091JIA + * AC4). Distinct from the plain idle/busy labels so "idle slots but no + * dispatches" is visible in the herdr header. The RAW reason is what gets + * logged; only the header label is abbreviated. + */ +export function decisionHeaderToken(reason: string): string { + switch (reason) { + case 'slot-owned': + return 'slot-owner'; + case 'proxy-contention': + return 'contention'; + case 'review-queue-hold': + return 'review-queue'; + default: + return reason; + } +} + /** Sane floor for the no-candidate cooldown (the pause cannot be disabled or set trivially small). */ export const DOWNTIME_NO_CANDIDATE_COOLDOWN_FLOOR_MS = 60_000; @@ -271,6 +310,15 @@ export const DOWNTIME_AUDIT_STALE_WINDOW_MS = 2 * 60 * 60 * 1000; // 2 hours */ export const DEFAULT_DOWNTIME_MARKER_STALE_WINDOW_MS = 24 * 60 * 60 * 1000; +/** + * Pane-lifecycle monitor cadence (WL-0MU308WSF0002JWN): the worker re-checks + * dispatched panes for terminal states at most once per this interval, + * bounding the per-tick worklog queries ("reasonable polling cadence" — + * parent Constraint) while still closing completed panes promptly. Overridable + * per tick via the optional `paneLifecycleIntervalMs` config field. + */ +export const DOWNTIME_PANE_LIFECYCLE_INTERVAL_MS = 30_000; + /** * Hard floor for the success-marker staleness window (1 h): below this the * age release would fire while a dispatched pane is plausibly still running, @@ -378,6 +426,26 @@ export const DEFAULT_COORDINATION_CHECK_IN_MS = 5 * 60 * 1000; */ export const DEFAULT_LEADER_CHECK_IN_MS = 4 * 60 * 1000; +/** + * Maximum local DISPATCH-lease TTL (seconds) the llama-proxy can hold a + * local slot — the cross-repo contract from `llm-manager` + * (`proxy/proxy/router_helpers.py`, WL-0MU8809SZ0022VZG). + * + * The lease is ADAPTIVE, not a fixed ~180 s: a static base plus + * generation-proportional extension, capped at + * `local_dispatch_lease_max_seconds` (default 1500 s), with chunk/prefill + * refresh buffers that keep it alive while a stream is active. A long agent + * generation therefore holds the lease for its WHOLE run — the RCA observed a + * dispatched-pane lease run 836 s → 0 (WL-0MU87ZGPP0029V28). + * + * The dispatcher MUST NOT assume leases expire after ~180 s. It does not WAIT + * OUT a lease: it dispatches into genuinely free UNOWNED slots (the per-slot + * gate, WL-0MU8807BI008C9ME) and only the count-based single-slot path treats + * a held lease as blocking. If `llm-manager` changes the default, revisit + * this constant and `docs/dev/downtime-dispatcher.md`. + */ +export const LOCAL_DISPATCH_LEASE_MAX_SECONDS = 1500; + /** * Retired coordination tier ordering (parent AC4 → WL-0MTK1ILM2009QYB2). * The coordination leader no longer re-ranks offers by tier: it dispatches @@ -421,6 +489,15 @@ export interface LlamaStatus { total_slots: number; current_model?: string; local_owner_session_id?: string | null; + /** + * Every owner session id reported by the proxy, normalised across the + * legacy string form and the current array form (WL-0MU88086A0089US4): + * array elements that are HTTP(S) URLs (the proxy's own base URL, e.g. + * `"http://localhost:8080"`) are excluded, and a legacy string yields a + * single-element array. Empty when no owner is reported. Kept alongside + * `local_owner_session_id` (the first id) for backward compatibility. + */ + local_owner_session_ids?: string[]; local_owner_lease_remaining_seconds?: number | null; /** * Proxy-reported LIVE contention queue depth (AC6, parent @@ -441,12 +518,23 @@ export interface LlamaStatus { * pre-feature proxies. */ contention_queued_count?: number; + /** + * Proxy degradation flag (LP-0MSVP7XJ6008QPKX, consumed by + * WL-0MUFP30T2003OX1F): `true` when the served slot COUNTS came from the + * proxy's last-known cache because the fresh `/slots` query failed. When + * true the per-slot `slots` detail cannot be trusted/paired with the + * counts, so the worker must fall back to the count-based path. ABSENT on + * pre-feature proxies (treated as not stale). + */ + slots_stale?: boolean; /** * Per-slot identity (LP-0MSG5TA7Y002GN39): served by proxies that expose * slot-level detail. ABSENT on pre-feature proxies — the worker then * falls back to the count-based all-slots-free logic. When present, the * downtime worker tracks idle duration PER SLOT ID so a configured N - * requires the SAME N slots continuously free. + * requires the SAME N slots continuously free. An EMPTY array means "no + * per-slot detail available" (WL-0MUFP30T2003OX1F) — never "zero free + * slots" — and likewise falls back to the count-based path. */ slots?: LlamaSlot[]; } @@ -539,6 +627,90 @@ export function countFreeUnownedSlots(slots: LlamaSlot[]): number { return count; } +/** + * Usable per-slot identity (WL-0MUFP30T2003OX1F): the `slots` array is only + * trustworthy when it is NON-EMPTY and NOT flagged stale by the proxy. An + * empty array (`slots: []`) means "no per-slot detail available" — NOT "zero + * free slots" — and `slots_stale: true` means the counts came from the + * proxy's last-known cache after a failed /slots query, so the detail cannot + * be paired with them. In both cases the worker must fall back to the + * count-based path; `null` is that signal. + */ +function usablePerSlotSlots(status: LlamaStatus): LlamaSlot[] | null { + if (!Array.isArray(status.slots)) return null; + if (status.slots.length === 0) return null; + if (status.slots_stale === true) return null; + return status.slots; +} + +/** + * Number of local dispatch leases the proxy reports (WL-0MUFP30T2003OX1F): + * the normalised `local_owner_session_ids` list when present, else the legacy + * single `local_owner_session_id` string, else 1 when only a positive lease + * TTL is served. Used both for the owner-lease qualifier and to reserve + * possibly-idle leased slots when the worker only has count-based data. + */ +function ownerLeaseCount(status: LlamaStatus): number { + if (Array.isArray(status.local_owner_session_ids)) { + return status.local_owner_session_ids.length; + } + if ( + typeof status.local_owner_session_id === 'string' && + status.local_owner_session_id.length > 0 + ) { + return 1; + } + if ( + typeof status.local_owner_lease_remaining_seconds === 'number' && + Number.isFinite(status.local_owner_lease_remaining_seconds) && + status.local_owner_lease_remaining_seconds > 0 + ) { + return 1; + } + return 0; +} + +/** + * Slots to reserve for a held lease in the count-based path + * (WL-0MUFP30T2003OX1F). While the lease owner is actively generating + * (`local_active_query === true`) its slot is processing and already excluded + * from `available_slots`, so nothing is reserved; otherwise the owner may be + * idle-but-leased, and one slot per lease is reserved so an idle leased slot + * counted as "available" is never dispatched onto. + */ +function leaseReserve(status: LlamaStatus): number { + return status.local_active_query === true ? 0 : ownerLeaseCount(status); +} + +/** + * Genuinely-free slot count for the count-based path + * (WL-0MUFP30T2003OX1F): the proxy's `available_slots` minus any reserved + * lease slots (never negative). + */ +function countBasedFreeSlots(status: LlamaStatus): number { + const available = Number.isFinite(status.available_slots) ? status.available_slots : 0; + return Math.max(0, available - leaseReserve(status)); +} + +/** + * Count-based spare-capacity decision (WL-0MUFP30T2003OX1F): with a + * multi-slot config (0 < N < total) but NO usable per-slot identity, the + * proxy's `available_slots` count is the only availability signal. A held + * local lease must not block dispatch into the spare slots, so this mirrors + * the per-slot spare-capacity relaxation using the count (after reserving + * possibly-idle leased slots). Fail-closed on ambiguous/missing fields. + */ +function countBasedSpareCapacity(status: LlamaStatus, requiredFreeSlots: number): boolean { + const total = status.total_slots; + const available = status.available_slots; + if (!status.llama_server_running) return false; + if (status.model_switch_in_progress) return false; + if (!Number.isFinite(total) || total <= 0) return false; + if (!Number.isFinite(available) || available < 0) return false; + if (requiredFreeSlots <= 0 || requiredFreeSlots >= total) return false; + return countBasedFreeSlots(status) >= requiredFreeSlots; +} + /** * True when the proxy reports an idle state for the required free-slot * count: @@ -583,16 +755,23 @@ export function isIdleStatus(status: LlamaStatus, requiredFreeSlots: number): bo * the global gate is the per-slot-safe subset (server up + no model switch * only) — a query/lease tied to a busy slot is the operator's own session * and must not block dispatch into the free slots (F1 tests AC1/AC2). + * + * Count-based spare-capacity (WL-0MUFP30T2003OX1F): when per-slot identity is + * unusable (stale/empty `slots`) but 0 < N < total AND a local lease is held, + * the same relaxation applies to the proxy's `available_slots` count (after + * reserving possibly-idle leased slots) instead of stalling for the whole + * lease. */ export function evaluateIdle(status: LlamaStatus, requiredFreeSlots: number): boolean { const total = status.total_slots; if (!Number.isFinite(total) || total <= 0) return false; // ambiguous → busy - // Per-slot mode: per-slot identity present AND 0 < N < total. The relaxed - // global gate applies (server up + no model switch); the slot requirement - // is the per-slot free count. + // Per-slot mode: usable per-slot identity present AND 0 < N < total. The + // relaxed global gate applies (server up + no model switch); the slot + // requirement is the per-slot free count. + const perSlotSlots = usablePerSlotSlots(status); if ( - Array.isArray(status.slots) && + perSlotSlots !== null && requiredFreeSlots > 0 && requiredFreeSlots < total ) { @@ -600,10 +779,22 @@ export function evaluateIdle(status: LlamaStatus, requiredFreeSlots: number): bo // Fail-closed counting: an entry without an explicit boolean // `is_processing` is treated as processing (busy), never free. Owned // slots (live lease) are excluded (AC5, WL-0MTYZXSLN008HZOW). - const free = countFreeUnownedSlots(status.slots); + const free = countFreeUnownedSlots(perSlotSlots); return free >= requiredFreeSlots; } + // Count-based spare-capacity (WL-0MUFP30T2003OX1F): multi-slot config with + // 0 < N < total but no usable per-slot identity, and a held lease. The + // strict all-slots-free fallback below would stall for the whole (adaptive) + // lease; the proxy's count says the capacity is real. + if ( + ownerLeaseCount(status) > 0 && + requiredFreeSlots > 0 && + requiredFreeSlots < total + ) { + return countBasedSpareCapacity(status, requiredFreeSlots); + } + const effective = requiredFreeSlots > 0 && requiredFreeSlots < total ? total : requiredFreeSlots; @@ -733,23 +924,47 @@ export const DEFAULT_DOWNTIME_POLL_TIMEOUT_MS = 5_000; * malformed/negative (ambiguous → the caller fails closed to busy). */ /** - * Extract the owner session ID from `local_owner_session_id`, accepting both - * the legacy string form and the current array form + * True for an HTTP(S) URL element of the proxy's owner array. The live proxy + * serves `local_owner_session_id` as `["http://localhost:8080", ""]` + * where the first element is its own base URL, NOT an owner session. + */ +function isOwnerUrlElement(value: string): boolean { + return /^https?:\/\//i.test(value); +} + +/** + * Normalise `local_owner_session_id` into the FULL list of owner session ids, + * accepting both the legacy string form and the current array form * `["http://localhost:8080", "herdr-"]`. * - * Returns the session string (2nd element of the array) for array inputs, - * the string itself for string inputs, and `undefined` for any malformed - * input (number, object, empty array, etc.) — fail-closed. + * Array elements that are HTTP(S) URLs (the proxy's own base URL) are not + * owners and are dropped; every non-empty non-URL string element is retained + * so a multi-owner payload is never silently truncated (contributing cause 1 + * of RCA WL-0MU87ZGPP0029V28). A legacy string yields a single-element array. + * Malformed input (number, object, `null`, array of non-strings) yields `[]` + * — fail-closed, never throws. * * (WL-0MU88086A0089US4 — parse array local_owner_session_id from llama-proxy) */ -function parseLocalOwnerSessionId(value: unknown): string | undefined { - if (typeof value === 'string' && value.length > 0) return value; - if (Array.isArray(value) && value.length >= 2) { - const session = value[1]; - if (typeof session === 'string' && session.length > 0) return session; +function parseLocalOwnerSessionIds(value: unknown): string[] { + if (typeof value === 'string' && value.length > 0) return [value]; + if (Array.isArray(value)) { + return value.filter( + (el): el is string => + typeof el === 'string' && el.length > 0 && !isOwnerUrlElement(el), + ); } - return undefined; + return []; +} + +/** + * The first (primary) owner session id — kept for compatibility with existing + * call sites (`local_lease_active` derivation, `ownerLeaseHeld`). Returns + * `undefined` when no owner session is reported. See + * {@link parseLocalOwnerSessionIds}. + */ +function parseLocalOwnerSessionId(value: unknown): string | undefined { + return parseLocalOwnerSessionIds(value)[0]; } function parseOptionalCount(value: unknown): number | undefined | null { @@ -798,6 +1013,16 @@ export function parseLlamaStatus(raw: unknown): LlamaStatus | null { (typeof leaseSeconds === 'number' && Number.isFinite(leaseSeconds) && leaseSeconds > 0); } + // Optional degradation flag (LP-0MSVP7XJ6008QPKX): absent on pre-feature + // proxies. A malformed (non-boolean) value is ambiguous → null (busy, + // fail-closed), matching the other optional flags. When true the per-slot + // `slots` detail is unusable (WL-0MUFP30T2003OX1F). + let slotsStale: boolean | undefined; + if (o.slots_stale !== undefined) { + if (typeof o.slots_stale !== 'boolean') return null; + slotsStale = o.slots_stale; + } + // Optional per-slot identity (LP-0MSG5TA7Y002GN39): absent on pre-feature // proxies (slots stays undefined — backward compatible). A malformed // array (non-array, entry missing/empty slot_id, non-boolean @@ -880,6 +1105,8 @@ export function parseLlamaStatus(raw: unknown): LlamaStatus | null { current_model: typeof o.current_model === 'string' ? o.current_model : undefined, local_owner_session_id: parseLocalOwnerSessionId(o.local_owner_session_id), + local_owner_session_ids: + parseLocalOwnerSessionIds(o.local_owner_session_id), local_owner_lease_remaining_seconds: typeof o.local_owner_lease_remaining_seconds === 'number' ? o.local_owner_lease_remaining_seconds @@ -887,6 +1114,7 @@ export function parseLlamaStatus(raw: unknown): LlamaStatus | null { contention_queue_depth: contentionQueueDepth, contention_queued_count: contentionQueuedCount, slots, + slots_stale: slotsStale, }; } @@ -1127,6 +1355,12 @@ export interface DowntimeItemInfo { * coordination leader path skips it (AC3). */ needsProducerReview?: boolean; + /** + * Recorded audit verdict (`auditResult.readyToClose` from `wl show + * --json`, WL-0MU308WSF0002JWN): `false` means the audit FAILED; `true` + * means it passed. Absent when the item has no recorded audit result. + */ + auditResult?: boolean | null; } /** @@ -1325,6 +1559,29 @@ export function paneLabelItemId(label: string | undefined): string | null { return id === '' ? null : id; } +/** + * Safe-close predicate (WL-0MU4US5MP001JFEN AC7): true ONLY when a LIVE herdr + * pane record exists for `paneId`, its label is a downtime pane label + * (`DOWNTIME_PANE_LABEL_PREFIX`) AND its item-id suffix equals `itemId`. + * + * Guarding the close with this predicate means a stale dispatch-log entry can + * never close an unrelated/operator pane whose pane id happens to collide with + * the recorded dispatched pane (pane ids may be reused after a pane closes). + * A missing record (the pane is already gone) returns false — there is nothing + * to close. + */ +export function isSafeDowntimePaneToClose( + records: HerdrPaneRecord[], + paneId: string, + itemId: string, +): boolean { + const rec = records.find((p) => p.paneId === paneId); + if (rec === undefined) return false; + const label = rec.label ?? ''; + if (!label.startsWith(DOWNTIME_PANE_LABEL_PREFIX)) return false; + return paneLabelItemId(label) === itemId; +} + /** * Item ids that currently have a LIVE `working` downtime pane * (WL-0MUBEZ6PE002WLP4, the in-flight guard). @@ -1675,6 +1932,14 @@ export interface DowntimeWorkerDeps { itemTitle?: string; itemId?: string; anchorId?: string; + /** + * Mode-aware Phase 2 parallelism inputs (WL-0MT50S9JW001DHME): the + * worker forwards the genuine free-slot snapshot and mode so the spawn + * boundary can set `AUDIT_PHASE2_PARALLELISM` without reaching back + * into the worker. Absent → the spawn falls back to `'1'` (backward + * compatible). + */ + spawnConfig?: DowntimeSpawnConfig; }, ): Promise; /** @@ -1753,6 +2018,40 @@ export interface DowntimeWorkerDeps { * dispatcher swallows any rejection. */ recordDispatchEnrichment?(event: DowntimeDispatchEnrichmentEvent): Promise; + /** + * Pane-lifecycle item state lookup (WL-0MU308WSF0002JWN): resolve the + * current work-item state (stage/status/risk/effort/auditedAt/auditResult/ + * needsProducerReview) for a dispatched pane's item so the monitor can + * classify its lifecycle outcome. OPTIONAL — when absent the monitor + * cannot classify and takes no action (fail-open; production wiring always + * provides it). Must never throw; resolves null on a wl/CLI failure so a + * lookup failure never triggers a spurious close. + */ + getItemLifecycleState?(itemId: string, cwd: string): Promise; + /** + * Close a dispatched pane (WL-0MU308WSF0002JWN): `herdr pane close + * `. Resolves true on success, false on any failure. OPTIONAL — + * when absent the monitor logs the outcome but performs no close (used by + * legacy/test callers). Must never throw (fail-closed): a failed close is + * logged with `closed:false` and never blocks other panes. + * + * `expected` (optional, WL-0MU4US5MP001JFEN AC7) carries the dispatch + * context so an implementation can verify the live pane really is the + * downtime pane spawned for THIS item before closing it — never close an + * unrelated/operator pane whose id happens to collide with a stale entry. + */ + closePane?( + paneId: string, + cwd: string, + expected?: { itemId: string; kind: PaneLifecycleKind }, + ): Promise; + /** + * Record a pane-close lifecycle entry in the rolling dispatch log + * (WL-0MU308WSF0002JWN). OPTIONAL — when absent the monitor falls back to + * appending directly via `appendPaneCloseLogEntry`. Must never throw + * (fail-closed): logging must never crash the worker. + */ + recordPaneClose?(entry: PaneCloseLogEntry, cwd: string): Promise; /** * Roll back a CAS claim that succeeded but never completed dispatch * (WL-0MT32F908002YFFA AC1/AC2): restore the item to its pre-claim @@ -1780,6 +2079,16 @@ export interface DowntimeWorkerDeps { * Must never throw (fail-closed): logging must not crash the worker. */ recordError(event: DowntimeErrorEvent): Promise; + /** + * Record one no-dispatch DECISION entry (WL-0MU8808ZY0091JIA) — the reason + * a polled tick refused to dispatch (slot-owner / contention / no-candidate + * / review-queue-hold / code-freeze / ...), with the observed slot/owner + * fields. Optional: when absent the worker appends directly to + * `.worklog/downtime-coordination.log` (the production default). Tests + * inject a spy to assert the decision vocabulary and rate-limiting without + * touching the filesystem. Fail-closed: a throw is swallowed. + */ + recordDecision?(entry: CoordinationLogEntry, cwd: string): Promise; } /** Audit event recorded for every successful downtime dispatch. */ @@ -2143,7 +2452,7 @@ export function selectCriticalFirstCandidates( async function dispatchFromHerdrList( deps: DowntimeWorkerDeps, items: DowntimeHerdrItem[], - ctx: { cwd: string; model: string; freeSlots?: number; frozen: boolean; panesEligible: boolean; auditEligible: boolean; reviewGate: ReviewQueueGateResult | null; markerStaleWindowMs: number; inFlight: InFlightPanes }, + ctx: { cwd: string; model: string; freeSlots?: number; frozen: boolean; panesEligible: boolean; auditEligible: boolean; reviewGate: ReviewQueueGateResult | null; markerStaleWindowMs: number; inFlight: InFlightPanes; spawnConfig?: DowntimeSpawnConfig }, flags: { auditInFlight: boolean; auditCheckFailed: boolean; auditCheckError?: string; freshnessSkip: boolean; reviewHeld: boolean }, ): Promise { if (items.length === 0) return null; @@ -2206,6 +2515,7 @@ async function dispatchFromHerdrList( cwd: ctx.cwd, selectionPath: 'critical-first', selectionReason: guard.reason, + spawnConfig: ctx.spawnConfig, }); if (outcome.dispatched) return outcome; // A lost CAS race / marker-recovery rollback applies to one candidate: @@ -2310,6 +2620,7 @@ async function dispatchFromHerdrList( cwd: ctx.cwd, selectionPath: 'normal-scan', selectionReason: item.priority === 'critical' ? 'no-live-pane' : 'non-critical', + spawnConfig: ctx.spawnConfig, }); if (outcome.dispatched) return outcome; if (outcome.reason === 'claim-failed') continue; @@ -2378,7 +2689,14 @@ async function dispatchClaimedTier( deps: DowntimeWorkerDeps, kind: DowntimeSkillKind, candidate: DowntimeCandidate, - opts: { model: string; cwd: string; selectionPath?: string; selectionReason?: string }, + opts: { + model: string; + cwd: string; + selectionPath?: string; + selectionReason?: string; + /** Mode-aware Phase 2 parallelism inputs (WL-0MT50S9JW001DHME). */ + spawnConfig?: DowntimeSpawnConfig; + }, ): Promise { const expected = TIER_EXPECTED[kind]; // Dispatcher anchor (C0 WL-0MTR01EU7005SYZG): resolve the dedicated @@ -2504,6 +2822,10 @@ async function dispatchClaimedTier( // leadership. Only set when the anchor resolved (never a bare // undefined key — legacy callers keep their exact opts shape). ...(anchorId !== undefined ? { anchorId } : {}), + // Mode-aware Phase 2 parallelism (WL-0MT50S9JW001DHME): only set when + // the worker supplied a snapshot (legacy/test callers keep the exact + // historical opts shape and fall back to '1'). + ...(opts.spawnConfig !== undefined ? { spawnConfig: opts.spawnConfig } : {}), }, ); if (!spawn.ok) { @@ -2660,7 +2982,7 @@ async function recordDispatchEnrichmentBestEffort( async function dispatchScheduledPrompt( deps: DowntimeWorkerDeps, prompt: ScheduledPrompt, - opts: { model: string; cwd: string }, + opts: { model: string; cwd: string; spawnConfig?: DowntimeSpawnConfig }, ): Promise { const at = new Date().toISOString(); @@ -2721,6 +3043,7 @@ async function dispatchScheduledPrompt( cwd: opts.cwd, paneName: `Downtime ${prompt.id}`, ...(anchorId !== undefined ? { anchorId } : {}), + ...(opts.spawnConfig !== undefined ? { spawnConfig: opts.spawnConfig } : {}), }); if (!spawn.ok) { // Failure trace (WL-0MSLWJ3I70031Z8U AC2 pattern): the audit log @@ -3138,7 +3461,7 @@ export async function computeMostImportantItem( export async function dispatchFromCoordination( deps: DowntimeWorkerDeps, entries: CoordinationEntry[], - opts: { model: string; cwd: string; coordinationDir: string; freeSlots?: number; leaseTtlMs?: number; browseItemCount?: number }, + opts: { model: string; cwd: string; coordinationDir: string; freeSlots?: number; leaseTtlMs?: number; browseItemCount?: number; spawnConfig?: DowntimeSpawnConfig }, now: number = Date.now(), ): Promise { // The leader path REQUIRES the item-fetch dep: without it the leader can @@ -3211,6 +3534,7 @@ export async function dispatchFromCoordination( return await dispatchScheduledPrompt(deps, duePrompt, { model: opts.model, cwd: opts.cwd, + spawnConfig: opts.spawnConfig, }); } } @@ -3314,7 +3638,7 @@ export async function dispatchFromCoordination( deps, kind, toCoordinationCandidate(result.info), - { model: opts.model, cwd: worklogRoot, selectionPath: 'coordination-offer', selectionReason: 'leader-offer' }, + { model: opts.model, cwd: worklogRoot, selectionPath: 'coordination-offer', selectionReason: 'leader-offer', spawnConfig: opts.spawnConfig }, ); if (outcome.dispatched) { // Dispatched — remove the entry so the owner re-queues its next @@ -3577,6 +3901,8 @@ export async function dispatchDowntimeWork( * `DEFAULT_DOWNTIME_MARKER_STALE_WINDOW_MS`. */ markerStaleWindowMs?: number; + /** Mode-aware Phase 2 parallelism inputs (WL-0MT50S9JW001DHME). */ + spawnConfig?: DowntimeSpawnConfig; }, ): Promise { // Per-process PIPELINE single-flight gate (F3, WL-0MT50LKAK001EF5Q): at @@ -3677,7 +4003,7 @@ export async function dispatchDowntimeWork( // spawn. `resolveInFlightPanes` never throws — an unavailable query // degrades to the marker-TTL fallback inside the decision table. const inFlight = await resolveInFlightPanes(deps, opts.cwd); - const ctx = { cwd: opts.cwd, model: opts.model, freeSlots, frozen, panesEligible, auditEligible, reviewGate, markerStaleWindowMs: opts.markerStaleWindowMs ?? DEFAULT_DOWNTIME_MARKER_STALE_WINDOW_MS, inFlight }; + const ctx = { cwd: opts.cwd, model: opts.model, freeSlots, frozen, panesEligible, auditEligible, reviewGate, markerStaleWindowMs: opts.markerStaleWindowMs ?? DEFAULT_DOWNTIME_MARKER_STALE_WINDOW_MS, inFlight, spawnConfig: opts.spawnConfig }; const herdrOutcome = await dispatchFromHerdrList(deps, head.items, ctx, flags); if (herdrOutcome !== null) return herdrOutcome; @@ -4061,22 +4387,35 @@ export type DowntimeSpawn = ( * (WL-0MT50S9JW001DHME). * * When supplied, `buildDowntimeSpawnOptions` selects the Phase 2 parallelism - * level based on the current operating mode and the available dispatch budget: + * level based on the current operating mode, the GENUINELY free slots at + * dispatch time, and the concurrent dispatch budget: * - * - `'1'` (safe default): fast mode, cheap mode with full budget, or config - * not supplied. - * - `'2'`: cheap mode AND a second slot is free AND the concurrent dispatch - * budget allows it (combined streams ≤ slot budget). + * - `'1'` (safe default): fast mode, cheap mode without a genuinely free + * second slot, a non-single-flight dispatch budget, or config not supplied. + * - `'2'`: cheap mode AND a second slot is genuinely free AND exactly one + * dispatch pipeline is in flight (combined streams ≤ slot budget). * - * When the config is absent the function falls back to `'1'` (the historic, - * backward-compatible value). + * `freeSlots` (not `slotBudget`) is the operative input for the second-slot + * check: `slotBudget` is the mode's total pool and being "free" cannot be + * inferred from it. When the config is absent the function falls back to + * `'1'` (the historic, backward-compatible value). */ export interface DowntimeSpawnConfig { /** `'cheap'` or `'fast'` — the proxy's current operating mode. */ mode: 'cheap' | 'fast'; - /** Total number of local proxy slots available (cheap = 2, fast = 3). */ + /** Total number of local proxy slots in the current mode (cheap = 2, fast = 3). */ slotBudget: number; - /** Maximum number of concurrent downtime dispatches allowed (0 = unbounded). */ + /** + * Genuinely free local proxy slots at dispatch time (unowned and not + * processing) — the real availability signal, never the total pool. + */ + freeSlots: number; + /** + * Maximum number of concurrent downtime dispatch pipelines allowed. + * `0` means UNBOUNDED (no cap): other dispatches may be in flight, so the + * cheap 2-slot pool cannot be guaranteed → treated as unsafe for `'2'`. + * Only a single-flight budget (`1`) enables `'2'`. + */ concurrentDispatchCap: number; } @@ -4086,15 +4425,16 @@ export interface DowntimeSpawnConfig { * * `AUDIT_PHASE2_PARALLELISM` is mode-aware (WL-0MT50S9JW001DHME): * - * - `'1'` (safe default): fast mode, cheap mode with full budget, or config - * not supplied. - * - `'2'`: cheap mode AND a second slot is free AND the concurrent dispatch - * budget allows it — up to 2 Phase 2 children run in parallel, fitting the + * - `'1'` (safe default): fast mode, cheap mode without a genuinely free + * second slot, a non-single-flight dispatch budget, or config not supplied. + * - `'2'`: cheap mode AND a second slot is genuinely free AND the dispatch + * is single-flight — up to 2 Phase 2 children run in parallel, fitting the * 2-slot cheap-mode pool (parent already done Phase 1). * * The parent audit always completes Phase 1 before Phase 2 children start, * so the max concurrent streams per audit is 2 (the children). This fits - * cheap mode's slot budget when a second slot is genuinely free. + * cheap mode's slot budget only when a second slot is genuinely free — the + * free count is therefore the operative check, never the total budget. */ export function buildDowntimeSpawnOptions( cwd: string, @@ -4109,23 +4449,22 @@ export function buildDowntimeSpawnOptions( // Default to '1' for backward compatibility when config is absent. let parallelism = '1'; if (opts?.config) { - const { mode, slotBudget, concurrentDispatchCap } = opts.config; - if (mode === 'cheap' && slotBudget >= 2) { - // In cheap mode with ≥ 2 slots, check if a second slot is free. - // PARALLELISM=2 means up to 2 Phase 2 children run in parallel. - // The parent already completed Phase 1, so max concurrent streams = 2. - // Only enable when the dispatch budget allows it: - // - If concurrentDispatchCap is 0 (unbounded), only 1 dispatch at a time - // during cheap mode → 2 children per audit = 2 streams total → safe. - // - If concurrentDispatchCap >= 2, multiple audits could run → each with - // PARALLELISM=2 would exceed 2-slot budget → stay at '1'. - const dispatchBudgetAllows = - concurrentDispatchCap === 0 || concurrentDispatchCap === 1; - if (dispatchBudgetAllows) { - parallelism = '2'; - } + const { mode, slotBudget, freeSlots, concurrentDispatchCap } = opts.config; + // Cheap mode is the 2-slot local pool this bound protects; fast mode + // (cloud-routed, wider pool) keeps the serial historic default. + const cheapPool = mode === 'cheap' && slotBudget >= DOWNTIME_AUDIT_MIN_FREE_SLOTS; + // A GENUINELY free second slot right now — Phase 2 needs the parent plus + // a child = 2 concurrent streams (the total budget is not availability). + const secondSlotFree = freeSlots >= DOWNTIME_AUDIT_MIN_FREE_SLOTS; + // Single-flight dispatch only: an unbounded (0) or ≥ 2 concurrent-dispatch + // budget means a second audit could run, so two audits × 2 children would + // exceed the cheap 2-slot pool. Only cap === 1 is safe. + const dispatchIsSingleFlight = concurrentDispatchCap === 1; + if (cheapPool && secondSlotFree && dispatchIsSingleFlight) { + parallelism = '2'; } - // Fast mode, insufficient budget, or config-supplied but constraints not met → '1' + // Fast mode, no free second slot, non-single-flight budget, or config + // supplied but constraints not met → '1'. } return { @@ -4175,7 +4514,7 @@ export const DOWNTIME_SPAWN_PROBE_MS = 500; export async function spawnDowntimePane( scriptPath: string, args: string[], - opts: { cwd: string }, + opts: { cwd: string; config?: DowntimeSpawnConfig }, spawnFn: DowntimeSpawn = defaultDowntimeSpawn, ): Promise { const child = spawnFn(scriptPath, args, opts); @@ -4213,6 +4552,162 @@ export async function spawnDowntimePane( }); } +// ── Pane-lifecycle monitor (WL-0MU308WSF0002JWN) ────────────────────── + +/** Summary of one pane-lifecycle monitor pass. */ +export interface PaneLifecycleMonitorResult { + /** Number of dispatched panes inspected. */ + checked: number; + /** Number of panes actually closed this pass. */ + closed: number; + /** Number of lifecycle outcomes logged this pass. */ + logged: number; + /** Number of per-pane failures swallowed (fail-closed). */ + errors: number; +} + +/** + * Inspect every dispatched pane recorded in the rolling log and, for each + * one that has reached a terminal or attention state, log a pane-close + * lifecycle entry and (except `implement`) close the pane + * (WL-0MU308WSF0002JWN). + * + * Fail-closed at every boundary (AC7): a missing log, an unreadable item, a + * failed pane close, or a failed log write is swallowed and never crashes + * the worker or blocks the remaining panes. Idempotent: a `(pane, outcome, + * reason)` triple already recorded in the log is never written twice, so + * repeated ticks (and multiple instances sharing a root) do not duplicate + * entries — while a genuine state CHANGE produces a new entry (intake Q&A). + * + * The monitor performs NO work when the deps are absent (legacy/test + * callers): with no `getItemLifecycleState` every pane classifies to null, + * so the pass is a cheap no-op. + */ +/** + * Warn-level observability for pane-lifecycle failures + * (WL-0MU4USJ07009JYL8 AC2). Fail-closed: a stderr write failure is + * swallowed — observability must never crash the worker. + */ +function paneLifecycleWarn(message: string): void { + try { + process.stderr.write(`[worklog-plugin] Downtime pane-lifecycle: ${message}\n`); + } catch { + // fail-closed: logging must never crash the worker + } +} + +function paneLifecycleErrMsg(err: unknown): string { + return err instanceof Error ? err.message : String(err); +} + +export async function monitorDispatchedPanes( + deps: DowntimeWorkerDeps, + cwd: string, +): Promise { + const result: PaneLifecycleMonitorResult = { checked: 0, closed: 0, logged: 0, errors: 0 }; + + // Strict no-op for legacy callers: without an item-state resolver the + // monitor cannot distinguish a terminal stage from "unknown", so taking + // any action (e.g. flagging requires-attention on agent-done alone) would + // be guesswork. Production wiring always provides the dep. + if (typeof deps.getItemLifecycleState !== 'function') return result; + + // Read the rolling log (fail-safe: unreadable → []). + let entries: Awaited>; + try { + entries = await _readDowntimeEntries(cwd); + } catch (err) { + paneLifecycleWarn(`could not read the dispatch log — skipping this pass: ${paneLifecycleErrMsg(err)}`); + return result; // fail-closed: no evidence, no action + } + + const panes = collectDispatchedPanes(entries); + if (panes.length === 0) return result; + const loggedKeys = loggedPaneLifecycleKeys(entries); + + // Running-pane liveness: `null` when unknown (fail-open — an unknown + // liveness must never be read as "agent done", which would close a live + // pane). When known, a dispatched pane absent from the live set has ended. + let livePanes: Set | null = null; + if (typeof deps.getRunningDowntimePanes === 'function') { + try { + const running = await deps.getRunningDowntimePanes(cwd); + if (running.ok && Array.isArray(running.records)) { + livePanes = new Set(running.records.map((rec) => rec.paneId)); + } else if (!running.ok) { + paneLifecycleWarn('live-pane query failed — skipping agent-done detection this pass'); + } + } catch (err) { + paneLifecycleWarn(`live-pane query threw — skipping agent-done detection this pass: ${paneLifecycleErrMsg(err)}`); + livePanes = null; // fail-open — never close on unknown liveness + } + } + + for (const pane of panes) { + result.checked += 1; + try { + let item: PaneItemState | null = null; + try { + item = await deps.getItemLifecycleState(pane.itemId, cwd); + } catch (err) { + paneLifecycleWarn(`item lookup failed for ${pane.itemId} (pane ${pane.paneId}): ${paneLifecycleErrMsg(err)}`); + result.errors += 1; + continue; // fail-closed: no evidence → take no action for this pane + } + const agentDone = livePanes !== null && !livePanes.has(pane.paneId); + const decision = classifyPaneLifecycle(pane, item, agentDone); + if (decision === null) continue; + + const key = paneLifecycleKey(pane.paneId, decision.outcome, decision.reasonCode); + if (loggedKeys.has(key)) continue; // already recorded — idempotent + + // Close the pane (except `implement`, which is never auto-closed — + // AC6). A failed/absent close is recorded with `closed:false` and + // never blocks the log entry or the remaining panes (AC7). + let closed = false; + if (decision.close && typeof deps.closePane === 'function') { + try { + closed = await deps.closePane(pane.paneId, cwd, { itemId: pane.itemId, kind: pane.kind }); + } catch (err) { + paneLifecycleWarn(`pane close failed for ${pane.paneId} (${pane.itemId}): ${paneLifecycleErrMsg(err)}`); + closed = false; // fail-closed + } + } + + const entry: PaneCloseLogEntry = { + entryType: 'pane-close', + timestamp: new Date().toISOString(), + itemId: pane.itemId, + itemTitle: item?.title ?? pane.itemTitle, + paneId: pane.paneId, + kind: pane.kind, + outcome: decision.outcome, + reason: decision.reason, + reasonCode: decision.reasonCode, + closed, + }; + try { + if (typeof deps.recordPaneClose === 'function') { + await deps.recordPaneClose(entry, cwd); + } else { + await _appendPaneCloseLogEntry(cwd, entry); + } + loggedKeys.add(key); + result.logged += 1; + if (closed) result.closed += 1; + } catch (err) { + paneLifecycleWarn(`pane-close log write failed for ${pane.paneId} (${pane.itemId}): ${paneLifecycleErrMsg(err)}`); + result.errors += 1; // fail-closed: logging must never crash the worker + } + } catch (err) { + paneLifecycleWarn(`lifecycle pass failed for pane ${pane.paneId}: ${paneLifecycleErrMsg(err)}`); + result.errors += 1; // fail-closed: one bad pane never blocks the rest + } + } + + return result; +} + // ── Worker orchestrator (implemented — F3) ──────────────────────────── /** @@ -4239,6 +4734,19 @@ export interface DowntimeWorkerConfig { requiredFreeSlots: number; model: string; cwd: string; + /** + * Current proxy operating mode (WL-0MT50S9JW001DHME). `undefined` when + * unknown (mode switching disabled, or the proxy has not been polled + * yet) → the dispatcher conservatively keeps `AUDIT_PHASE2_PARALLELISM` + * at `'1'`. + */ + mode?: 'cheap' | 'fast'; + /** + * Maximum concurrent dispatch pipelines (WL-0MT50S9JW001DHME). Defaults + * to `DISPATCH_PIPELINE_SINGLE_FLIGHT` (1). Only a single-flight budget + * permits `'2'`; an unbounded (`0`) or ≥ 2 budget keeps `'1'`. + */ + concurrentDispatchCap?: number; /** Pause duration after a genuine empty backlog (no-candidate), ms. */ noCandidateCooldownMs: number; /** Sprint-complete threshold (parent WL-0MTHSHN5V008R5L0). Optional for backward compat — defaults to 20. */ @@ -4249,6 +4757,12 @@ export interface DowntimeWorkerConfig { * `DEFAULT_DOWNTIME_MARKER_STALE_WINDOW_MS` (24 h). */ markerStaleWindowMs?: number; + /** + * Pane-lifecycle monitor cadence, ms (WL-0MU308WSF0002JWN). Optional — + * defaults to `DOWNTIME_PANE_LIFECYCLE_INTERVAL_MS` (30 s). Tests may + * pass 0 to run the monitor on every tick. + */ + paneLifecycleIntervalMs?: number; }; /** * Optional shared round-robin registry (WL-0MSSRED76008LGB6) used for @@ -4321,6 +4835,14 @@ export interface DowntimeWorker { readonly dispatching: boolean; /** Timestamp of the last successful dispatch (null until the first). */ readonly lastDispatchAt: number | null; + /** + * Short token for the gate that blocked the last polled tick (e.g. + * `'slot-owner'`, `'contention'`, `'code-freeze'`), or null when the worker + * was not gate-blocked (idle/busy/dispatching/disabled). Powers the header's + * `[downtime held: ]` label so "idle slots but no dispatches" is + * visible (WL-0MU8808ZY0091JIA AC4). + */ + readonly blockReason: string | null; /** * Whether the worker is enabled per the current settings (re-read) AND the * per-instance in-memory override: effective enabled = `override ?? @@ -4393,6 +4915,9 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker const perSlotTracker = createPerSlotIdleTracker(); let dispatching = false; let lastDispatchAt: number | null = null; + // Pane-lifecycle monitor cadence gate (WL-0MU308WSF0002JWN): the timestamp + // of the last monitor pass. 0 forces a pass on the first tick. + let lastPaneMonitorAt = 0; // No-candidate cooldown (WL-0MSI7DQL10016QYX): timestamp until which the // worker is fully paused (no poll, no idle tracking, no dispatch) after a // genuine empty backlog OR three consecutive CLI errors. Cancelled early @@ -4402,6 +4927,12 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker // Three-strike rule: consecutive CLI-error dispatch outcomes. A successful // dispatch, a genuine no-candidate outcome, or an expired cooldown resets it. let errorStrikes = 0; + // No-dispatch decision logging (WL-0MU8808ZY0091JIA): the last reason + // written and when, so repeated identical refusals are rate-limited. + let lastDecisionReason: string | null = null; + let lastDecisionAt = 0; + // Current header blocking token; null when not gate-blocked. Reset each tick. + let blockReason: string | null = null; // Per-instance in-memory enabled override (parent WL-0MSZ4NSOE007AQEF): // null (default) = follow the global setting; true/false force dispatch // on/off for THIS instance. In-memory only — resets on plugin restart, @@ -4517,6 +5048,54 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker } }; + // ── No-dispatch decision log (WL-0MU8808ZY0091JIA) ── + // Record WHY a polled tick refused to dispatch so "idle slots but no + // dispatches" is diagnosable from the logs alone. Rate-limited: a repeated + // refusal with the SAME reason is written at most once per + // DOWNTIME_DECISION_LOG_MIN_INTERVAL_MS; a reason CHANGE always writes. The + // header blocking token is updated on EVERY refusal (even a rate-limited + // one) so the header never goes stale. Fail-closed: a logging failure never + // affects the dispatch decision. + const recordDecision = async ( + cwd: string, + reason: string, + fields: { + freeSlots: number; + totalSlots: number; + ownerPresent: boolean; + runningPanes: number | null; + contentionDepth: number; + }, + ): Promise => { + blockReason = decisionHeaderToken(reason); + const now = Date.now(); + if ( + lastDecisionReason === reason && + now - lastDecisionAt < DOWNTIME_DECISION_LOG_MIN_INTERVAL_MS + ) { + return; // rate-limited: identical refusal within the window + } + lastDecisionReason = reason; + lastDecisionAt = now; + const entry: CoordinationLogEntry = { + kind: 'decision', + operation: 'no-dispatch', + instanceId, + reason, + ...fields, + at: new Date(now).toISOString(), + }; + try { + if (typeof opts.deps.recordDecision === 'function') { + await opts.deps.recordDecision(entry, cwd); + } else { + await appendCoordinationLogEntry(cwd, entry); + } + } catch { + // fail-closed: decision logging must never crash the worker + } + }; + return { get idleSince(): number | null { return tracker.idleSince; @@ -4576,8 +5155,14 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker get errorStrikes(): number { return errorStrikes; }, + get blockReason(): string | null { + return blockReason; + }, async tick(): Promise { const cfg = opts.config(); + // Fresh per-tick decision state: clear the header blocking reason; a + // gate below re-sets it when this tick is refused (WL-0MU8808ZY0091JIA). + blockReason = null; // Short-circuit on the EFFECTIVE enabled state (override ?? settings): // while toggled off the worker performs no proxy polling, no idle // tracking, and no dispatch — exactly the settings-disabled path. @@ -4737,6 +5322,30 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker } } + // ── Pane-lifecycle monitor (WL-0MU308WSF0002JWN) ────────────────── + // Runs on the LEADER (legacy mode: always) and BEFORE the cooldown + // gate, so completed dispatched panes are tidied even while dispatch + // is paused in a no-candidate cooldown. Cadence-bounded (default 30 s) + // so the ~10 s tick does not re-query the worklog for every open pane + // on every tick. + // + // FIRE-AND-FORGET (deliberately NOT awaited): the single-flight + // dispatch guard relies on the first in-flight tick setting + // `dispatching` before a second concurrent tick reaches its check — an + // extra await on the pre-dispatch path lets the second tick win that + // race and double-dispatch (pinned by the worker single-flight test). + // The monitor is internally fail-closed and idempotent, so running it + // concurrently is safe; the `.catch` is belt-and-braces. + const paneMonitorIntervalMs = + cfg.paneLifecycleIntervalMs ?? DOWNTIME_PANE_LIFECYCLE_INTERVAL_MS; + if (tickNow - lastPaneMonitorAt >= paneMonitorIntervalMs) { + lastPaneMonitorAt = tickNow; + void monitorDispatchedPanes(opts.deps, cfg.cwd).catch((err) => { + // fail-closed: pane-lifecycle monitoring must never crash the worker + paneLifecycleWarn(`monitor pass threw: ${paneLifecycleErrMsg(err)}`); + }); + } + // Cooldown gate (WL-0MTEZ4XZJ006Y9U7 AC2 — ordering): the check-in // block above runs FIRST, so a no-candidate pause never suppresses the // coordination check-in (the only mechanism that re-offers work once @@ -4781,14 +5390,15 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker // session and must not reset the free slots' timers (spare-capacity // dispatch, parent WL-0MT32F90V008UAD2). A slot reporting processing // resets only its own timer. + const perSlotSlots = usablePerSlotSlots(status); const perSlotMode = - Array.isArray(status.slots) && + perSlotSlots !== null && cfg.requiredFreeSlots > 0 && cfg.requiredFreeSlots < status.total_slots; let idle: boolean; let ready: boolean; - if (perSlotMode && Array.isArray(status.slots)) { + if (perSlotMode && perSlotSlots !== null) { const globalIdle = perSlotGlobalIdleChecks(status); // Display-only: the global idle tracker also reflects per-slot query // activity for the title bar idle indicator — when any slot is @@ -4796,12 +5406,12 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker // not "idle". The dispatch logic (spare-capacity relaxation) is // unaffected because free-slot count comes from perSlotTracker, not // tracker.idleSince. (parent WL-0MT65T14L002HTWB) - const anySlotProcessing = status.slots.some( + const anySlotProcessing = perSlotSlots.some( (s) => typeof s.is_processing === 'boolean' && s.is_processing, ); tracker.record(globalIdle && !anySlotProcessing); if (globalIdle) { - perSlotTracker.record(status.slots); + perSlotTracker.record(perSlotSlots); idle = true; ready = perSlotTracker.thresholdMetCount(cfg.thresholdMs) >= cfg.requiredFreeSlots; @@ -4843,10 +5453,29 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker // minimums (WL-0MT32F90V008UAD2 AC3): audit needs ≥2 (parent + Phase 2 // child), single-pane tiers need ≥1; idle-duration gate (configured N) // is unchanged and shared. - const freeSlots = - Array.isArray(status.slots) - ? countFreeUnownedSlots(status.slots) - : status.available_slots; + // Count-based: the proxy's own free-slot count (historical behaviour). + // The lease reserve in `countBasedSpareCapacity` is a GATE only — the + // reported budget stays the proxy figure so the strict single-slot path + // and its decision log are unchanged. + const freeSlots = perSlotSlots + ? countFreeUnownedSlots(perSlotSlots) + : status.available_slots; + + // Mode-aware Phase 2 parallelism inputs (WL-0MT50S9JW001DHME): the + // genuine free-slot snapshot (never the total budget), the current + // proxy mode, and the single-flight pipeline budget. `mode` is + // undefined until the mode-switch worker has observed the proxy, so an + // unknown mode leaves `spawnConfig` absent → the spawn defaults to the + // safe serial '1'. + const spawnConfig: DowntimeSpawnConfig | undefined = + cfg.mode === undefined + ? undefined + : { + mode: cfg.mode, + slotBudget: status.total_slots, + freeSlots, + concurrentDispatchCap: cfg.concurrentDispatchCap ?? DISPATCH_PIPELINE_SINGLE_FLIGHT, + }; // ── Running-pane liveness (owner-lease qualifier only) ── // Count dispatched downtime panes that are STILL ALIVE (machine-wide, @@ -4895,18 +5524,25 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker // `slotOwned` is qualified on a known running-pane count > 0 so an // OPERATOR lease on a spare-capacity multi-slot setup does not block // dispatch into the free slots when the worker has no running pane - // of its own. (The lease signal self-heals: proxy leases expire ~180 s - // after activity stops — router_helpers.py `_get_lease_timeout_seconds` - // — so an idle-but-open pane does not block dispatch indefinitely.) - const ownerLeaseHeld = - (parseLocalOwnerSessionId(status.local_owner_session_id) !== undefined) || - (typeof status.local_owner_lease_remaining_seconds === 'number' && - Number.isFinite(status.local_owner_lease_remaining_seconds) && - status.local_owner_lease_remaining_seconds > 0); + // of its own. The lease is NOT short-lived: the proxy holds an + // ADAPTIVE lease up to `LOCAL_DISPATCH_LEASE_MAX_SECONDS` (default + // 1500 s, cross-repo `llm-manager`), so an idle-but-open pane CAN block + // the count-based path for its whole run — the historical "~180 s" + // assumption was wrong (WL-0MU8809SZ0022VZG). The per-slot path + // (WL-0MU8807BI008C9ME) is what keeps a dispatched pane's own lease + // from blocking the OTHER free unowned slots. + const ownerLeaseHeld = ownerLeaseCount(status) > 0; + // Count-based spare-capacity (WL-0MUFP30T2003OX1F): when per-slot + // identity is unusable and 0 < N < total, a held lease no longer blocks + // dispatch into the proxy-reported spare slots. This mirrors the + // `evaluateIdle` relaxation exactly, so the idle gate and the ownership + // gate can never disagree. + const countBasedSpare = + !perSlotMode && countBasedSpareCapacity(status, cfg.requiredFreeSlots); const slotOwned = - perSlotMode && Array.isArray(status.slots) - ? countFreeUnownedSlots(status.slots) === 0 - : ownerLeaseHeld && (runningPanes ?? 0) > 0; + perSlotMode && perSlotSlots !== null + ? countFreeUnownedSlots(perSlotSlots) === 0 + : ownerLeaseHeld && (runningPanes ?? 0) > 0 && !countBasedSpare; // LIVE depth only (WL-0MU1DWXO600153OI): `contention_queued_count` is // cumulative telemetry and must never gate dispatch. const contentionQueueDepth = @@ -4925,9 +5561,23 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker // concurrency limiter, and a liveness-query failure no longer blocks // dispatch (it only feeds the `slotOwned` qualifier). if (slotOwned) { + void recordDecision(cfg.cwd, 'slot-owned', { + freeSlots, + totalSlots: status.total_slots, + ownerPresent: ownerLeaseHeld, + runningPanes, + contentionDepth: contentionQueueDepth, + }); return { polled: true, dispatched: false, idle: true }; } if (contentionQueueDepth > 0) { + void recordDecision(cfg.cwd, 'proxy-contention', { + freeSlots, + totalSlots: status.total_slots, + ownerPresent: ownerLeaseHeld, + runningPanes, + contentionDepth: contentionQueueDepth, + }); return { polled: true, dispatched: false, idle: true }; } @@ -4959,6 +5609,7 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker leaseTtlMs: opts.leaseTtlSeconds ? opts.leaseTtlSeconds * 1000 : DEFAULT_LEASE_TTL_SECONDS * 1000, + spawnConfig, }, ) : await dispatchDowntimeWork(opts.deps, { @@ -4973,7 +5624,22 @@ export function createDowntimeWorker(opts: DowntimeWorkerConfig): DowntimeWorker contentionQueueDepth, // Success-marker staleness window (WL-0MU6UL0RJ008IHGT). markerStaleWindowMs: cfg.markerStaleWindowMs, + spawnConfig, }); + // Record the refusal reason (WL-0MU8808ZY0091JIA): actionable + // no-dispatch outcomes (no-candidate / review-queue-hold / code-freeze + // / audit-in-flight / wl-error / ...) are logged (rate-limited) so the + // dispatcher's decision is observable. A successful dispatch is not a + // refusal. + if (!outcome.dispatched && typeof outcome.reason === 'string') { + void recordDecision(cfg.cwd, outcome.reason, { + freeSlots, + totalSlots: status.total_slots, + ownerPresent: ownerLeaseHeld, + runningPanes, + contentionDepth: contentionQueueDepth, + }); + } if (outcome.dispatched) { lastDispatchAt = Date.now(); errorStrikes = 0; // a successful dispatch proves the CLI is healthy @@ -5886,6 +6552,17 @@ export function parseShowItemOutput(stdout: string): DowntimeItemInfo | null { needsProducerReview: raw.needsProducerReview !== undefined ? Boolean(raw.needsProducerReview) : undefined, }; + // Top-level audit result (WL-0MU308WSF0002JWN): `wl show --json` serves + // `auditResult` as a TOP-LEVEL sibling of `workItem` (not nested inside + // it), carrying the audit verdict (`readyToClose`) the pane-lifecycle + // monitor needs to distinguish audit-passed from audit-failed. Additive + // and tolerant — a missing/malformed auditResult leaves the fields absent. + const topAudit = (parsed as { auditResult?: unknown }).auditResult; + if (topAudit !== null && typeof topAudit === 'object') { + const a = topAudit as Record; + if (typeof a.auditedAt === 'string') info.auditedAt = a.auditedAt; + if (typeof a.readyToClose === 'boolean') info.auditResult = a.readyToClose; + } return info; } diff --git a/packages/herdr/src/index.test.ts b/packages/herdr/src/index.test.ts index b630c1805..a284cb05b 100644 --- a/packages/herdr/src/index.test.ts +++ b/packages/herdr/src/index.test.ts @@ -1789,6 +1789,29 @@ describe('createDowntimeDeps', () => { ); }); + it('spawnAgentPane forwards the mode-aware spawnConfig to the spawn boundary (WL-0MT50S9JW001DHME)', async () => { + const spawnFn = vi.fn(() => ({ unref: vi.fn(), once: vi.fn() })); + const deps = createDowntimeDeps('/path/to/send-to-pi.sh', 'Map', spawnFn); + const spawnConfig = { + mode: 'cheap' as const, + slotBudget: 2, + freeSlots: 2, + concurrentDispatchCap: 1, + }; + + await deps.spawnAgentPane('Run /skill:audit WL-AUD — Audit me.', { + model: 'plan', + cwd: '/repo', + spawnConfig, + }); + + expect(spawnFn).toHaveBeenCalledWith( + '/path/to/send-to-pi.sh', + expect.arrayContaining(['--pane-name', 'Downtime audit']), + { cwd: '/repo', config: spawnConfig }, + ); + }); + it('spawnAgentPane honours an explicit paneName (scheduled prompts run as Downtime )', async () => { const spawnFn = vi.fn(() => ({ unref: vi.fn(), once: vi.fn() })); const deps = createDowntimeDeps('/path/to/send-to-pi.sh', 'Map', spawnFn); diff --git a/packages/herdr/src/index.ts b/packages/herdr/src/index.ts index 635aba3e8..1c9487853 100644 --- a/packages/herdr/src/index.ts +++ b/packages/herdr/src/index.ts @@ -88,6 +88,7 @@ import { type DowntimeClaimResult, type DowntimeSpawn, type DowntimeSpawnResult, + type DowntimeSpawnConfig, type ScheduledPrompt, type DowntimeItemResult, parseShowItemOutput, @@ -100,6 +101,7 @@ import { withTransientRetry, parseHerdrPaneListOutput, countRunningDowntimePanes, + isSafeDowntimePaneToClose, type RunningPanesResult, type LlamaStatus, } from './downtime-worker.js'; @@ -111,6 +113,7 @@ import { import { createRoundRobinRegistry, type RoundRobinRegistry } from './downtime-round-robin.js'; import { appendDowntimeLogEntry, + appendPaneCloseLogEntry, auditDispatchedItemIds, implementDispatchedItemIds, planDispatchedItemStages, @@ -1215,13 +1218,14 @@ export function createDowntimeDeps( itemTitle?: string; itemId?: string; anchorId?: string; + spawnConfig?: DowntimeSpawnConfig; }, ): Promise { const kind = skillKindFromPrompt(prompt); return spawnDowntimePane( scriptPath, buildDowntimePaneArgs(kind, prompt, opts), - { cwd: opts.cwd }, + { cwd: opts.cwd, config: opts.spawnConfig }, spawnFn, ); }, @@ -1311,6 +1315,77 @@ export function createDowntimeDeps( // fail-open: enrichment logging must never crash the worker } }, + // Pane-lifecycle item state (WL-0MU308WSF0002JWN): resolve the current + // state of a dispatched pane's item so the monitor can classify its + // lifecycle outcome. Reuses the enriched `wl show` fetch (which now also + // carries the top-level audit verdict). Fail-closed: a wl failure or an + // unparseable item resolves null (the monitor then takes no action for + // that pane). Never throws. + async getItemLifecycleState(itemId: string, cwd: string) { + try { + const result = await fetchAuditItemById(itemId, cwd); + if (!result.ok || !result.info) return null; + const info = result.info; + return { + id: info.id, + title: info.title, + status: info.status, + stage: info.stage, + risk: info.risk, + effort: info.effort, + auditedAt: info.auditedAt, + auditResult: info.auditResult, + needsProducerReview: info.needsProducerReview, + }; + } catch { + return null; // fail-closed: an unreadable item is never acted upon + } + }, + // Close a dispatched pane (WL-0MU308WSF0002JWN): `herdr pane close + // `. Fail-closed: any herdr failure resolves false and the + // monitor still records the lifecycle outcome with `closed:false`. + // + // Safety (WL-0MU4US5MP001JFEN AC7): when the dispatch context is + // supplied, verify the LIVE pane's label is a downtime pane whose + // item-id suffix matches THIS dispatch BEFORE closing — a stale entry + // must never close an unrelated/operator pane whose pane id collides. + async closePane( + paneId: string, + _cwd: string, + expected?: { itemId: string; kind: string }, + ): Promise { + try { + const herdrBin = process.env.HERDR_BIN_PATH ?? 'herdr'; + if (expected) { + const { stdout } = await getExecFileAsync()( + herdrBin, + ['pane', 'list'], + { encoding: 'utf8', timeout: DOWNTIME_WL_TIMEOUT_MS, maxBuffer: 4 * 1024 * 1024 }, + ); + const panes = parseHerdrPaneListOutput(stdout); + // Only ever close a downtime pane for THIS item (AC7). A missing + // record (pane already gone) or a mismatched label means we must + // NOT close (never an unrelated/operator pane id collision). + if (panes === null || !isSafeDowntimePaneToClose(panes, paneId, expected.itemId)) { + return false; + } + } + await getExecFileAsync()( + herdrBin, + ['pane', 'close', paneId], + { encoding: 'utf8', timeout: DOWNTIME_WL_TIMEOUT_MS }, + ); + return true; + } catch { + return false; // fail-closed: a failed close must never crash the worker + } + }, + // Record a pane-close lifecycle entry in the rolling dispatch log + // (WL-0MU308WSF0002JWN). Fail-closed: `appendPaneCloseLogEntry` never + // throws. + async recordPaneClose(entry, cwd: string): Promise { + await appendPaneCloseLogEntry(cwd, entry); + }, async rollbackClaim( itemId: string, original: DowntimeClaimExpected, @@ -1471,20 +1546,30 @@ async function main(): Promise { // open in the resolved worklog root (--cwd). const targetCwd = wlRoot ?? resolvedCwd ?? process.cwd(); + // Machine-wide coordination directory shared by the downtime leader + // election and the mode-switch shared activity file (WL-0MU6MXCZZ007ZXT9, + // AC2). HERDR_COORDINATION_DIR override wins; default ~/.herdr/downtime/. + const coordinationDir = getMachineCoordinationDir() ?? join(targetCwd, '.worklog'); + // Mode-switch worker: automatically switches the llama-proxy between fast // (cloud) and cheap (local) modes based on operator activity and proxy // idle state. Created with settings.downtimeProxyUrl (reuse, no new URL - // key). Passes `enabled` via the settings flag (modeSwitchEnabled). - // Created BEFORE the downtime worker so we can wire the idle callback. - const modeSwitchWorker: ModeSwitchWorker = createModeSwitchWorker(); + // key). Created AFTER the downtime worker because it needs + // `downtimeWorker.isLeader` for leader-only cheap switching (AC1) and the + // coordination directory for shared activity broadcast (AC2). The idle + // callback is wired through a holder because createDowntimeWorker needs + // `onProxyIdle` before the mode-switch worker exists. + const modeSwitchHolder: { worker?: ModeSwitchWorker } = {}; // Callback: when the downtime dispatcher finds the proxy idle, trigger a // mode-switch tick immediately with the fresh status — avoids the 10 s // poll delay of the independent scheduler task. const onProxyIdle = async (proxyStatus: LlamaStatus): Promise => { + const worker = modeSwitchHolder.worker; + if (!worker) return; // dispatcher cannot tick before the worker exists try { const s = loadSettings(); - await modeSwitchWorker.tick({ + await worker.tick({ enabled: s.modeSwitchEnabled ?? true, idleThresholdMs: s.modeSwitchIdleThresholdMs ?? DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS, proxyUrl: s.downtimeProxyUrl, @@ -1507,7 +1592,7 @@ async function main(): Promise { // ~/.herdr/downtime/. The per-worklog join(targetCwd, '.worklog') // coupling is retired (F6). The instance id is auto-generated at // worker construction (stable for the process lifetime). - coordinationDir: getMachineCoordinationDir() ?? join(targetCwd, '.worklog'), + coordinationDir, config: () => { const s = loadSettings(); return { @@ -1520,6 +1605,19 @@ async function main(): Promise { // the concurrency limiter. model: s.downtimeModel, cwd: targetCwd, + // Mode-aware Phase 2 parallelism (WL-0MT50S9JW001DHME): the last + // proxy mode observed by the mode-switch worker (`null` until polled + // → `undefined` → the dispatcher conservatively keeps PARALLELISM=1). + // + // WL-0MUFRFLRQ004KNDG: read through `modeSwitchHolder`, NOT the + // `modeSwitchWorker` const below. createDowntimeWorker calls config() + // SYNCHRONOUSLY during construction (the durable-disable marker check), + // which runs before `modeSwitchWorker` is initialized — referencing it + // directly hit the temporal dead zone and crashed the whole plugin at + // startup. The holder is declared above; it is empty at construction + // (conservative `undefined` → PARALLELISM=1) and populated immediately + // after, so later ticks read the real mode. + mode: modeSwitchHolder.worker?.getLastKnownMode() ?? undefined, noCandidateCooldownMs: s.downtimeNoCandidateCooldownMs, // Dispatched success-marker staleness window (WL-0MU6UL0RJ008IHGT). markerStaleWindowMs: s.downtimeMarkerStaleWindowMs, @@ -1529,6 +1627,15 @@ async function main(): Promise { onProxyIdle, }); + // Mode-switch worker (created AFTER the downtime worker so it can reuse the + // leader probe): only the downtime leader runs the idle cheap switch (AC1) + // and the shared activity file is read from the same coordination dir. + const modeSwitchWorker: ModeSwitchWorker = createModeSwitchWorker({ + isLeader: () => downtimeWorker.isLeader, + coordinationDir, + }); + modeSwitchHolder.worker = modeSwitchWorker; + const selectedItem = await runWorklistTui( fetcher, undefined, diff --git a/packages/herdr/src/mode-switch-integration.test.ts b/packages/herdr/src/mode-switch-integration.test.ts index f568589ac..c40665912 100644 --- a/packages/herdr/src/mode-switch-integration.test.ts +++ b/packages/herdr/src/mode-switch-integration.test.ts @@ -116,7 +116,7 @@ describe('scheduler task configuration', () => { it('idle threshold floor is at least 60s', () => { expect(MODE_SWITCH_IDLE_THRESHOLD_FLOOR_MS).toBeGreaterThanOrEqual(60_000); - expect(DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS).toBe(1_800_000); // 30 minutes + expect(DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS).toBe(3_600_000); // 60 minutes }); it('run timeout watchdog exceeds the admin API timeout (hung ticks get abandoned)', () => { diff --git a/packages/herdr/src/mode-switch-worker.test.ts b/packages/herdr/src/mode-switch-worker.test.ts index 709a4cb51..ef6a9c0e3 100644 --- a/packages/herdr/src/mode-switch-worker.test.ts +++ b/packages/herdr/src/mode-switch-worker.test.ts @@ -6,18 +6,24 @@ * Run: npx vitest run packages/herdr/src/mode-switch-worker.test.ts */ -import { describe, it, expect } from 'vitest'; +import { describe, it, expect, beforeEach, afterEach } from 'vitest'; +import { existsSync, mkdtempSync, rmSync, writeFileSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; import { createModeSwitchWorker, getAdminMode, setAdminMode, fetchProxyStatus, + readSharedActivity, + writeSharedActivity, clampModeSwitchIdleThresholdMs, clampModeSwitchPollIntervalMs, DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS, MODE_SWITCH_IDLE_THRESHOLD_FLOOR_MS, MODE_SWITCH_POLL_INTERVAL_FLOOR_MS, MODE_SWITCH_POLL_INTERVAL_CAP_MS, + MODE_ACTIVITY_FILE, ADMIN_MODE_PATH, ADMIN_SET_MODE_PATH, PROXY_STATUS_PATH, @@ -301,6 +307,40 @@ describe('fast switch on command', () => { }); }); +// ── Last-known-mode exposure (WL-0MT50S9JW001DHME) ─────────────────── + +describe('getLastKnownMode', () => { + it('returns null before any poll or switch', () => { + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ fetcher: api.fetcher, now }); + expect(worker.getLastKnownMode()).toBeNull(); + }); + + it('returns fast after an operator command triggers the fast switch', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ fetcher: api.fetcher, now }); + worker.onOperatorCommand('http://proxy'); + await flushAsync(); + expect(worker.getLastKnownMode()).toBe('fast'); + }); + + it('returns cheap after an idle tick switches to cheap', async () => { + clock = 1_000_000; + const api = mockAdminApi(); // GET /admin/mode defaults to 'fast' + const worker = createModeSwitchWorker({ fetcher: api.fetcher, now }); + advance(900_000); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(worker.getLastKnownMode()).toBe('cheap'); + }); +}); + // ── Cheap switch trigger ───────────────────────────────────────────── describe('cheap switch trigger', () => { @@ -912,4 +952,280 @@ describe('per-slot operator gate', () => { // Malformed per-slot identity → proxy treated as busy → NO cheap switch. expect(setModePostsMade).toHaveLength(0); }); +}); + +// ── Leader-gated cheap switching + shared activity ──────────────────── +// (WL-0MU6MXCZZ007ZXT9: mode-switch flip-flop — leader election for proxy +// mode changes.) + +describe('leader-gated cheap switching (AC1)', () => { + it('a non-leader skips the entire cheap-switch tick even when idle and proxy idle', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => false, + }); + advance(900_000); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + // No cheap POST, and the tick was skipped before any proxy/mode read. + expect(setModePosts(api)).toHaveLength(0); + expect(api.calls.filter((c) => c.url.endsWith(ADMIN_MODE_PATH))).toHaveLength(0); + expect(worker.getLastKnownMode()).toBeNull(); + }); + + it('the leader performs the cheap switch when idle and proxy idle', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => true, + }); + advance(900_000); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(1); + expect(setModePosts(api)[0].body).toBe(JSON.stringify({ mode: 'cheap' })); + }); + + it('a non-leader still fires the fast switch on an operator command (the active pane may not be the leader, AC4)', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => false, + }); + worker.onOperatorCommand('http://proxy'); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(1); + expect(setModePosts(api)[0].body).toBe(JSON.stringify({ mode: 'fast' })); + }); + + it('defaults to leader when no probe is supplied (legacy/no-coordination single instance)', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ fetcher: api.fetcher, now }); + advance(900_000); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(1); + }); +}); + +describe('shared activity broadcast (AC2/AC4/AC6)', () => { + let dir: string; + + beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'wl-mode-activity-')); + }); + + afterEach(() => { + rmSync(dir, { recursive: true, force: true }); + }); + + it('an operator command broadcasts mode-activity.json into the coordination dir', async () => { + clock = 5_000_000; + const api = mockAdminApi(); + const worker = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => false, + coordinationDir: dir, + }); + worker.onOperatorCommand('http://proxy'); + await flushAsync(); + expect(existsSync(join(dir, MODE_ACTIVITY_FILE))).toBe(true); + expect(readSharedActivity(dir)).toBe(5_000_000); + }); + + it('the idle leader reads the active pane\'s shared activity and does NOT cheap-switch (no flip-flop, AC2/AC4)', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + // Two panes on one machine, one coordination dir. The idle pane is the + // downtime leader; the active pane is a non-leader. + const idleLeader = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => true, + coordinationDir: dir, + }); + const activeNonLeader = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => false, + coordinationDir: dir, + }); + // Almost a full idle window passes; the active pane then receives a + // command and broadcasts its activity (local clock alone would switch). + advance(899_000); + activeNonLeader.onOperatorCommand('http://proxy'); + await flushAsync(); + api.reset(); + await idleLeader.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + // Shared activity from the other pane keeps the leader in fast mode. + expect(setModePosts(api)).toHaveLength(0); + }); + + it('the leader cheap-switches once the shared activity ages past the threshold', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + writeSharedActivity(dir, clock); // activity recorded "now" + const leader = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => true, + coordinationDir: dir, + }); + advance(900_000); + await leader.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(1); + expect(setModePosts(api)[0].body).toBe(JSON.stringify({ mode: 'cheap' })); + }); + + it('falls back to the local clock when the shared file is unreadable (AC6, fail-closed)', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + writeFileSync(join(dir, MODE_ACTIVITY_FILE), '{ not valid json', 'utf8'); + const worker = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => true, + coordinationDir: dir, + }); + expect(readSharedActivity(dir)).toBeNull(); + advance(900_000); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + // Local clock is authoritative when the shared state is unreadable. + expect(setModePosts(api)).toHaveLength(1); + expect(setModePosts(api)[0].body).toBe(JSON.stringify({ mode: 'cheap' })); + }); + + it('writeSharedActivity is monotonic — a stale timestamp never regresses a newer one', () => { + expect(writeSharedActivity(dir, 5_000)).toBe(true); + expect(writeSharedActivity(dir, 3_000)).toBe(true); + expect(readSharedActivity(dir)).toBe(5_000); + }); + + it('readSharedActivity/writeSharedActivity are no-ops when no coordination dir is supplied', () => { + expect(writeSharedActivity(undefined, 1)).toBe(false); + expect(readSharedActivity(undefined)).toBeNull(); + }); + + it('writeSharedActivity returns false when the coordination path is unwritable (AC6)', () => { + // A regular file used as a directory: mkdir/write cannot succeed. + const filePath = join(dir, 'not-a-dir'); + writeFileSync(filePath, 'x', 'utf8'); + expect(writeSharedActivity(join(filePath, 'sub'), 1)).toBe(false); + expect(readSharedActivity(join(filePath, 'sub'))).toBeNull(); + }); +}); + +describe('graceful leader transitions (AC5)', () => { + let dir: string; + + beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'wl-mode-activity-')); + }); + + afterEach(() => { + rmSync(dir, { recursive: true, force: true }); + }); + + it('a new leader reads shared activity and continues from the correct state (no spurious switch during election)', async () => { + clock = 1_000_000; + const api = mockAdminApi(); + let leader = false; + const worker = createModeSwitchWorker({ + fetcher: api.fetcher, + now, + isLeader: () => leader, + coordinationDir: dir, + }); + advance(900_000); + + // Before the handover the instance is a non-leader: it never switches. + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(0); + + // Another pane was active 10s ago — recorded in the shared file. + writeSharedActivity(dir, clock - 10_000); + + // Leadership handover. The new leader must honour the shared recent + // activity and NOT spuriously switch to cheap during the election. + leader = true; + api.reset(); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(0); + + // Once the shared activity ages past the threshold the new leader + // resumes normal cheap switching. + advance(900_000); + await worker.tick({ + enabled: true, + idleThresholdMs: 900_000, + proxyUrl: 'http://proxy', + proxyStatus: idleStatus(), + }); + await flushAsync(); + expect(setModePosts(api)).toHaveLength(1); + }); +}); + +describe('60-minute default (AC3)', () => { + it('defaults the idle threshold to 3_600_000 ms and clamps invalid input to it', () => { + expect(DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS).toBe(3_600_000); + expect(clampModeSwitchIdleThresholdMs(NaN)).toBe(3_600_000); + expect(clampModeSwitchIdleThresholdMs(-1)).toBe(3_600_000); + // The 60s floor is unchanged. + expect(clampModeSwitchIdleThresholdMs(1_000)).toBe(MODE_SWITCH_IDLE_THRESHOLD_FLOOR_MS); + }); }); \ No newline at end of file diff --git a/packages/herdr/src/mode-switch-worker.ts b/packages/herdr/src/mode-switch-worker.ts index a8f97a9ad..6b3fc3e25 100644 --- a/packages/herdr/src/mode-switch-worker.ts +++ b/packages/herdr/src/mode-switch-worker.ts @@ -9,12 +9,28 @@ * the plugin (WL-0MSN3FWV5008KQE9), the worker records the operator * timestamp and fire-and-forget POSTs `/admin/set-mode {"mode":"fast"}`. * A failed switch never blocks or delays the command dispatch (fail-open: - * the pane opens regardless). + * the pane opens regardless). The fast switch fires on the instance that + * received the command, whichever pane that is — see the leader note below. + * - **Leader-only cheap switching (WL-0MU6MXCZZ007ZXT9, AC1):** only the + * downtime leader (`DowntimeWorker.isLeader`, reused — no separate + * election) runs the idle cheap-switch logic. Non-leader instances skip + * `tick()` entirely, so idle panes can no longer flip the shared proxy to + * cheap behind an active pane's back (the flip-flop fix). The leader probe + * is read live each tick, so a leadership handover is honoured on the next + * tick (AC5). + * - **Shared activity broadcast (AC2):** every instance writes its latest + * operator-command timestamp to `mode-activity.json` in the coordination + * directory (`getMachineCoordinationDir()`, the same dir as the downtime + * leader lease) and the leader reads it each tick. The idle clock is the + * max of the local clock and the shared timestamp, so the proxy stays fast + * while **any** pane has recent activity. A read/write failure falls back + * to the local clock (AC6, fail-closed: never a premature cheap switch). * - **Cheap switch on idle:** on each tick (scheduler task, or the downtime - * dispatcher's `onProxyIdle` callback), when the operator has been idle - * (no agent-route commands) for ≥ `modeSwitchIdleThresholdMs` **AND** the - * proxy reports idle (reusing `evaluateIdle` from downtime-worker.ts), the - * worker POSTs `/admin/set-mode {"mode":"cheap"}`. + * dispatcher's `onProxyIdle` callback — the leader is the only pane that + * runs that dispatcher), when the operator has been idle + * (no agent-route commands on any pane) for ≥ `modeSwitchIdleThresholdMs` + * **AND** the proxy reports idle (reusing `evaluateIdle` from + * downtime-worker.ts), the worker POSTs `/admin/set-mode {"mode":"cheap"}`. * **Per-slot operator gate (parent WL-0MT9F67Y3008S0PR, decision 1.a):** * when the proxy serves per-slot identity (`slots[]` valid per * `parseLlamaStatus`), the idle gate requires only ≥ 1 free slot @@ -59,6 +75,8 @@ * paused). Both call the same fail-closed `tick()`. */ +import { existsSync, mkdirSync, readFileSync, renameSync, writeFileSync } from 'node:fs'; +import { join } from 'node:path'; import { evaluateIdle, parseLlamaStatus, @@ -75,8 +93,8 @@ export const ADMIN_MODE_PATH = '/admin/mode'; /** Proxy mode-switch endpoint path. */ export const ADMIN_SET_MODE_PATH = '/admin/set-mode'; -/** Default idle window before switching to cheap mode: 30 minutes. */ -export const DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS = 1_800_000; +/** Default idle window before switching to cheap mode: 60 minutes. */ +export const DEFAULT_MODE_SWITCH_IDLE_THRESHOLD_MS = 3_600_000; /** * Defensive floor for the idle threshold (60s): a trivially small window @@ -111,7 +129,7 @@ export const MODE_SWITCH_RUN_TIMEOUT_MS = 30_000; /** * Clamp the mode-switch idle threshold: reject negative/non-finite (fall - * back to the 30-minute default) and floor at 60s so the operator cannot + * back to the 60-minute default) and floor at 60s so the operator cannot * configure an immediate cheap-switch. */ export function clampModeSwitchIdleThresholdMs(value: number): number { @@ -133,6 +151,76 @@ export function clampModeSwitchPollIntervalMs(value: number): number { ); } +// ── Shared activity (cross-pane arbitration) ───────────────────────── + +/** + * Name of the shared activity file written into the coordination directory. + * Every mode-switch worker instance (leader and non-leader alike) broadcasts + * its latest operator-command timestamp here so the downtime leader can + * evaluate idleness against activity from *any* pane (AC2). The file is a + * tiny JSON object (`{ "lastActivityAt": }`) written atomically. + */ +export const MODE_ACTIVITY_FILE = 'mode-activity.json'; + +/** Shared activity record shape (tolerant reader). */ +interface ModeActivityRecord { + lastActivityAt: number; +} + +/** + * Read the shared operator-activity timestamp from the coordination + * directory. Returns the epoch-ms timestamp, or null when the coordination + * directory is unset, the file is absent/unreadable/malformed, or the value + * is not a finite number. A null result makes the caller fall back to its + * local clock (fail-closed, AC6) — never a premature cheap switch. + */ +export function readSharedActivity(coordinationDir: string | undefined): number | null { + if (!coordinationDir) return null; + try { + const path = join(coordinationDir, MODE_ACTIVITY_FILE); + if (!existsSync(path)) return null; + const raw: unknown = JSON.parse(readFileSync(path, 'utf8')); + if (typeof raw !== 'object' || raw === null) return null; + const ts = (raw as Partial).lastActivityAt; + return typeof ts === 'number' && Number.isFinite(ts) ? ts : null; + } catch { + return null; // unreadable / invalid JSON → fall back to the local clock + } +} + +/** + * Broadcast an operator-activity timestamp to the shared activity file so + * every pane's mode-switch worker sees it (AC2). The write is atomic (temp + * file + rename) and monotonic (never regresses an existing newer value). + * Returns true on success and false when the coordination directory is unset + * or the write fails — the caller then relies on its local clock (AC6). + */ +export function writeSharedActivity( + coordinationDir: string | undefined, + timestamp: number, +): boolean { + if (!coordinationDir) return false; + try { + mkdirSync(coordinationDir, { recursive: true }); + const path = join(coordinationDir, MODE_ACTIVITY_FILE); + const existing = readSharedActivity(coordinationDir); + const value = existing !== null ? Math.max(existing, timestamp) : timestamp; + const payload = JSON.stringify({ lastActivityAt: value }); + const tmp = `${path}.tmp-${process.pid}-${Date.now()}`; + writeFileSync(tmp, payload, 'utf8'); + try { + renameSync(tmp, path); + } catch { + // rename-over-existing is not portable (Windows); fall back to a + // direct small synchronous write. + writeFileSync(path, payload, 'utf8'); + } + return true; + } catch { + return false; // permission/IO error → local clock only (AC6) + } +} + // ── Types ───────────────────────────────────────────────────────────── /** Proxy operating mode: 'fast' (cloud-backed) or 'cheap' (local-first). */ @@ -298,6 +386,40 @@ export interface ModeSwitchWorker { * fail-closed (no switch) and never throw. */ tick(opts: ModeSwitchTickOptions): Promise; + /** + * The most recently observed proxy mode, or `null` when it has not been + * resolved yet (mode switching disabled, or no poll/switch has run). + * Consumed by the downtime dispatcher's mode-aware + * `AUDIT_PHASE2_PARALLELISM` decision (WL-0MT50S9JW001DHME): an unknown + * mode (`null`) conservatively maps to the serial `'1'` default. + */ + getLastKnownMode(): ProxyMode | null; +} + +/** + * Optional dependencies and coordination hooks for the mode-switch worker. + * All fields are injectable for tests; production (index.ts) passes only + * `isLeader` and `coordinationDir`. + */ +export interface ModeSwitchWorkerOptions { + /** Injectable HTTP fetcher (tests). */ + fetcher?: AdminApiFetcher; + /** Injectable time source (tests). */ + now?: Now; + /** + * Leadership probe reused from the downtime worker + * (`DowntimeWorker.isLeader` — constraint: reuse the existing election). + * Read live on every tick so a leadership handover is honoured without + * reconstructing the worker (AC1/AC5). Defaults to `() => true`: with no + * coordination there is exactly one instance and it is always the leader. + */ + isLeader?: () => boolean; + /** + * Machine-wide coordination directory containing the shared activity file + * (AC2). When absent the worker keeps the original process-local idle + * clock (no shared state). + */ + coordinationDir?: string; } /** @@ -306,17 +428,29 @@ export interface ModeSwitchWorker { * so after a plugin restart the proxy stays fast until a fresh full idle * window passes (fail-safe, operator decision Q3: "a"). * - * @param deps - Injectable fetcher/time (tests). + * @param deps - Injectable fetcher/time plus the leader probe and shared + * activity-coordination directory (tests / index.ts). */ -export function createModeSwitchWorker(deps?: { - fetcher?: AdminApiFetcher; - now?: Now; -}): ModeSwitchWorker { +export function createModeSwitchWorker(deps?: ModeSwitchWorkerOptions): ModeSwitchWorker { const fetcher = deps?.fetcher ?? (globalThis.fetch as unknown as AdminApiFetcher); const now = deps?.now ?? Date.now; + const isLeader = deps?.isLeader ?? (() => true); + const coordinationDir = deps?.coordinationDir; /** Last operator agent-route command timestamp; construction = "now" (restart reset). */ let lastOperatorCommandAt: number = now(); + + /** + * Latest operator-activity timestamp across all panes: the max of this + * process's local clock and the shared activity file. Falls back to the + * local clock when the shared state is unreadable or unwritable (AC6, + * fail-closed: never a premature cheap switch off stale cross-pane state). + */ + const effectiveLastActivityAt = (): number => { + const shared = readSharedActivity(coordinationDir); + if (shared === null) return lastOperatorCommandAt; + return Math.max(lastOperatorCommandAt, shared); + }; /** Last known proxy mode (refreshed via GET /admin/mode on each poll). */ let lastKnownMode: ProxyMode | null = null; /** True while a mode-switch POST is in flight (per-process single-flight). */ @@ -348,20 +482,41 @@ export function createModeSwitchWorker(deps?: { return { onOperatorCommand(proxyUrl: string): void { - // Record operator activity (agent-route command). + // Record operator activity (agent-route command) on the local clock. lastOperatorCommandAt = now(); - // Fire-and-forget fast switch (fail-open: never blocks dispatch). + // Broadcast to every pane — leader and non-leader alike — so the + // downtime leader's idle evaluation sees activity from any pane (AC2). + // A failed broadcast leaves this process's local clock authoritative + // (AC6, fail-closed). + writeSharedActivity(coordinationDir, lastOperatorCommandAt); + // Fire-and-forget fast switch on the instance that received the + // command (fail-open: never blocks dispatch). Fast is always the safe + // direction, and the operator's active pane may not be the downtime + // leader — gating fast on leadership would leave the proxy in cheap + // while the operator is actively working (AC4). Only the *cheap* idle + // switch is leader-gated; see tick() (AC1). void fireSwitch(proxyUrl, 'fast'); }, + getLastKnownMode(): ProxyMode | null { + return lastKnownMode; + }, + async tick(opts: ModeSwitchTickOptions): Promise { if (!opts.enabled) return; + // Leader-only cheap switching (AC1): non-leader instances skip the + // entire idle cheap-switch logic (no proxy status fetch, no mode read, + // no POST). The probe is read live so a leadership handover is picked + // up on the next tick (AC5). + if (!isLeader()) return; if (switchInFlight) return; // single-flight: a switch is settling - // Idle window: has the operator issued no agent-route command for ≥ - // the threshold? (lastOperatorCommandAt can never be null — restart - // resets to "active now", so a fresh full window is always required.) - const elapsed = now() - lastOperatorCommandAt; + // Idle window: has there been no operator agent-route command on ANY + // pane for ≥ the threshold? (local clock max shared activity, AC2; a + // shared read failure falls back to the local clock, AC6. The local + // clock can never be null — restart resets to "active now", so a fresh + // full window is always required.) + const elapsed = now() - effectiveLastActivityAt(); if (elapsed < opts.idleThresholdMs) return; // Fetch proxy status when not provided (the worker fetches its own diff --git a/packages/herdr/src/pane-lifecycle.test.ts b/packages/herdr/src/pane-lifecycle.test.ts new file mode 100644 index 000000000..fa3f0ffd8 --- /dev/null +++ b/packages/herdr/src/pane-lifecycle.test.ts @@ -0,0 +1,212 @@ +/** + * Unit tests for pane-lifecycle.ts — the pure pane-lifecycle classifier and + * rolling-log collectors for the downtime worker's auto-close monitor + * (WL-0MU308WSF0002JWN, child WL-0MU4URK4H006OFCE). + * + * These tests pin the decision contract: which outcomes are produced, which + * kinds are auto-closed (everything except `implement` — AC6), and the + * idempotency keys that stop duplicate log entries. + */ + +import { describe, it, expect } from 'vitest'; +import { + shouldAutoClosePane, + collectDispatchedPanes, + loggedPaneLifecycleKeys, + paneLifecycleKey, + classifyPaneLifecycle, + type DispatchedPane, + type PaneItemState, +} from './pane-lifecycle.js'; +import type { DowntimeLogEntry } from './downtime-log.js'; + +function pane(overrides: Partial = {}): DispatchedPane { + return { + itemId: 'WL-1', + itemTitle: 'Test item', + paneId: 'w1:p1', + kind: 'plan', + dispatchedAt: '2026-01-01T00:00:00.000Z', + stage: 'intake_complete', + ...overrides, + }; +} + +function item(overrides: Partial = {}): PaneItemState { + return { id: 'WL-1', title: 'Test item', stage: 'intake_complete', ...overrides }; +} + +describe('shouldAutoClosePane (AC6 — implement is never auto-closed)', () => { + it('excludes implement and includes every other dispatch kind', () => { + expect(shouldAutoClosePane('implement')).toBe(false); + expect(shouldAutoClosePane('plan')).toBe(true); + expect(shouldAutoClosePane('intake')).toBe(true); + expect(shouldAutoClosePane('audit')).toBe(true); + expect(shouldAutoClosePane('risk-effort')).toBe(true); + }); +}); + +describe('collectDispatchedPanes', () => { + it('reconstructs panes from enrichment entries carrying a resolved paneId', () => { + const entries: DowntimeLogEntry[] = [ + { itemId: 'WL-1', kind: 'plan', title: 'Plan me', dispatchedAt: '2026-01-01T00:00:00.000Z', stage: 'intake_complete' }, + { itemId: 'WL-1', kind: 'plan', title: 'Plan me', dispatchedAt: '2026-01-01T00:00:00.000Z', stage: 'intake_complete', paneId: 'w1:p1', enrichment: true }, + ]; + const panes = collectDispatchedPanes(entries); + expect(panes).toHaveLength(1); + expect(panes[0]).toMatchObject({ itemId: 'WL-1', paneId: 'w1:p1', kind: 'plan', itemTitle: 'Plan me' }); + }); + + it('ignores entries without a paneId, without an itemId, of an unmanaged kind, or spawn-failed', () => { + const entries: DowntimeLogEntry[] = [ + { itemId: 'WL-1', kind: 'plan' }, // no paneId → not closeable + { kind: 'plan', paneId: 'w1:p2' }, // no itemId + { itemId: 'WL-3', kind: 'scheduled', paneId: 'w1:p3' }, // unmanaged kind + { itemId: 'WL-4', kind: 'audit', paneId: 'w1:p4', outcome: 'spawn-failed' }, // never appeared + { entryType: 'pane-close', paneId: 'w1:p5', itemId: 'WL-5' }, // lifecycle entry, not a dispatch + ]; + expect(collectDispatchedPanes(entries)).toEqual([]); + }); + + it('keeps the most recent entry per pane id', () => { + const entries: DowntimeLogEntry[] = [ + { itemId: 'WL-1', kind: 'plan', title: 'old', paneId: 'w1:p1', dispatchedAt: '2026-01-01T00:00:00.000Z' }, + { itemId: 'WL-1', kind: 'plan', title: 'new', paneId: 'w1:p1', dispatchedAt: '2026-01-02T00:00:00.000Z' }, + ]; + const panes = collectDispatchedPanes(entries); + expect(panes).toHaveLength(1); + expect(panes[0].itemTitle).toBe('new'); + expect(panes[0].dispatchedAt).toBe('2026-01-02T00:00:00.000Z'); + }); +}); + +describe('loggedPaneLifecycleKeys / paneLifecycleKey', () => { + it('collects the pane+outcome+reasonCode keys already recorded', () => { + const entries: DowntimeLogEntry[] = [ + { entryType: 'pane-close', paneId: 'w1:p1', outcome: 'closed-as-plan-complete', reasonCode: 'none' }, + { entryType: 'pane-close', paneId: 'w1:p2', outcome: 'requires-attention' }, // missing reasonCode → 'none' + { itemId: 'WL-1', kind: 'plan', paneId: 'w1:p3' }, // not a pane-close entry + ]; + const keys = loggedPaneLifecycleKeys(entries); + expect(keys.has(paneLifecycleKey('w1:p1', 'closed-as-plan-complete', 'none'))).toBe(true); + expect(keys.has(paneLifecycleKey('w1:p2', 'requires-attention', 'none'))).toBe(true); + expect(keys.size).toBe(2); + }); +}); + +describe('classifyPaneLifecycle — terminal close outcomes (AC2)', () => { + it('intake pane at intake_complete → closed-as-intake-complete (close)', () => { + const d = classifyPaneLifecycle(pane({ kind: 'intake' }), item({ stage: 'intake_complete' }), false); + expect(d).toMatchObject({ outcome: 'closed-as-intake-complete', close: true }); + }); + + it('plan pane at plan_complete → closed-as-plan-complete (close)', () => { + const d = classifyPaneLifecycle(pane({ kind: 'plan' }), item({ stage: 'plan_complete' }), false); + expect(d).toMatchObject({ outcome: 'closed-as-plan-complete', close: true }); + }); + + it('an intake pane whose item skipped ahead to plan_complete is still closed as intake-complete', () => { + const d = classifyPaneLifecycle(pane({ kind: 'intake' }), item({ stage: 'plan_complete' }), false); + expect(d).toMatchObject({ outcome: 'closed-as-intake-complete', close: true }); + }); + + it('risk-effort pane at plan_complete with risk+effort populated → closed-as-plan-complete (close)', () => { + const d = classifyPaneLifecycle( + pane({ kind: 'risk-effort' }), + item({ stage: 'plan_complete', risk: 'Low', effort: 'Small' }), + false, + ); + expect(d).toMatchObject({ outcome: 'closed-as-plan-complete', close: true }); + }); + + it('risk-effort pane at plan_complete WITHOUT risk/effort stays open while the agent runs', () => { + expect( + classifyPaneLifecycle(pane({ kind: 'risk-effort' }), item({ stage: 'plan_complete' }), false), + ).toBeNull(); + }); +}); + +describe('classifyPaneLifecycle — audit outcomes (AC5)', () => { + it('audit recorded + passed → audit-passed (close)', () => { + const d = classifyPaneLifecycle( + pane({ kind: 'audit' }), + item({ stage: 'in_review', auditedAt: '2026-01-02T00:00:00.000Z', auditResult: true }), + false, + ); + expect(d).toMatchObject({ outcome: 'audit-passed', close: true }); + }); + + it('audit recorded + failed → audit-failed (close)', () => { + const d = classifyPaneLifecycle( + pane({ kind: 'audit' }), + item({ stage: 'in_review', auditedAt: '2026-01-02T00:00:00.000Z', auditResult: false }), + false, + ); + expect(d).toMatchObject({ outcome: 'audit-failed', close: true }); + }); + + it('audit recorded with no explicit verdict defaults to passed', () => { + const d = classifyPaneLifecycle( + pane({ kind: 'audit' }), + item({ stage: 'in_review', auditedAt: '2026-01-02T00:00:00.000Z' }), + false, + ); + expect(d).toMatchObject({ outcome: 'audit-passed', close: true }); + }); + + it('audit pane whose agent ended without a result → requires-attention (close)', () => { + const d = classifyPaneLifecycle(pane({ kind: 'audit' }), item({ stage: 'in_review' }), true); + expect(d).toMatchObject({ outcome: 'requires-attention', reasonCode: 'audit-ended-no-result', close: true }); + }); + + it('audit pane still in flight → null', () => { + expect(classifyPaneLifecycle(pane({ kind: 'audit' }), item({ stage: 'in_review' }), false)).toBeNull(); + }); +}); + +describe('classifyPaneLifecycle — implement is logged but never closed (AC4/AC6)', () => { + it('implement pane at in_review → requires-attention, close:false', () => { + const d = classifyPaneLifecycle(pane({ kind: 'implement' }), item({ stage: 'in_review' }), false); + expect(d).toMatchObject({ outcome: 'requires-attention', reasonCode: 'reached-in-review', close: false }); + }); + + it('implement pane whose agent ended before in_review → requires-attention, close:false', () => { + const d = classifyPaneLifecycle(pane({ kind: 'implement' }), item({ stage: 'plan_complete' }), true); + expect(d).toMatchObject({ outcome: 'requires-attention', reasonCode: 'agent-ended-no-terminal', close: false }); + }); + + it('implement pane still running → null', () => { + expect(classifyPaneLifecycle(pane({ kind: 'implement' }), item({ stage: 'plan_complete' }), false)).toBeNull(); + }); +}); + +describe('classifyPaneLifecycle — requires-attention (AC3)', () => { + it('an item awaiting producer review → requires-attention (close)', () => { + const d = classifyPaneLifecycle( + pane({ kind: 'plan' }), + item({ stage: 'intake_complete', needsProducerReview: true }), + false, + ); + expect(d).toMatchObject({ outcome: 'requires-attention', reasonCode: 'producer-review', close: true }); + }); + + it('a plan agent that ended without reaching plan_complete → requires-attention (close)', () => { + const d = classifyPaneLifecycle(pane({ kind: 'plan' }), item({ stage: 'intake_complete' }), true); + expect(d).toMatchObject({ outcome: 'requires-attention', reasonCode: 'agent-ended-no-terminal', close: true }); + }); + + it('a risk-effort agent that ended without populating risk/effort → requires-attention (close)', () => { + const d = classifyPaneLifecycle(pane({ kind: 'risk-effort' }), item({ stage: 'plan_complete' }), true); + expect(d).toMatchObject({ outcome: 'requires-attention', reasonCode: 'risk-effort-incomplete', close: true }); + }); + + it('a still-working pane with no terminal → null (no action)', () => { + expect(classifyPaneLifecycle(pane({ kind: 'plan' }), item({ stage: 'intake_complete' }), false)).toBeNull(); + }); + + it('a missing item is tolerated (agent done → requires-attention, never a throw)', () => { + const d = classifyPaneLifecycle(pane({ kind: 'plan' }), null, true); + expect(d).toMatchObject({ outcome: 'requires-attention', close: true }); + expect(classifyPaneLifecycle(pane({ kind: 'plan' }), null, false)).toBeNull(); + }); +}); diff --git a/packages/herdr/src/pane-lifecycle.ts b/packages/herdr/src/pane-lifecycle.ts new file mode 100644 index 000000000..dd84c27dc --- /dev/null +++ b/packages/herdr/src/pane-lifecycle.ts @@ -0,0 +1,351 @@ +/** + * packages/herdr/src/pane-lifecycle.ts — Pane-lifecycle monitor (pure logic) + * + * Supporting logic for the downtime worker's automatic pane lifecycle + * management (WL-0MU308WSF0002JWN): dispatched panes stay open forever + * unless an operator closes them manually. This module classifies each + * dispatched pane's current state into a lifecycle outcome and decides + * whether the pane should be auto-closed (everything except `implement`, + * which is never auto-closed — AC6). + * + * The module is deliberately PURE (no fs / no herdr / no wl): the worker + * gathers the dispatch markers + current item states, this module decides, + * and the worker performs the log append + pane close. That keeps the + * decision logic trivially testable and the fail-closed I/O at the + * orchestration boundary. + * + * Outcomes (AC1): + * - `closed-as-intake-complete` — an `intake` pane's item reached + * `intake_complete` (or beyond). + * - `closed-as-plan-complete` — a `plan`/`risk-effort` pane's item reached + * `plan_complete` (risk-effort additionally requires risk+effort set). + * - `audit-passed` / `audit-failed` — an `audit` pane's item has a + * recorded audit result (`readyToClose`). + * - `requires-attention` — the pane ended (or is blocked) without reaching + * a closeable terminal: agent session ended early, an item awaiting + * producer review, an audit that never recorded a result, or an + * `implement` pane that reached `in_review` (logged, NOT closed — AC4). + */ + +import type { DowntimeLogEntry, PaneLifecycleKind } from './downtime-log.js'; + +// ── Types ───────────────────────────────────────────────────────────── + +/** + * Stable machine-readable reason for a lifecycle decision. Used as part of + * the idempotency key so a state CHANGE (e.g. `requires-attention` because + * the agent ended → `requires-attention` because the item later reached + * `in_review`) is logged again while a repeated identical state is not + * (intake Q&A: "if the pane is still open and the item changes again, log + * the new state"). + */ +export type PaneLifecycleReasonCode = + | 'none' + | 'agent-ended-no-terminal' + | 'reached-in-review' + | 'audit-ended-no-result' + | 'risk-effort-incomplete' + | 'producer-review'; + +/** + * One dispatched pane reconstructed from the rolling dispatch log. The + * enrichment entry (WL-0MUBVL251006JAQ0) records `paneId` alongside the + * marker fields; a dispatch with no enrichment (older entries, or a failed + * pane-id resolution) cannot be auto-closed. + */ +export interface DispatchedPane { + itemId: string; + itemTitle: string; + paneId: string; + kind: PaneLifecycleKind; + dispatchedAt: string; + /** Worklog stage at dispatch (change-guard marker). */ + stage?: string; +} + +/** + * The subset of the current work-item state the lifecycle classifier + * consults. Every field is optional / tolerant so a partially fetched or + * malformed item never throws. + */ +export interface PaneItemState { + id: string; + title?: string; + status?: string; + stage?: string; + risk?: string; + effort?: string; + auditedAt?: string | null; + /** + * Recorded audit verdict (`readyToClose`). `false` explicitly means the + * audit FAILED; `true`/`null`/absent (with an `auditedAt`) means passed + * (an audit with no recorded readyToClose is treated as a pass — the + * historical default, WL-0MTH7G2O1004BHN5). + */ + auditResult?: boolean | null; + needsProducerReview?: boolean; + /** Agent session state for the pane (idle/working/blocked/done/unknown). */ + agentState?: string; +} + +/** A decision for one dispatched pane. */ +export interface PaneLifecycleDecision { + outcome: import('./downtime-log.js').PaneLifecycleOutcome; + /** Human-readable summary reason (always populated). */ + reason: string; + /** Stable idempotency reason code. */ + reasonCode: PaneLifecycleReasonCode; + /** Whether the worker should close the pane. `false` only for `implement`. */ + close: boolean; +} + +// ── Constants ───────────────────────────────────────────────────────── + +/** Worklog stage rank — higher means further through the lifecycle. */ +const STAGE_RANK: Record = { + idea: 0, + intake_complete: 1, + plan_complete: 2, + in_review: 3, +}; + +/** The dispatch kinds the pane-lifecycle monitor manages. */ +const LIFECYCLE_KINDS: readonly PaneLifecycleKind[] = [ + 'plan', + 'intake', + 'audit', + 'risk-effort', + 'implement', +]; + +// ── Helpers ─────────────────────────────────────────────────────────── + +function isLifecycleKind(kind: unknown): kind is PaneLifecycleKind { + return typeof kind === 'string' && (LIFECYCLE_KINDS as readonly string[]).includes(kind); +} + +function stageRank(stage: string | undefined): number { + if (typeof stage !== 'string') return -1; + return STAGE_RANK[stage] ?? -1; +} + +/** + * AC6: `implement` panes are NEVER auto-closed — the operator closes them + * manually. Every other kind (plan / intake / audit / risk-effort) is + * auto-closed once its lifecycle outcome is determined. + */ +export function shouldAutoClosePane(kind: PaneLifecycleKind): boolean { + return kind !== 'implement'; +} + +/** + * Build the idempotency key for one (pane, outcome, reason) triple. A + * pane-close entry with a matching key suppresses a duplicate log entry on + * a later tick. + */ +export function paneLifecycleKey( + paneId: string, + outcome: string, + reasonCode: string, +): string { + return `${paneId}::${outcome}::${reasonCode}`; +} + +// ── Collection from the rolling log ─────────────────────────────────── + +/** + * Reconstruct the set of dispatched panes from the rolling dispatch log: + * every entry that carries BOTH an `itemId` and a resolved `paneId` of a + * managed kind. Spawn-failed entries are excluded (the pane never + * appeared). The LAST entry per pane id wins (a re-dispatch updates the + * marker), so the returned list holds at most one record per pane. + */ +export function collectDispatchedPanes(entries: DowntimeLogEntry[]): DispatchedPane[] { + const byPane = new Map(); + for (const e of entries) { + if (e.outcome === 'spawn-failed') continue; + if (!isLifecycleKind(e.kind)) continue; + if (typeof e.itemId !== 'string' || e.itemId === '') continue; + if (typeof e.paneId !== 'string' || e.paneId === '') continue; + byPane.set(e.paneId, { + itemId: e.itemId, + itemTitle: typeof e.title === 'string' && e.title !== '' ? e.title : e.itemId, + paneId: e.paneId, + kind: e.kind, + dispatchedAt: typeof e.dispatchedAt === 'string' ? e.dispatchedAt : '', + stage: typeof e.stage === 'string' ? e.stage : undefined, + }); + } + return [...byPane.values()]; +} + +/** + * Build the set of lifecycle keys already recorded in the log, so the + * monitor never writes a duplicate pane-close entry for an unchanged state. + */ +export function loggedPaneLifecycleKeys(entries: DowntimeLogEntry[]): Set { + const keys = new Set(); + for (const e of entries) { + if (e.entryType !== 'pane-close') continue; + if (typeof e.paneId !== 'string' || e.paneId === '') continue; + const outcome = typeof e.outcome === 'string' ? e.outcome : ''; + const reasonCode = typeof e.reasonCode === 'string' ? e.reasonCode : 'none'; + keys.add(paneLifecycleKey(e.paneId, outcome, reasonCode)); + } + return keys; +} + +// ── Classification ──────────────────────────────────────────────────── + +function decision( + kind: PaneLifecycleKind, + outcome: PaneLifecycleDecision['outcome'], + reason: string, + reasonCode: PaneLifecycleReasonCode, +): PaneLifecycleDecision { + return { outcome, reason, reasonCode, close: shouldAutoClosePane(kind) }; +} + +/** + * Classify one dispatched pane's lifecycle outcome from its current item + * state. Returns `null` when the pane has not yet reached any terminal or + * attention state (i.e. the agent is still legitimately working) — the + * caller logs/closes nothing this tick. + * + * `agentDone` is the authoritative "the pane's agent session has ended" + * signal (the pane is gone from `herdr agent list`, or reported `done`); + * it is passed explicitly so the pure classifier never queries herdr. + * + * Precedence (first match wins): + * 1. audit result recorded (`auditedAt`) → audit-passed/failed (AC5) + * 2. kind terminal reached → closed-as-* (AC2); for + * `implement` this is `in_review` and is logged only, never closed (AC4/AC6) + * 3. item awaiting producer review → requires-attention (AC3) + * 4. agent session ended without a terminal → requires-attention (AC3) + * 5. otherwise → null (still running) + */ +export function classifyPaneLifecycle( + dispatch: DispatchedPane, + item: PaneItemState | null, + agentDone: boolean, +): PaneLifecycleDecision | null { + const kind = dispatch.kind; + const title = item?.title ?? dispatch.itemTitle; + + // 1. Audit panes (AC5): complete when the item has a recorded audit. + if (kind === 'audit') { + if (item && typeof item.auditedAt === 'string' && item.auditedAt !== '') { + const passed = item.auditResult !== false; + return decision( + kind, + passed ? 'audit-passed' : 'audit-failed', + passed + ? `audit recorded for ${title} — passed` + : `audit recorded for ${title} — failed`, + 'none', + ); + } + if (item?.needsProducerReview === true) { + return decision( + kind, + 'requires-attention', + `${title} is awaiting producer review before the audit can complete`, + 'producer-review', + ); + } + if (agentDone) { + return decision( + kind, + 'requires-attention', + `audit agent session ended without recording an audit result for ${title}`, + 'audit-ended-no-result', + ); + } + return null; // audit still in flight + } + + // 2. Kind terminal reached. + if (item) { + const rank = stageRank(item.stage); + if (kind === 'intake' && rank >= stageRank('intake_complete')) { + return decision( + kind, + 'closed-as-intake-complete', + `${title} advanced to ${item.stage ?? 'intake_complete'} — intake complete`, + 'none', + ); + } + if (kind === 'plan' && rank >= stageRank('plan_complete')) { + return decision( + kind, + 'closed-as-plan-complete', + `${title} advanced to ${item.stage ?? 'plan_complete'} — plan complete`, + 'none', + ); + } + if (kind === 'risk-effort') { + const populated = + typeof item.risk === 'string' && item.risk !== '' && + typeof item.effort === 'string' && item.effort !== ''; + if (rank >= stageRank('plan_complete') && populated) { + return decision( + kind, + 'closed-as-plan-complete', + `${title} has risk/effort populated at ${item.stage ?? 'plan_complete'} — risk-effort complete`, + 'none', + ); + } + if (agentDone && rank >= stageRank('plan_complete') && !populated) { + return decision( + kind, + 'requires-attention', + `risk-effort agent session ended without populating risk/effort for ${title}`, + 'risk-effort-incomplete', + ); + } + if (agentDone) { + return decision( + kind, + 'requires-attention', + `risk-effort agent session ended before reaching plan_complete for ${title}`, + 'agent-ended-no-terminal', + ); + } + return null; + } + // implement (AC4/AC6): reaching in_review completes the implementation + // but the pane is NEVER auto-closed — log the event for the operator. + if (kind === 'implement' && rank >= stageRank('in_review')) { + return decision( + kind, + 'requires-attention', + `${title} reached in_review — implement panes are not auto-closed (AC6); close manually`, + 'reached-in-review', + ); + } + } + + // 3. Producer-review gate (AC3): a review-blocked item is not making + // progress — flag it so the pane does not linger silently. + if (item?.needsProducerReview === true) { + return decision( + kind, + 'requires-attention', + `${title} is awaiting producer review`, + 'producer-review', + ); + } + + // 4. Agent session ended without reaching a closeable terminal (AC3). + if (agentDone) { + return decision( + kind, + 'requires-attention', + `${title} agent session ended without reaching a terminal stage`, + 'agent-ended-no-terminal', + ); + } + + // 5. Still running. + return null; +} diff --git a/packages/herdr/src/plugin-startup.test.ts b/packages/herdr/src/plugin-startup.test.ts new file mode 100644 index 000000000..2f1f30777 --- /dev/null +++ b/packages/herdr/src/plugin-startup.test.ts @@ -0,0 +1,81 @@ +/** + * Plugin startup regression test (WL-0MUFRFLRQ004KNDG). + * + * The worklist plugin crashed on initialization with a temporal-dead-zone + * ReferenceError: `createDowntimeWorker` calls its `config()` callback + * SYNCHRONOUSLY during construction, and index.ts's callback referenced the + * `modeSwitchWorker` const that is declared AFTER the downtime worker — so + * the whole plugin died before the TUI ever rendered. + * + * This is an end-to-end guard: it runs the real entry point (the same command + * herdr's pane manifest uses, `npx tsx src/index.ts`) and asserts it reaches + * the TUI instead of crashing during wiring. + */ + +import { describe, it, expect } from 'vitest'; +import { spawn } from 'node:child_process'; +import { fileURLToPath } from 'node:url'; + +interface StartupResult { + code: number | null; + output: string; +} + +/** Run the plugin entry point and resolve with its combined output. */ +function runPluginStartup(cwd: string, timeoutMs: number): Promise { + return new Promise((resolve) => { + const child = spawn('npx', ['tsx', 'src/index.ts'], { + cwd, + // stdin is closed so the TUI tears down instead of blocking on input. + stdio: ['ignore', 'pipe', 'pipe'], + env: { ...process.env, HERDR_PANE_ID: '' }, + }); + let output = ''; + let settled = false; + const timer = setTimeout(() => finish(null), timeoutMs); + function finish(code: number | null): void { + if (settled) return; + settled = true; + clearTimeout(timer); + child.removeAllListeners(); + child.kill('SIGKILL'); // the TUI runs a render loop until killed + resolve({ code, output }); + } + const collect = (chunk: Buffer): void => { + output += chunk.toString(); + // Resolve as soon as the outcome is observable: the rendered TUI frame + // (construction completed) or the init-error prefix (it crashed). + if (output.includes('Work Items') || /before initialization|Worklog plugin error/.test(output)) { + finish(null); + } + }; + child.stdout.on('data', collect); + child.stderr.on('data', collect); + child.on('exit', (code) => finish(code)); + child.on('error', (err) => { + output += `spawn error: ${String(err)}`; + finish(null); + }); + }); +} + +describe('worklist plugin startup (WL-0MUFRFLRQ004KNDG)', () => { + it( + 'initializes past worker wiring without the modeSwitchWorker TDZ crash', + async () => { + const pluginRoot = fileURLToPath(new URL('..', import.meta.url)); + const { output } = await runPluginStartup(pluginRoot, 30_000); + + // The exact TDZ failure that crashed the plugin at startup. + expect(output).not.toMatch(/Cannot access 'modeSwitchWorker' before initialization/); + expect(output).not.toMatch(/before initialization/); + // Any init failure is surfaced on this prefix; none is allowed. + expect(output).not.toMatch(/Worklog plugin error/); + + // Reaching the TUI proves construction completed past the downtime + // worker (where config() runs synchronously) into the render loop. + expect(output).toContain('Work Items'); + }, + 60_000, + ); +}); diff --git a/packages/herdr/src/settings.test.ts b/packages/herdr/src/settings.test.ts index b9dec50fa..4a8511871 100644 --- a/packages/herdr/src/settings.test.ts +++ b/packages/herdr/src/settings.test.ts @@ -165,10 +165,10 @@ describe('modeSwitchEnabled', () => { }); describe('modeSwitchIdleThresholdMs', () => { - it('defaults to 1_800_000 ms (30 minutes)', () => { - expect(defaultSettings.modeSwitchIdleThresholdMs).toBe(1_800_000); + it('defaults to 3_600_000 ms (60 minutes)', () => { + expect(defaultSettings.modeSwitchIdleThresholdMs).toBe(3_600_000); const path = tempSettingsPath(); - expect(loadSettings(path).modeSwitchIdleThresholdMs).toBe(1_800_000); + expect(loadSettings(path).modeSwitchIdleThresholdMs).toBe(3_600_000); }); it('clamps a persisted value below the 60s floor up to the floor', () => { @@ -183,7 +183,7 @@ describe('modeSwitchIdleThresholdMs', () => { it('falls back to the default when the persisted value is not a number', () => { const path = tempSettingsPath(); writeFileSync(path, JSON.stringify({ ...defaultSettings, modeSwitchIdleThresholdMs: 'later' }), 'utf-8'); - expect(loadSettings(path).modeSwitchIdleThresholdMs).toBe(1_800_000); + expect(loadSettings(path).modeSwitchIdleThresholdMs).toBe(3_600_000); }); }); diff --git a/packages/herdr/src/settings.ts b/packages/herdr/src/settings.ts index e1733fe99..4a6d0cefd 100644 --- a/packages/herdr/src/settings.ts +++ b/packages/herdr/src/settings.ts @@ -87,7 +87,7 @@ export interface PluginSettings { */ modeSwitchEnabled: boolean; /** - * Idle window before switching to cheap mode (ms). Default 1_800_000 (30 min). + * Idle window before switching to cheap mode (ms). Default 3_600_000 (60 min). * A new operator agent-route command resets this timer. */ modeSwitchIdleThresholdMs: number; diff --git a/packages/herdr/src/worklist.test.ts b/packages/herdr/src/worklist.test.ts index 22b715ac4..77db68970 100644 --- a/packages/herdr/src/worklist.test.ts +++ b/packages/herdr/src/worklist.test.ts @@ -3291,6 +3291,28 @@ describe('renderDowntimeStatus', () => { expect(status).not.toContain('downtime idle'); }); + it('renders the held reason when a gate blocked the last tick (WL-0MU8808ZY0091JIA)', () => { + const worker = { + idleSince: Date.now() - 60_000, + dispatching: false, + enabled: true, + blockReason: 'slot-owner', + } as unknown as DowntimeWorker; + const status = renderDowntimeStatus(worker); + expect(status).toContain('downtime held: slot-owner'); + expect(status).not.toContain('downtime idle'); + }); + + it('renders plain idle when no gate blocked the last tick', () => { + const worker = { + idleSince: Date.now() - 60_000, + dispatching: false, + enabled: true, + blockReason: null, + } as unknown as DowntimeWorker; + expect(renderDowntimeStatus(worker)).toContain('downtime idle'); + }); + it('renders busy when the proxy is not idle', () => { const worker = { idleSince: null, diff --git a/packages/herdr/src/worklist.ts b/packages/herdr/src/worklist.ts index 51789ae25..36f39ced6 100644 --- a/packages/herdr/src/worklist.ts +++ b/packages/herdr/src/worklist.ts @@ -3286,6 +3286,10 @@ export function handleMouseInput( * `[Downtime Off (restored)]` (disable restored from the persisted marker, * WL-0MT5SG0VU005ARUR), or `[downtime paused]` (no-candidate cooldown, * WL-0MSI7DQL10016QYX). + * `[downtime held: ]` (WL-0MU8808ZY0091JIA) shows the gate that + * refused the last polled tick (e.g. `slot-owner`, `contention`, + * `code-freeze`) so "idle slots but no dispatches" is visible instead of a + * misleading idle label. * `[Downtime Off]` replaces the legacy `[downtime disabled]` text and is * shown whenever dispatch is off for the instance — either globally * settings-disabled or toggled off via the `d` shortcut (parent @@ -3315,6 +3319,12 @@ export function renderDowntimeStatus(worker: DowntimeWorker | undefined): string // duration (AC6, WL-0MSI7DQL10016QYX). return ` ${ANSI.dim}[downtime paused]${ANSI.reset}`; } + if (worker.blockReason) { + // A gate refused the last polled tick (slot-owner / contention / + // code-freeze / ...). Distinct from the idle label so the operator can + // see WHY idle slots are not being used (WL-0MU8808ZY0091JIA AC4). + return ` ${ANSI.fg(208)}[downtime held: ${worker.blockReason}]${ANSI.reset}`; + } if (worker.idleSince !== null) { const elapsedSecs = Math.max(0, Math.floor((Date.now() - worker.idleSince) / 1000)); const minutes = Math.floor(elapsedSecs / 60); diff --git a/packages/shared/src/fields.test.ts b/packages/shared/src/fields.test.ts index fac2b8ccc..ad5533030 100644 --- a/packages/shared/src/fields.test.ts +++ b/packages/shared/src/fields.test.ts @@ -146,4 +146,20 @@ describe('pickFields', () => { it('VALID_FIELDS has no unexpected entries', () => { expect(VALID_FIELDS).toHaveLength(14); }); + + it('error message for unknown fields excludes id from valid fields list', () => { + let error: Error | undefined; + try { + pickFields(SAMPLE_ITEM, ['bogusField']); + } catch (e) { + error = e instanceof Error ? e : undefined; + } + expect(error).toBeDefined(); + // id is always included regardless of request, so it must NOT appear in + // the error message's valid-fields list. + expect(error!.message).not.toMatch(/Valid fields:.*\bid\b/); + // but other fields should still appear + expect(error!.message).toContain('title'); + expect(error!.message).toContain('status'); + }); }); diff --git a/packages/shared/src/fields.ts b/packages/shared/src/fields.ts index a7b6019a3..c1b4a5439 100644 --- a/packages/shared/src/fields.ts +++ b/packages/shared/src/fields.ts @@ -65,7 +65,10 @@ export function pickFields( // Validate: reject unknown field names. const unknown = fields.filter((f) => !VALID_FIELDS.includes(f as (typeof VALID_FIELDS)[number])); if (unknown.length > 0) { - const validList = VALID_FIELDS.join(', '); + // id is always included regardless of request, so omit it from the + // error message's valid-fields list — the caller doesn't need to + // request it. + const validList = VALID_FIELDS.filter(f => f !== 'id').join(', '); throw new Error( `Unknown fields: ${unknown.join(', ')}. Valid fields: ${validList}` ); diff --git a/packages/tui/extensions/README.md b/packages/tui/extensions/README.md index c260b2e2b..e815f1b4d 100644 --- a/packages/tui/extensions/README.md +++ b/packages/tui/extensions/README.md @@ -249,13 +249,14 @@ Recovery behaviour is driven by `DEFAULT_RECOVERY_CONFIG` in ### Server-Requested Retry Delays (`Retry-After`) When a provider asks the client to wait — e.g. the llm-proxy startup-ramp gate -returns HTTP `503` with a `Retry-After` header and a body containing -`retry_after` (seconds) — the retry loop honours that hint instead of -retrying on the plain exponential schedule: - -- The delay is the **larger** of the exponential backoff and the - server-requested delay, so the client never retries sooner than asked - (bounded by `maxDelayMs`, default 60s). +returns HTTP `503` with a `Retry-After` header — the retry loop honours that +hint instead of retrying on the plain exponential schedule: + +- When a hint is present it is **authoritative**: the delay tracks the + server-requested delay (plus upward-only jitter, bounded by `maxDelayMs`, + default 60s). The local exponential backoff is used only when the hint is + absent or malformed, so a grown local backoff can never override the + server's recommended wait. - Upward-only jitter (25% by default, `serverHintJitterRatio`) is applied to hint-derived delays so concurrent clients do not retry in lockstep. - Missing or malformed hints fall back to the existing exponential backoff, @@ -264,11 +265,28 @@ retrying on the plain exponential schedule: (the proxy's `startup_ramp.max_seconds`, default 180s) without surfacing a hard failure. -Supported forms: `retry-after-ms` / `retry_after_ms` (milliseconds), -`retry-after` / `retry_after` delta-seconds (fractional allowed), and -HTTP-date `Retry-After`. Escaped JSON bodies (`\"retry_after\": 9`) are also -parsed. Parsing lives in `parseServerRetryDelayMs()` and the single decision -point `resolveRetryDelay()` in `retry-logic.ts`. +#### Where the hint is read from + +The server hint is resolved from two sources, in precedence order: + +1. **Response headers** (`after_provider_response` / `fetch` capture). Pi's + `openai-completions` provider throws on a non-2xx response *before* the + `after_provider_response` extension event fires, and the resulting + assistant error message drops the header. The recovery module therefore + installs a transparent `globalThis.fetch` wrapper + (`createRetryHintCapturingFetch()`) that records the parsed + `Retry-After` / `Retry-After-Ms` header for 429/5xx responses and clears it + on 2xx. This is the source that works for the llm-proxy startup ramp. +2. **Assistant error message** (`parseServerRetryDelayMs()`), for providers + that fold the hint into the error text (e.g. a JSON body containing + `retry_after`). Real llm-proxy startup-ramp messages do **not** carry this + field — the header is authoritative. + +`resolveRetryDelay()` is the single decision point that combines both sources +and hands the delay to `calculateDelay()`. Supported header/body forms: +`retry-after-ms` / `retry_after_ms` (milliseconds), `retry-after` / +`retry_after` delta-seconds (fractional allowed), and HTTP-date `Retry-After`. +Escaped JSON bodies (`\"retry_after\": 9`) are also parsed. ### `/retry` Command @@ -309,7 +327,7 @@ The recovery module is implemented in `Worklog/lib/recovery/` and consists of: | File | Purpose | |------|---------| | `error-patterns.ts` | Error classification patterns for all 8 categories | -| `retry-logic.ts` | Exponential backoff, `Retry-After`/`retry_after` parsing and jitter, state managers, interruptible sleep | +| `retry-logic.ts` | Exponential backoff, `Retry-After` header/`retry_after` parsing (plus a `fetch` capture wrapper) and jitter, state managers, interruptible sleep | | `recovery.ts` | Compact-and-continue, checkpoint-and-terminate, and single-shot parse-error continue handlers | | `retry-command.ts` | `/retry` command interface (status, reset, manual-trigger) | | `register-recovery.ts` | Extension lifecycle wiring (agent_end, turn_end, session_start, session_compact) | diff --git a/packages/tui/extensions/Worklog/lib/recovery/register-recovery.ts b/packages/tui/extensions/Worklog/lib/recovery/register-recovery.ts index ecd8621ab..a5bbedd08 100644 --- a/packages/tui/extensions/Worklog/lib/recovery/register-recovery.ts +++ b/packages/tui/extensions/Worklog/lib/recovery/register-recovery.ts @@ -32,7 +32,12 @@ import { type RetryCommandContext, type RetryCommandOptions, } from './retry-command.js'; -import { formatDuration, resolveRetryDelay, DEFAULT_BACKOFF_CONFIG } from './retry-logic.js'; +import { + formatDuration, + resolveRetryDelay, + createRetryHintCapturingFetch, + DEFAULT_BACKOFF_CONFIG, +} from './retry-logic.js'; let _recoveryRegistered = false; @@ -49,6 +54,13 @@ let _notifyFn: ((message: string, level: 'info' | 'warning' | 'error') => void) // Timestamp of the last completed triggerInvisibleContinue call. let _lastInvisibleContinueTime = 0; +// Server-requested retry delay captured from the latest provider response +// headers (`Retry-After` / `Retry-After-Ms`). Consumed by the retry loop. +let _lastServerRetryHintMs: number | undefined = undefined; + +// Guards against installing the fetch hint capture more than once. +let _fetchHintCaptureInstalled = false; + /** * Register the recovery module with the extension API. * @@ -65,6 +77,7 @@ export function registerRecoveryModule(pi: ExtensionAPI): void { // the built-in retry from racing with our retry loop. suppressBuiltinRetry(); captureAgentInstance(); + installFetchRetryHintCapture(); // Refresh the notify function on every handler that carries a ctx. pi.on('agent_end', async (_event, ctx) => { @@ -373,14 +386,18 @@ async function triggerInvisibleContinue(): Promise { while (true) { if (interruptibleState.userAborted || interruptibleState.sessionGeneration !== _sessionGenerationAtStart) return; - // Capture the server-requested retry delay (`Retry-After` / - // `retry_after`) from the error message before the error is removed - // from agent state, then honour it (AC1/AC2). + // Capture the server-requested retry delay before the error is removed + // from agent state, then honour it (AC1/AC2). The header captured by + // `installFetchRetryHintCapture()` takes precedence over the + // error-message fallback: real startup_ramp errors carry the hint only + // on the `Retry-After` header, never in the message text. attempt++; const { delayMs: delay, serverHintMs } = resolveRetryDelay( attempt, lastErrorMessageFromAgentState(), DEFAULT_BACKOFF_CONFIG, + Math.random, + _lastServerRetryHintMs, ); // Remove the error assistant message from agent state @@ -582,6 +599,34 @@ function lastMessageIsRetryableError(): boolean { return lastMsg?.role === 'assistant' && lastMsg.stopReason === 'error'; } +// ── Server retry-hint capture (fetch wrapper) ───────────────────────── + +/** + * Capture the server-requested retry delay from provider HTTP response + * headers. + * + * Pi's `openai-completions` provider throws on a non-2xx response before the + * `after_provider_response` extension event fires, and the assistant error + * message does not carry the `Retry-After` header value. Wrapping + * `globalThis.fetch` is the only point at which the recovery module can see + * the header for that provider. The wrapper is transparent: it returns the + * original response untouched and never swallows errors. + */ +function installFetchRetryHintCapture(): void { + if (_fetchHintCaptureInstalled) return; + const originalFetch = globalThis.fetch; + if (typeof originalFetch !== 'function') return; + _fetchHintCaptureInstalled = true; + try { + globalThis.fetch = createRetryHintCapturingFetch(originalFetch, (hintMs) => { + _lastServerRetryHintMs = hintMs; + }); + } catch { + // Non-writable fetch in this runtime — fall back to message parsing. + _fetchHintCaptureInstalled = false; + } +} + // ── Built-in retry suppression ──────────────────────────────────────── /** diff --git a/packages/tui/extensions/Worklog/lib/recovery/retry-after-header.test.ts b/packages/tui/extensions/Worklog/lib/recovery/retry-after-header.test.ts new file mode 100644 index 000000000..2e475cd33 --- /dev/null +++ b/packages/tui/extensions/Worklog/lib/recovery/retry-after-header.test.ts @@ -0,0 +1,237 @@ +/** + * Tests for server-requested retry delays carried on HTTP response headers. + * + * Why this file exists (WL-0MU9Z7L8X00117BI RCA): the original fix parsed the + * retry hint out of the assistant error *message*. Real llm-proxy startup-ramp + * errors do NOT carry `retry_after` in that message — the observed shape is + * + * 503: {"type":"startup_ramp","code":"startup_ramp","message":"Server is starting up; retry shortly."} + * + * — and the machine-readable hint is only on the `Retry-After` response header. + * Pi's `openai-completions` provider throws before the + * `after_provider_response` extension event fires, so the header never reaches + * the extension through events. The recovery module therefore captures the + * header from a transparent `globalThis.fetch` wrapper and feeds it into the + * retry loop. + * + * Run: cd /home/rgardler/projects/ContextHub && npx vitest run packages/tui/extensions/Worklog/lib/recovery/retry-after-header.test.ts + */ + +import { describe, it, expect, vi } from 'vitest'; +import { + calculateDelay, + resolveRetryDelay, + parseServerRetryDelayMs, + parseRetryAfterHeaders, + createRetryHintCapturingFetch, + DEFAULT_BACKOFF_CONFIG, + type BackoffConfig, +} from './retry-logic.js'; + +// The exact error message shape observed in production logs (no retry_after). +const REAL_RAMP_503 = + '503: {"type":"startup_ramp","code":"startup_ramp","message":"Server is starting up; retry shortly."}'; + +// ── parseRetryAfterHeaders: Headers object ──────────────────────────── + +describe('parseRetryAfterHeaders (Headers object)', () => { + it('parses a delta-seconds Retry-After header', () => { + const headers = new Headers({ 'Retry-After': '7' }); + expect(parseRetryAfterHeaders(headers)).toBe(7000); + }); + + it('prefers Retry-After-Ms over Retry-After', () => { + const headers = new Headers({ 'Retry-After-Ms': '5000', 'Retry-After': '9' }); + expect(parseRetryAfterHeaders(headers)).toBe(5000); + }); + + it('parses a fractional delta-seconds header', () => { + expect(parseRetryAfterHeaders(new Headers({ 'Retry-After': '2.5' }))).toBe(2500); + }); + + it('parses a future HTTP-date header', () => { + const future = new Date(Date.now() + 10_000).toUTCString(); + const parsed = parseRetryAfterHeaders(new Headers({ 'Retry-After': future })); + expect(parsed).toBeDefined(); + expect(parsed!).toBeGreaterThan(5000); + expect(parsed!).toBeLessThanOrEqual(10_000); + }); + + it('returns 0 (retry now) for a past HTTP-date header', () => { + const past = new Date(Date.now() - 10_000).toUTCString(); + expect(parseRetryAfterHeaders(new Headers({ 'Retry-After': past }))).toBe(0); + }); + + it('returns undefined when the headers carry no hint', () => { + expect(parseRetryAfterHeaders(new Headers({ 'Content-Type': 'application/json' }))).toBeUndefined(); + }); + + it('returns undefined for malformed values', () => { + expect(parseRetryAfterHeaders(new Headers({ 'Retry-After': 'soon' }))).toBeUndefined(); + }); +}); + +// ── parseRetryAfterHeaders: plain record ────────────────────────────── + +describe('parseRetryAfterHeaders (plain record)', () => { + it('matches header names case-insensitively', () => { + expect(parseRetryAfterHeaders({ 'RETRY-AFTER': '12' })).toBe(12000); + expect(parseRetryAfterHeaders({ 'rEtRy-AfTeR': '3' })).toBe(3000); + }); + + it('is tolerant of absent / null input', () => { + expect(parseRetryAfterHeaders(undefined)).toBeUndefined(); + expect(parseRetryAfterHeaders(null)).toBeUndefined(); + expect(parseRetryAfterHeaders({})).toBeUndefined(); + }); + + it('returns undefined for negative values', () => { + expect(parseRetryAfterHeaders({ 'retry-after': '-3' })).toBeUndefined(); + }); +}); + +// ── resolveRetryDelay: header hint takes precedence ─────────────────── + +describe('resolveRetryDelay with a header hint', () => { + const noJitter = () => 0; + + it('honours a header hint that exceeds the exponential backoff', () => { + const result = resolveRetryDelay(1, undefined, DEFAULT_BACKOFF_CONFIG, noJitter, 7000); + expect(result.serverHintMs).toBe(7000); + expect(result.hintSource).toBe('header'); + expect(result.delayMs).toBe(7000); + }); + + it('prefers the header hint over a message hint', () => { + const result = resolveRetryDelay(1, '503: {"retry_after": 3}', DEFAULT_BACKOFF_CONFIG, noJitter, 9000); + expect(result.hintSource).toBe('header'); + expect(result.delayMs).toBe(9000); + }); + + it('falls back to the message hint when no header hint is present', () => { + const result = resolveRetryDelay(1, '503: {"retry_after": 3}', DEFAULT_BACKOFF_CONFIG, noJitter, undefined); + expect(result.hintSource).toBe('message'); + expect(result.delayMs).toBe(3000); + }); + + it('caps a large header hint at the configured maximum', () => { + const result = resolveRetryDelay(1, undefined, DEFAULT_BACKOFF_CONFIG, noJitter, 90_000); + expect(result.delayMs).toBe(60_000); + }); + + it('does not let a grown local backoff override the header hint', () => { + // attempt 6 local exponential is capped at 60000ms, but the header hint is + // authoritative — the local backoff must not override the server's wait. + const result = resolveRetryDelay(6, REAL_RAMP_503, DEFAULT_BACKOFF_CONFIG, noJitter, 8000); + expect(result.hintSource).toBe('header'); + expect(result.delayMs).toBe(8000); + }); + + it('treats a negative/NaN header hint as absent', () => { + expect(resolveRetryDelay(1, undefined, DEFAULT_BACKOFF_CONFIG, noJitter, -1).hintSource).toBeUndefined(); + expect(resolveRetryDelay(1, undefined, DEFAULT_BACKOFF_CONFIG, noJitter, Number.NaN).hintSource).toBeUndefined(); + }); + + it('applies upward-only jitter to a header-derived delay', () => { + const config: BackoffConfig = { baseDelayMs: 2000, maxDelayMs: 60000, multiplier: 2, serverHintJitterRatio: 0.25 }; + expect(calculateDelay(1, config, 8000, () => 0.5)).toBe(9000); + expect(calculateDelay(1, config, 8000, () => 0.5)).toBeGreaterThanOrEqual(8000); + }); +}); + +// ── createRetryHintCapturingFetch ───────────────────────────────────── + +function makeResponse(status: number, headers: Record = {}): Response { + return new Response('body', { status, headers }); +} + +describe('createRetryHintCapturingFetch', () => { + it('captures the hint from a 503 response', async () => { + const onHint = vi.fn(); + const capture = createRetryHintCapturingFetch( + async () => makeResponse(503, { 'Retry-After': '11' }), + onHint, + ); + await capture('http://example.test'); + expect(onHint).toHaveBeenCalledWith(11_000); + }); + + it('captures the hint from a 429 response', async () => { + const onHint = vi.fn(); + const capture = createRetryHintCapturingFetch( + async () => makeResponse(429, { 'Retry-After-Ms': '2500' }), + onHint, + ); + await capture('http://example.test'); + expect(onHint).toHaveBeenCalledWith(2500); + }); + + it('clears the hint on a successful response', async () => { + const onHint = vi.fn(); + const capture = createRetryHintCapturingFetch(async () => makeResponse(200), onHint); + await capture('http://example.test'); + expect(onHint).toHaveBeenCalledWith(undefined); + }); + + it('reports undefined for a retryable response without a hint', async () => { + const onHint = vi.fn(); + const capture = createRetryHintCapturingFetch(async () => makeResponse(502), onHint); + await capture('http://example.test'); + expect(onHint).toHaveBeenCalledWith(undefined); + }); + + it('returns the original response untouched', async () => { + const response = makeResponse(503, { 'Retry-After': '5' }); + const capture = createRetryHintCapturingFetch(async () => response, () => {}); + await expect(capture('http://example.test')).resolves.toBe(response); + }); + + it('propagates fetch rejections (network errors) without capturing', async () => { + const onHint = vi.fn(); + const capture = createRetryHintCapturingFetch(async () => { + throw new Error('network down'); + }, onHint); + await expect(capture('http://example.test')).rejects.toThrow('network down'); + expect(onHint).not.toHaveBeenCalled(); + }); + + it('does not clear the hint on a non-2xx, non-retryable response', async () => { + const onHint = vi.fn(); + const capture = createRetryHintCapturingFetch(async () => makeResponse(400), onHint); + await capture('http://example.test'); + expect(onHint).not.toHaveBeenCalled(); + }); +}); + +// ── RCA regression: the real error shape + header hint ──────────────── + +describe('startup_ramp RCA regression', () => { + it('the real error message carries no parseable hint', () => { + expect(parseServerRetryDelayMs(REAL_RAMP_503)).toBeUndefined(); + }); + + it('honours the Retry-After header that the message dropped', () => { + const headerHint = parseRetryAfterHeaders(new Headers({ 'Retry-After': '12' })); + const result = resolveRetryDelay(1, REAL_RAMP_503, DEFAULT_BACKOFF_CONFIG, () => 0, headerHint); + expect(headerHint).toBe(12_000); + expect(result.hintSource).toBe('header'); + expect(result.delayMs).toBe(12_000); + }); + + it('does not retry sooner than the hint across a full startup ramp', () => { + const config: BackoffConfig = { baseDelayMs: 2000, maxDelayMs: 60000, multiplier: 2, serverHintJitterRatio: 0.25 }; + let elapsed = 0; + let attempt = 0; + while (elapsed < 180_000 && attempt < 100) { + attempt++; + // Proxy degrades hints across the ramp, 5s .. 18s. + const headerHint = parseRetryAfterHeaders(new Headers({ 'Retry-After': String(5 + (attempt % 14)) })); + const { delayMs } = resolveRetryDelay(attempt, REAL_RAMP_503, config, () => 0, headerHint); + expect(delayMs).toBeGreaterThanOrEqual(headerHint!); + expect(delayMs).toBeLessThanOrEqual(config.maxDelayMs); + elapsed += delayMs; + } + expect(elapsed).toBeGreaterThanOrEqual(180_000); + expect(attempt).toBeLessThan(100); + }); +}); diff --git a/packages/tui/extensions/Worklog/lib/recovery/retry-after.test.ts b/packages/tui/extensions/Worklog/lib/recovery/retry-after.test.ts index e5a09b231..c8da9e163 100644 --- a/packages/tui/extensions/Worklog/lib/recovery/retry-after.test.ts +++ b/packages/tui/extensions/Worklog/lib/recovery/retry-after.test.ts @@ -120,9 +120,12 @@ describe('calculateDelay with a server hint', () => { expect(calculateDelay(1, DEFAULT_BACKOFF_CONFIG, 7000, noJitter)).toBe(7000); }); - it('uses the exponential backoff when it exceeds the hint', () => { - // attempt 5 exponential = 32000ms, hint = 5000ms -> floor is 32000ms. - expect(calculateDelay(5, DEFAULT_BACKOFF_CONFIG, 5000, noJitter)).toBe(32000); + it('honours the server hint even when the local exponential has grown larger', () => { + // attempt 5 exponential = 32000ms, hint = 5000ms. The server hint is + // authoritative: the local backoff must not override the recommended wait + // (producer rejection: "the local retry mechanism overriding the + // recommended wait duration"). + expect(calculateDelay(5, DEFAULT_BACKOFF_CONFIG, 5000, noJitter)).toBe(5000); }); it('caps the server-requested delay at the configured maximum', () => { @@ -137,12 +140,20 @@ describe('calculateDelay with a server hint', () => { multiplier: 2, serverHintJitterRatio: 0.25, }; - const floor = 8000; // max(exponential 2000, hint 8000) - expect(calculateDelay(1, config, 8000, () => 0)).toBe(floor); + // Hint-derived delays track the hint, not the (smaller) exponential. + expect(calculateDelay(1, config, 8000, () => 0)).toBe(8000); expect(calculateDelay(1, config, 8000, () => 0.5)).toBe(9000); expect(calculateDelay(1, config, 8000, () => 1)).toBe(10_000); }); + it('does not let the local backoff escalate a hint-derived delay across attempts', () => { + // A constant 7s hint must yield ~7s on every attempt, even at attempt 6 + // where the local exponential would otherwise be capped at 60s. + for (const attempt of [1, 2, 3, 4, 5, 6, 10]) { + expect(calculateDelay(attempt, DEFAULT_BACKOFF_CONFIG, 7000, () => 0)).toBe(7000); + } + }); + it('never retries sooner than the hint under maximum jitter', () => { const config: BackoffConfig = { baseDelayMs: 2000, diff --git a/packages/tui/extensions/Worklog/lib/recovery/retry-logic.ts b/packages/tui/extensions/Worklog/lib/recovery/retry-logic.ts index 379eefa36..7843b2bf7 100644 --- a/packages/tui/extensions/Worklog/lib/recovery/retry-logic.ts +++ b/packages/tui/extensions/Worklog/lib/recovery/retry-logic.ts @@ -113,6 +113,97 @@ function normaliseDelayMs(value: number, factor: number): number | undefined { return Math.round(ms); } +/** + * Parse a server-requested retry delay from HTTP response headers. + * + * The llm-proxy startup-ramp gate sets a `Retry-After` header (delta-seconds + * or HTTP-date) on its 503 response. Pi's `openai-completions` provider throws + * before the `after_provider_response` extension event fires and formats the + * assistant error message without the header value, so the recovery retry + * loop captures the header from a `fetch` wrapper and parses it here. + * + * Supports both a real `Headers` object (case-insensitive by construction) and + * a plain string record. `retry-after-ms` wins over `retry-after`, matching the + * provider-level retry helper's precedence. + * + * @param headers - Response headers (`Headers` or a plain record) + * @returns Delay in milliseconds, or `undefined` when absent or malformed + */ +export function parseRetryAfterHeaders( + headers: Headers | Record | undefined | null, +): number | undefined { + if (!headers) return undefined; + + const get = (name: string): string | undefined => { + const maybeHeaders = headers as Headers; + if (typeof maybeHeaders.get === 'function') { + const value = maybeHeaders.get(name); + return value === null ? undefined : value; + } + const record = headers as Record; + const direct = record[name]; + if (typeof direct === 'string') return direct; + for (const [key, value] of Object.entries(record)) { + if (key.toLowerCase() === name && typeof value === 'string') return value; + } + return undefined; + }; + + // 1. Milliseconds form (checked first so `retry-after-ms` is not read as + // delta-seconds). + const msHeader = get('retry-after-ms'); + if (msHeader !== undefined) { + const value = Number.parseFloat(msHeader); + if (Number.isFinite(value)) return normaliseDelayMs(value, 1); + } + + // 2. Delta-seconds form, then HTTP-date form. + const retryAfter = get('retry-after'); + if (retryAfter !== undefined) { + const seconds = Number.parseFloat(retryAfter); + if (Number.isFinite(seconds)) return normaliseDelayMs(seconds, 1000); + const target = Date.parse(retryAfter); + if (!Number.isNaN(target)) { + // A past date means "retry now" (0ms) rather than an invalid hint. + return Math.max(0, Math.round(target - Date.now())); + } + } + + return undefined; +} + +/** + * Wrap a `fetch` implementation so retryable provider responses report the + * server-requested retry delay (`Retry-After` / `Retry-After-Ms` on 429/5xx) + * to `onHint`. Successful (2xx) responses report `undefined` so a stale hint + * is not reused. The response is returned untouched and fetch rejections + * propagate unchanged. + * + * This is the transport-level source of the retry hint for providers that + * throw before an extension event can observe the response headers. + * + * @param originalFetch - The fetch implementation to delegate to + * @param onHint - Called with the parsed delay in ms (or undefined to clear) + * @returns A drop-in fetch wrapper + */ +export function createRetryHintCapturingFetch( + originalFetch: typeof fetch, + onHint: (hintMs: number | undefined) => void, +): typeof fetch { + const capturingFetch = async (input: RequestInfo | URL, init?: RequestInit): Promise => { + const response = await originalFetch(input, init); + if (response && typeof response.status === 'number') { + if (response.status === 429 || response.status >= 500) { + onHint(parseRetryAfterHeaders(response.headers)); + } else if (response.status >= 200 && response.status < 300) { + onHint(undefined); + } + } + return response; + }; + return capturingFetch as typeof fetch; +} + /** * Calculate delay for a given attempt number. * @@ -120,10 +211,17 @@ function normaliseDelayMs(value: number, factor: number): number | undefined { * capped at `maxDelayMs` (existing exponential backoff, unchanged). * * With a usable server hint (from `Retry-After` / `retry_after`): the delay - * is the larger of the exponential backoff and the server-requested delay, - * plus upward-only jitter, capped at `maxDelayMs`. This guarantees the client - * never retries sooner than the server asked (unless the configured cap is - * below the hint). + * tracks the server-requested delay (plus upward-only jitter, capped at + * `maxDelayMs`). The local exponential backoff is **not** combined into this + * value — a growing local backoff must not silently override the server's + * recommendation. + * + * @remarks + * The server hint is authoritative when present. An earlier revision used + * `max(exponential, serverHintMs)`, which let the local exponential override + * the hint once it outgrew it (e.g. `Retry-After: 7` -> retry at 32s/60s). + * That is the behaviour the producer rejected as "the local retry mechanism + * overriding the recommended wait duration". * * @param attempt - The attempt number (1-based) * @param config - Backoff configuration (defaults if not provided) @@ -150,9 +248,11 @@ export function calculateDelay( return exponential; } - const floor = Math.max(exponential, serverHintMs); + // A usable server hint is authoritative: the delay tracks the hint, not the + // local exponential. Upward-only jitter keeps the delay at or above the + // requested wait, and the configurable maximum still bounds it. const jitterRatio = Math.max(0, config.serverHintJitterRatio ?? DEFAULT_SERVER_HINT_JITTER_RATIO); - const jittered = floor * (1 + jitterRatio * random()); + const jittered = serverHintMs * (1 + jitterRatio * random()); return Math.min(Math.round(jittered), config.maxDelayMs); } @@ -168,17 +268,32 @@ export function calculateDelay( * @param errorMessage - The assistant error message * @param config - Backoff configuration (defaults if not provided) * @param random - Random source in [0, 1) used for jitter (injectable for tests) - * @returns The delay in milliseconds and the parsed server hint, if present + * @param headerHintMs - Retry delay parsed from the response `Retry-After` + * header (see {@link parseRetryAfterHeaders}); takes precedence over the + * error-message hint + * @returns The delay in milliseconds, the parsed server hint (if any), and + * which source produced it */ export function resolveRetryDelay( attempt: number, errorMessage: string | undefined | null, config: BackoffConfig = DEFAULT_BACKOFF_CONFIG, random: () => number = Math.random, -): { delayMs: number; serverHintMs?: number } { - const serverHintMs = parseServerRetryDelayMs(errorMessage); + headerHintMs?: number, +): { delayMs: number; serverHintMs?: number; hintSource?: 'header' | 'message' } { + const headerHint = + typeof headerHintMs === 'number' && Number.isFinite(headerHintMs) && headerHintMs >= 0 + ? headerHintMs + : undefined; + const messageHint = parseServerRetryDelayMs(errorMessage); + const serverHintMs = headerHint ?? messageHint; + const hintSource = headerHint !== undefined ? 'header' : messageHint !== undefined ? 'message' : undefined; const delayMs = calculateDelay(attempt, config, serverHintMs, random); - return serverHintMs === undefined ? { delayMs } : { delayMs, serverHintMs }; + + const result: { delayMs: number; serverHintMs?: number; hintSource?: 'header' | 'message' } = { delayMs }; + if (serverHintMs !== undefined) result.serverHintMs = serverHintMs; + if (hintSource !== undefined) result.hintSource = hintSource; + return result; } /** diff --git a/scripts/install-memwatch.sh b/scripts/install-memwatch.sh new file mode 100755 index 000000000..23542ac2f --- /dev/null +++ b/scripts/install-memwatch.sh @@ -0,0 +1,149 @@ +#!/usr/bin/env bash +# install-memwatch.sh — deploy memwatch memory monitoring as a cron job +# +# Installs the monitoring script to a root-owned location (default +# /usr/local/sbin/memwatch) and writes /etc/cron.d/memwatch to invoke it +# every minute as root. +# +# Copying the script to a root-owned path is deliberate: the cron job runs as +# root, so the executed script must not be modifiable by a non-root user. A +# cron job pointing at a script inside a user-writable checkout would be a +# privilege-escalation vector. +# +# Usage: +# sudo scripts/install-memwatch.sh # defaults +# sudo scripts/install-memwatch.sh --warning 8192 --critical 4096 +# scripts/install-memwatch.sh --dry-run # preview only +# sudo scripts/install-memwatch.sh --uninstall +# +# Environment overrides: +# MEMWATCH_SCRIPT_PATH Source script (default: /memwatch.sh) +# MEMWATCH_INSTALL_PATH Root-owned target (default: /usr/local/sbin/memwatch) +# MEMWATCH_STATE_FILE State file for dedup (default: /run/memwatch-state) +# +# Work Item: WL-0MT1KJNGA006EEHU +# Date: 2026-09-25 + +set -euo pipefail + +SCRIPT_DIR="$(cd "$(dirname "$0")" && pwd)" +MEMWATCH_SCRIPT="${MEMWATCH_SCRIPT_PATH:-$SCRIPT_DIR/memwatch.sh}" +INSTALL_PATH="${MEMWATCH_INSTALL_PATH:-/usr/local/sbin/memwatch}" +CRON_FILE="/etc/cron.d/memwatch" +DRY_RUN=0 +UNINSTALL=0 +WARNING_MB="" +CRITICAL_MB="" + +while [[ $# -gt 0 ]]; do + case "$1" in + --dry-run) DRY_RUN=1; shift ;; + --uninstall) UNINSTALL=1; shift ;; + --warning) WARNING_MB="$2"; shift 2 ;; + --critical) CRITICAL_MB="$2"; shift 2 ;; + -h|--help) + cat <<'EOF' +Usage: install-memwatch.sh [--dry-run] [--uninstall] [--warning MB] [--critical MB] + +Install (or remove) memwatch memory monitoring as a root cron job. + +Options: + --dry-run Show what would be installed without making changes + --uninstall Remove the cron job and installed script + --warning MB Warning threshold in MB (default: script default, 4096) + --critical MB Critical threshold in MB (default: script default, 2048) + -h, --help Show this help +EOF + exit 0 + ;; + *) echo "Unknown option: $1" >&2; exit 1 ;; + esac +done + +if (( DRY_RUN == 0 )) && (( EUID != 0 )); then + echo "Error: this script must be run as root (or via sudo)" >&2 + exit 1 +fi + +MEMWATCH_SCRIPT_ABS="$(cd "$(dirname "$MEMWATCH_SCRIPT")" && pwd)/$(basename "$MEMWATCH_SCRIPT")" + +if (( UNINSTALL )); then + echo "Removing memwatch..." + rm -f "$CRON_FILE" + rm -f "$INSTALL_PATH" + echo "✓ Removed $CRON_FILE and $INSTALL_PATH" + exit 0 +fi + +if [[ ! -f "$MEMWATCH_SCRIPT" ]]; then + echo "Error: memwatch.sh not found at $MEMWATCH_SCRIPT" >&2 + exit 1 +fi + +# Build the optional threshold overrides for the cron line. When unset, the +# script's own defaults (documented at the top of memwatch.sh) apply. +THRESHOLD_ENV="" +if [[ -n "$WARNING_MB" ]]; then + THRESHOLD_ENV+="MEMWATCH_WARNING_MB=$WARNING_MB " +fi +if [[ -n "$CRITICAL_MB" ]]; then + THRESHOLD_ENV+="MEMWATCH_CRITICAL_MB=$CRITICAL_MB " +fi + +CRON_CONTENT="# memwatch - memory pressure monitoring and alerting +# Installed by scripts/install-memwatch.sh (Work Item: WL-0MT1KJNGA006EEHU) +# +# Checks /proc/meminfo MemAvailable every minute and logs a MEMWATCH: line to +# journald when the pressure level changes. See docs/dev/memory-monitoring.md. + +SHELL=/bin/bash +PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin + +* * * * * root ${THRESHOLD_ENV}${INSTALL_PATH} +" + +echo "=== memwatch installer ===" +echo "Source: $MEMWATCH_SCRIPT_ABS" +echo "Install: $INSTALL_PATH (root:root 0755)" +echo "Cron: $CRON_FILE" +echo "Warning: ${WARNING_MB:-