From 7b8f63392ad5ade9077d544e58396062a060bf37 Mon Sep 17 00:00:00 2001 From: Jean-Baptiste Date: Fri, 2 Oct 2026 16:36:30 +0200 Subject: [PATCH 1/4] (triggers): wait for the CLI descriptor before every chain step (#407, #360) Step 0 of a chain landed in the composer with its Enter absorbed while background subagents were running: the readiness wait only covered the step after /compact. It now runs before every step, never writes into a dialog, and falls back to the old behaviour without a usable descriptor. The busy-fall wait also takes the descriptor as authority: idle after the step's Enter ends it even when the terminal-derived busy flag is stuck, which timed out a chain on an idle session. Closes #360 Refs #407 --- .ai/contexts/trigger-watcher.md | 46 +++++- CHANGELOG.md | 1 + test/trigger-every-step-readiness.test.js | 176 ++++++++++++++++++++++ trigger-watcher.js | 92 ++++++++--- 4 files changed, 296 insertions(+), 19 deletions(-) create mode 100644 test/trigger-every-step-readiness.test.js diff --git a/.ai/contexts/trigger-watcher.md b/.ai/contexts/trigger-watcher.md index 1cf5f8b2..d46beb52 100644 --- a/.ai/contexts/trigger-watcher.md +++ b/.ai/contexts/trigger-watcher.md @@ -834,7 +834,7 @@ wired to `cliSessionState.getStatus` in `main.js`; `undefined` for a remote session, which has no local descriptor). No new watcher: it reuses the cache `cli-session-state.js` already keeps. -- **Readiness.** A chain step that follows a `/compact` step first waits +- **Readiness.** (Extended to every step, see the next section.) A chain step that follows a `/compact` step first waits (`waitForCliIdleAfter`) for `status: "idle"` with a `statusUpdatedAt` later than the compact step's send time. Bounded by `SWITCHBOARD_CLI_READY_WAIT_MS` (default 60 000 ms) and by the step's own @@ -885,6 +885,50 @@ named, not that the first Enter always lands. Tests: `test/trigger-descriptor-proof.test.js` (fake timers and a fake descriptor for the helpers; the real watcher for the chain wiring). +### Readiness before every step, and the descriptor as busy-fall authority (issues #407, #360) + +Second field case (2026-10-02): step 0 of a `compact-now.sh` chain, with no +`/compact` before it, landed in the composer and its Enter became a line +break, while four background subagents had just been spawned. The #407 +readiness wait only covered the step after a `/compact`; nothing waited +before step 0. Text written while the CLI is mid-turn has its Enter absorbed +whatever preceded it. + +- **The wait now runs before EVERY chain step**, step 0 included + (`waitForCliIdleAfter`, after the composer-free and liveness checks, so the + descriptor is read as close to the write as possible). Before a step that + follows `/compact` the idle must also be newer than the compact's send; + before any other step any `idle` counts. The idle must hold for the busy-fall + settle window (`SWITCHBOARD_BUSY_FALL_SETTLE_MS`, 300 ms) with an unchanged + `statusUpdatedAt`, so a `busy` that follows an `idle` within the window is + not mistaken for readiness. Bound: `SWITCHBOARD_CLI_READY_WAIT_MS` (default + 60 000 ms) and the step's own deadline. +- **`waiting` (a dialog is open) is never typed into.** If the descriptor still + reads `waiting` when the bound expires, the step is NOT written: the result + is `ok: false`, `error` `not sent` (step 0) or `chain timeout` (later steps), + `reason` "the CLI reports a dialog open (waiting); nothing was written into + it", the step is recorded with `submitted: "no"`. +- **`busy` at the bound** keeps the #410 behaviour: the step is written anyway + with the warning `CLI not idle ... within N ms, writing chain step N anyway`. + Failing there instead would turn a stuck descriptor into a lost chain; the + submission proof and the recovery-Enter ban still apply to that write. +- **No usable descriptor** (`getCliStatus` absent, `undefined`, or a + `statusUpdatedAt` that is not an integer): no wait, today's behaviour. +- **Single triggers do not share this path.** Their own `wait` field + (`idle` by the level probe, or `none`) is unchanged and no descriptor wait + is added: `wait: "none"` is an explicit request not to wait. +- **Busy-fall authority (#360).** `waitForBusyFall` receives the Enter's + timestamp (`submitWithVerify` returns `enterAt`). A descriptor `idle` with + `statusUpdatedAt >= enterAt`, held for the settle window, ends the wait even + when `_cliBusy` is stuck true (observed: 600 s stuck, CLI idle within a + minute, `chain timeout` after step 0). An idle older than the Enter proves + nothing (the Enter may have been absorbed) and leaves the `_cliBusy` logic in + charge, as it does when no usable descriptor exists. A descriptor `busy` + does not hold the wait open on its own. + +Tests: `test/trigger-every-step-readiness.test.js` (the real watcher with a +fake descriptor, plus `waitForBusyFall` under mocked timers). + ### Why `composerEmptyAfterWrite` cannot be made to prove submission, even by feeding it our own writes A proposal, considered and rejected 2026-09-04: since `submitToPty` writes diff --git a/CHANGELOG.md b/CHANGELOG.md index 00da1499..c0ab8d7e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,7 @@ What changes for you in each release of Switchboard. How to write an entry: [doc ### Changed - After three failed refreshes of a remote host in a row, a row that would have attached opens its transcript and says why in its tooltip, instead of failing when clicked. Stop is never disabled: it runs its own ssh. (#218) ### Fixed +- A step of a trigger chain, the first one included, now waits for the CLI to be at its prompt before it is written, so steps are no longer lost while background agents run; a step is never typed into an open dialog. A chain no longer times out after a step on a session that is idle but still shown as busy. (#407, #360) - A step of a trigger chain that follows `/compact` now waits for the CLI to be back at its prompt before it is written, and a step whose Enter did not start a turn is retried once and then reported as "not confirmed submitted" in the log and the result instead of "sent". (#407) - Stopping a terminal twice in quick succession, or resizing it while it is being stopped, no longer closes the Windows pseudo console twice, which could kill the whole app with no error. (#405) - A sandboxed session, or a sandboxed schedule, whose Additional Directories include a `.claude` or `.git` directory, or a path inside one, is now refused instead of binding it read-write over its read-only protection; add the project directory instead. A session started in a `.claude` or `.git` directory is refused too, except below `.claude/worktrees`, and Additional Directories naming your home directory or a parent of it are refused however the path is written. A relative `add-dirs` entry in a schedule is taken from the schedule's directory. (#385) diff --git a/test/trigger-every-step-readiness.test.js b/test/trigger-every-step-readiness.test.js new file mode 100644 index 00000000..f2f2dcb5 --- /dev/null +++ b/test/trigger-every-step-readiness.test.js @@ -0,0 +1,176 @@ +// test/trigger-every-step-readiness.test.js +// +// The descriptor readiness wait before EVERY chain step, and the descriptor as +// the authority for the busy-fall wait. See +// .ai/contexts/trigger-watcher.md, "Readiness before every step". +'use strict'; + +process.env.SWITCHBOARD_SUBMIT_ENTER_DELAY_MS = '1'; +process.env.SWITCHBOARD_SUBMIT_VERIFY_MS = '400'; +process.env.SWITCHBOARD_BUSY_FALL_SETTLE_MS = '50'; +process.env.SWITCHBOARD_BUSY_RISE_WAIT_MS = '100'; + +const test = require('node:test'); +const assert = require('node:assert/strict'); +const fs = require('fs'); +const os = require('os'); +const path = require('path'); + +const { start, waitForBusyFall } = require('../trigger-watcher'); + +function mkTmp() { + return fs.realpathSync.native(fs.mkdtempSync(path.join(os.tmpdir(), 'sw-trigger-every-'))); +} + +function recordingLog() { + const lines = []; + const mk = (level) => (...args) => { lines.push({ level, text: args.join(' ') }); }; + return { lines, info: mk('info'), warn: mk('warn'), error: mk('error'), debug: () => {} }; +} + +function chainSession(sessionId, { log, onEnter, withDescriptor = true }) { + const written = []; + const desc = { status: 'idle', statusUpdatedAt: Date.now() - 10_000 }; + const ptyProcess = { + pid: process.pid, + write(data) { + written.push({ data, at: Date.now() }); + if (data === '\r') onEnter(written.filter((w) => w.data === '\r').length, desc); + }, + }; + let busy = false; + const ctx = { + log, + getPtyForSession: (id) => (id === sessionId ? { ptyProcess } : null), + isSessionBusy: () => busy, + isPtyAlive: () => true, + getComposerState: () => ({ pending: 0, lastInputAt: 0 }), + }; + if (withDescriptor) ctx.getCliStatus = (id) => (id === sessionId ? { ...desc } : undefined); + return { ctx, written, desc, setBusy(v) { busy = v; } }; +} + +async function runChain(chain, session, uuid, timeoutMs = 20000) { + const tmp = mkTmp(); + process.env.SWITCHBOARD_TRIGGERS_DIR = tmp; + process.env.SWITCHBOARD_TRIGGER_IDLE_TIMEOUT_MS = '2000'; + const watcher = start(session.ctx); + try { + fs.writeFileSync(path.join(tmp, uuid + '.json'), + JSON.stringify({ sessionId: uuid, wait: 'idle', chain, timeout_ms: timeoutMs }), 'utf8'); + const resultPath = path.join(tmp, 'processed', uuid + '.result.json'); + const deadline = Date.now() + 15000; + while (!fs.existsSync(resultPath)) { + if (Date.now() > deadline) throw new Error('no result file'); + await new Promise((r) => setTimeout(r, 20)); + } + await new Promise((r) => setTimeout(r, 20)); + return JSON.parse(fs.readFileSync(resultPath, 'utf8')); + } finally { + watcher.close(); + delete process.env.SWITCHBOARD_TRIGGERS_DIR; + delete process.env.SWITCHBOARD_TRIGGER_IDLE_TIMEOUT_MS; + fs.rmSync(tmp, { recursive: true, force: true }); + } +} + +function quickTurn(session) { + return (_n, desc) => { + desc.status = 'busy'; desc.statusUpdatedAt = Date.now(); + setTimeout(() => { desc.status = 'idle'; desc.statusUpdatedAt = Date.now(); }, 100); + }; +} + +test('step 0 while the descriptor reads busy: nothing is written until it reads idle', async () => { + process.env.SWITCHBOARD_CLI_READY_WAIT_MS = '5000'; + try { + const uuid = 'sess-every-busy-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: (n, d) => quickTurn(session)(n, d) }); + session.desc.status = 'busy'; + session.desc.statusUpdatedAt = Date.now(); + let idleAt = null; + setTimeout(() => { session.desc.status = 'idle'; session.desc.statusUpdatedAt = Date.now(); idleAt = Date.now(); }, 700); + + const result = await runChain([{ command: 'first step' }], session, uuid); + + assert.ok(idleAt, 'the descriptor never went idle'); + assert.equal(session.written[0].data, 'first step'); + assert.ok(session.written[0].at >= idleAt, `step 0 written ${idleAt - session.written[0].at} ms before the descriptor read idle`); + assert.equal(result.ok, true); + } finally { + delete process.env.SWITCHBOARD_CLI_READY_WAIT_MS; + } +}); + +test('a dialog open ("waiting"): never written into, the step fails at the bound with the dialog reason', async () => { + process.env.SWITCHBOARD_CLI_READY_WAIT_MS = '400'; + try { + const uuid = 'sess-every-waiting-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: () => {} }); + session.desc.status = 'waiting'; + session.desc.statusUpdatedAt = Date.now(); + + const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid); + + assert.deepEqual(session.written, []); + assert.equal(result.ok, false); + assert.equal(result.error, 'not sent'); + assert.match(result.reason, /dialog/); + assert.equal(result.steps_completed, 0); + assert.equal(result.steps[0].submitted, 'no'); + } finally { + delete process.env.SWITCHBOARD_CLI_READY_WAIT_MS; + } +}); + +test('#360: _cliBusy stuck true but the descriptor idle after the Enter -> the chain proceeds to step 1', async () => { + const uuid = 'sess-every-stuck-' + Date.now(); + const session = chainSession(uuid, { + log: recordingLog(), + onEnter(n, desc) { + session.setBusy(true); + quickTurn(session)(n, desc); + }, + }); + + const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid, 4000); + + assert.ok(session.written.some((w) => w.data === 'second step'), 'step 1 was never written'); + assert.equal(result.ok, true); +}); + +test('no descriptor: the chain behaves as before, nothing waits before step 0', async () => { + const uuid = 'sess-every-none-' + Date.now(); + const session = chainSession(uuid, { + log: recordingLog(), + withDescriptor: false, + onEnter(n) { + session.setBusy(true); + setTimeout(() => session.setBusy(false), 100); + }, + }); + + const started = Date.now(); + const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid); + + assert.ok(session.written[0].at - started < 1000, 'step 0 was held although no descriptor exists'); + assert.deepEqual(session.written.map((w) => w.data).filter((d) => d !== '\r'), ['first step', 'second step']); + assert.equal(result.ok, true); +}); + +test('waitForBusyFall: a descriptor idle that predates the Enter does not end the wait', async (t) => { + t.mock.timers.enable({ apis: ['Date', 'setTimeout'], now: 1_000_000 }); + const ctx = { + getPtyForSession: () => ({}), + isSessionBusy: () => true, + getCliStatus: () => ({ status: 'idle', statusUpdatedAt: 999_000 }), + }; + const p = waitForBusyFall('sid', ctx, 1_000_000 + 2000, 1_000_000); + let result; + p.then((r) => { result = r; }); + for (let i = 0; i < 600 && !result; i += 1) { + t.mock.timers.tick(5); + await new Promise((r) => setImmediate(r)); + } + assert.equal(result.timedOut, true); +}); diff --git a/trigger-watcher.js b/trigger-watcher.js index 8e06be54..125daa8b 100644 --- a/trigger-watcher.js +++ b/trigger-watcher.js @@ -88,6 +88,7 @@ const SUBMITTED_RANK = { const ERROR_NOT_SENT = 'not sent'; const ERROR_CHAIN_TIMEOUT = 'chain timeout'; +const REASON_DIALOG_OPEN = 'the CLI reports a dialog open (waiting); nothing was written into it'; const ACCEPTED_WAITS = ['idle', 'none']; @@ -381,29 +382,44 @@ function cliForbidsRecoveryEnter(ctx, sessionId) { /** * Wait until the CLI's own descriptor reports "idle" with a statusUpdatedAt - * later than `afterMs`, bounded by `deadlineMs`. + * later than `afterMs`, held for `settleMs`, bounded by `deadlineMs`. * - * Returns { ready, available, timedOut, sessionExited, waited_ms }. `available: - * false` means no descriptor could be read (at the start or later): the caller - * keeps its pre-descriptor behaviour. + * Returns { ready, available, timedOut, sessionExited, waited_ms, lastStatus }. + * `available: false` means no descriptor could be read (at the start or + * later): the caller keeps its pre-descriptor behaviour. `lastStatus` is the + * descriptor's status at the last sample. + * + * see .ai/contexts/trigger-watcher.md, "Readiness before every step" */ -function waitForCliIdleAfter(sessionId, ctx, afterMs, deadlineMs) { +function waitForCliIdleAfter(sessionId, ctx, afterMs, deadlineMs, settleMs = 0) { const start = Date.now(); + let idleSince = null; + let idleStamp = null; + let lastStatus = null; return pollLoop((resolve, scheduleNext) => { const now = Date.now(); const waited_ms = now - start; if (!ctx.getPtyForSession(sessionId)) { - return resolve({ ready: false, available: true, timedOut: false, sessionExited: true, waited_ms }); + return resolve({ ready: false, available: true, timedOut: false, sessionExited: true, waited_ms, lastStatus }); } const s = readCliStatus(ctx, sessionId); if (!s) { - return resolve({ ready: false, available: false, timedOut: false, sessionExited: false, waited_ms }); + return resolve({ ready: false, available: false, timedOut: false, sessionExited: false, waited_ms, lastStatus }); } - if (s.status === 'idle' && Number.isInteger(s.statusUpdatedAt) && s.statusUpdatedAt > afterMs) { - return resolve({ ready: true, available: true, timedOut: false, sessionExited: false, waited_ms }); + lastStatus = s.status; + if (s.status === 'idle' && s.statusUpdatedAt > afterMs) { + if (idleSince === null || idleStamp !== s.statusUpdatedAt) { + idleSince = now; + idleStamp = s.statusUpdatedAt; + } + if (now - idleSince >= settleMs) { + return resolve({ ready: true, available: true, timedOut: false, sessionExited: false, waited_ms, lastStatus }); + } + } else { + idleSince = null; } if (now >= deadlineMs) { - return resolve({ ready: false, available: true, timedOut: true, sessionExited: false, waited_ms }); + return resolve({ ready: false, available: true, timedOut: true, sessionExited: false, waited_ms, lastStatus }); } scheduleNext(); }); @@ -466,6 +482,7 @@ async function submitWithVerify(handle, sessionId, command, ctx, deadlineMs) { const first = await pollForBusyObserved(sessionId, ctx, windowMs, effectiveDeadline, probe); if (first.sawBusy || first.sessionExited || first.timedOut) { return { + enterAt, submit_retries: 0, sawBusy: first.sawBusy, confirmed: edgeMode ? first.sawBusy : null, @@ -483,6 +500,7 @@ async function submitWithVerify(handle, sessionId, command, ctx, deadlineMs) { const recoveryDeadline = Math.min(effectiveDeadline, Date.now() + windowMs); if (cliForbidsRecoveryEnter(ctx, sessionId)) { return { + enterAt, submit_retries: 0, sawBusy: false, confirmed: edgeMode ? false : null, @@ -497,6 +515,7 @@ async function submitWithVerify(handle, sessionId, command, ctx, deadlineMs) { const polite = await waitForComposerFree(sessionId, ctx, recoveryDeadline); if (!polite.free) { return { + enterAt, submit_retries: 0, sawBusy: false, confirmed: edgeMode ? false : null, @@ -514,6 +533,7 @@ async function submitWithVerify(handle, sessionId, command, ctx, deadlineMs) { } catch (err) { // Surface as a sessionExited-like failure; caller maps to an error result. return { + enterAt, submit_retries: 1, sawBusy: false, confirmed: edgeMode ? false : null, @@ -527,6 +547,7 @@ async function submitWithVerify(handle, sessionId, command, ctx, deadlineMs) { const second = await pollForBusyObserved(sessionId, ctx, windowMs, effectiveDeadline, probe); return { + enterAt, submit_retries: 1, sawBusy: second.sawBusy, confirmed: edgeMode ? second.sawBusy : null, @@ -550,9 +571,15 @@ async function submitWithVerify(handle, sessionId, command, ctx, deadlineMs) { * * see .ai/contexts/trigger-watcher.md, "waitForBusyFall waits for the rise too" * + * With `enterAtMs` and a usable descriptor, the descriptor is the authority: idle + * with a statusUpdatedAt at or after the Enter, held for the settle window, + * ends the wait whatever `isSessionBusy` says. Without one the level probe decides. + * + * see .ai/contexts/trigger-watcher.md, "Readiness before every step" + * * Returns { timedOut, sessionExited, waited_ms }. */ -function waitForBusyFall(sessionId, ctx, deadlineMs) { +function waitForBusyFall(sessionId, ctx, deadlineMs, enterAtMs) { const start = Date.now(); const settleMs = getBusyFallSettleMs(); const riseDeadline = start + getBusyRiseWaitMs(); @@ -561,6 +588,8 @@ function waitForBusyFall(sessionId, ctx, deadlineMs) { // Set the instant busy first reads false (after having risen); reset to // null on every re-assertion. let idleSince = null; + let descIdleSince = null; + let descIdleStamp = null; return pollLoop((resolve, scheduleNext) => { const now = Date.now(); @@ -570,6 +599,18 @@ function waitForBusyFall(sessionId, ctx, deadlineMs) { if (!ctx.getPtyForSession(sessionId)) { return resolve({ timedOut: false, sessionExited: true, waited_ms: now - start }); } + const desc = Number.isFinite(enterAtMs) ? readCliStatus(ctx, sessionId) : null; + if (desc && desc.status === 'idle' && desc.statusUpdatedAt >= enterAtMs) { + if (descIdleSince === null || descIdleStamp !== desc.statusUpdatedAt) { + descIdleSince = now; + descIdleStamp = desc.statusUpdatedAt; + } + if (now - descIdleSince >= settleMs) { + return resolve({ timedOut: false, sessionExited: false, waited_ms: now - start }); + } + } else { + descIdleSince = null; + } if (ctx.isSessionBusy(sessionId)) { hasRisen = true; idleSince = null; @@ -1241,12 +1282,11 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR } let readyWaitedMs = 0; - if (readyAfterMs !== null && !readCliStatus(ctx, sessionId)) { + if (!readCliStatus(ctx, sessionId)) { ctx.log.info(`[trigger-watcher] No usable CLI descriptor for ${sessionId}, readiness wait skipped before chain step ${i}`); - } - if (readyAfterMs !== null && readCliStatus(ctx, sessionId)) { + } else { const readyDeadline = Math.min(stepDeadline, Date.now() + getCliReadyWaitMs()); - const ready = await waitForCliIdleAfter(sessionId, ctx, readyAfterMs, readyDeadline); + const ready = await waitForCliIdleAfter(sessionId, ctx, readyAfterMs === null ? -Infinity : readyAfterMs, readyDeadline, getBusyFallSettleMs()); readyWaitedMs = ready.waited_ms; totalWaitedMs += readyWaitedMs; if (ready.sessionExited) { @@ -1257,8 +1297,24 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR if (!ready.available) { ctx.log.info(`[trigger-watcher] CLI descriptor vanished for ${sessionId}, readiness wait ended early before chain step ${i}`); } + if (ready.timedOut && ready.lastStatus === 'waiting') { + ctx.log.warn(`[trigger-watcher] CLI dialog still open after ${readyWaitedMs} ms, chain step ${i} not written:`, sessionId); + steps.push({ + idx: i, command: step.command, sent_at: stepSentAt, waited_ms: polite.waited_ms + readyWaitedMs, + submit_retries: 0, submitted: SUBMITTED_NO, + }); + await writeResult({ + ok: false, + submitted: weakestSubmitted(chainSubmitted, SUBMITTED_NO), + error: (i === 0) ? ERROR_NOT_SENT : ERROR_CHAIN_TIMEOUT, + reason: REASON_DIALOG_OPEN, + partial: i > 0, steps_completed: i, sessionId, sent_at: step0SentAt, steps, + total_waited_ms: totalWaitedMs, + }); + return; + } if (ready.timedOut) { - ctx.log.warn(`[trigger-watcher] CLI not idle after /compact within ${readyWaitedMs} ms, writing chain step ${i} anyway:`, sessionId); + ctx.log.warn(`[trigger-watcher] CLI not idle${readyAfterMs === null ? '' : ' after /compact'} within ${readyWaitedMs} ms, writing chain step ${i} anyway:`, sessionId); } } @@ -1331,7 +1387,7 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR // could not confirm a turn. if (i < chain.length - 1) { // Same per-step deadline as the verify above — bounds the busy-fall wait. - const result = await waitForBusyFall(sessionId, ctx, stepDeadline); + const result = await waitForBusyFall(sessionId, ctx, stepDeadline, verify.enterAt); stepWaitedMs += result.waited_ms; totalWaitedMs += result.waited_ms; @@ -1521,4 +1577,4 @@ function start(ctx) { }; } -module.exports = { start, weakestSubmitted, SUBMITTED_RANK, normalizeCwd, submitWithVerify, waitForCliIdleAfter, isCompactCommand }; +module.exports = { start, weakestSubmitted, SUBMITTED_RANK, normalizeCwd, submitWithVerify, waitForCliIdleAfter, waitForBusyFall, isCompactCommand }; From 02e872fdd1be6874ae1e1d10dd59e5c98d8f7736 Mon Sep 17 00:00:00 2001 From: Jean-Baptiste Date: Fri, 2 Oct 2026 16:54:26 +0200 Subject: [PATCH 2/4] (triggers): never type a chain step while the CLI is not idle (#407, #360) The readiness wait wrote the step anyway after 60 s, so a parent whose descriptor stays busy while delegated agents run still got text typed into a busy composer, and the chain then typed the next step into the same composer. The wait now runs to the step deadline and a step is written only on idle; busy, waiting and unknown statuses fail the step with a reason. A step that stays unconfirmed with the recovery Enter withheld stops the chain. Post-compact readiness is anchored on the compact's Enter, and waiting is judged over the final settle window. Refs #360 Refs #407 --- .ai/contexts/trigger-watcher.md | 84 +++++++------ CHANGELOG.md | 3 +- docs/automation.md | 3 +- test/trigger-descriptor-proof.test.js | 55 ++++----- test/trigger-every-step-readiness.test.js | 143 ++++++++++++++++++++-- trigger-watcher.js | 61 +++++---- 6 files changed, 244 insertions(+), 105 deletions(-) diff --git a/.ai/contexts/trigger-watcher.md b/.ai/contexts/trigger-watcher.md index d46beb52..73ab472b 100644 --- a/.ai/contexts/trigger-watcher.md +++ b/.ai/contexts/trigger-watcher.md @@ -836,11 +836,9 @@ session, which has no local descriptor). No new watcher: it reuses the cache - **Readiness.** (Extended to every step, see the next section.) A chain step that follows a `/compact` step first waits (`waitForCliIdleAfter`) for `status: "idle"` with a `statusUpdatedAt` later - than the compact step's send time. Bounded by - `SWITCHBOARD_CLI_READY_WAIT_MS` (default 60 000 ms) and by the step's own - deadline; on expiry the step is written anyway, with the warning `CLI not - idle after /compact within N ms, writing chain step N anyway`. Its time is - counted in the step's and the chain's `waited_ms`. + than the compact step's Enter. Bounded by the step's own deadline; on + expiry the step is not written (see the next section). Its time is counted + in the step's and the chain's `waited_ms`. - **Proof of submission by edge.** When a descriptor with an integer `statusUpdatedAt` is available, a submission counts when the descriptor shows ANY status write (`busy`, `idle` or `waiting`) with a @@ -889,45 +887,59 @@ descriptor for the helpers; the real watcher for the chain wiring). Second field case (2026-10-02): step 0 of a `compact-now.sh` chain, with no `/compact` before it, landed in the composer and its Enter became a line -break, while four background subagents had just been spawned. The #407 -readiness wait only covered the step after a `/compact`; nothing waited -before step 0. Text written while the CLI is mid-turn has its Enter absorbed -whatever preceded it. - -- **The wait now runs before EVERY chain step**, step 0 included +break, while four background subagents had just been spawned (three still +running). The #407 readiness wait only covered the step after a `/compact`; +nothing waited before step 0. + +**The mechanism is NOT established.** The working hypothesis is that text +written while the CLI is mid-turn has its Enter absorbed as a newline, but #360 +shows the opposite: a step written mid-turn was enqueued and submitted +normally. What is known is only that the step was typed while the descriptor +read `busy`. The rule below stops typing in that state; it does not prove that +state was the cause. + +- **The wait runs before EVERY chain step**, step 0 included (`waitForCliIdleAfter`, after the composer-free and liveness checks, so the descriptor is read as close to the write as possible). Before a step that - follows `/compact` the idle must also be newer than the compact's send; - before any other step any `idle` counts. The idle must hold for the busy-fall - settle window (`SWITCHBOARD_BUSY_FALL_SETTLE_MS`, 300 ms) with an unchanged + follows `/compact` the idle must also be newer than the compact's Enter + (`enterAt` from `submitWithVerify`); before any other step any `idle` counts. + The idle must hold for the busy-fall settle window + (`SWITCHBOARD_BUSY_FALL_SETTLE_MS`, 300 ms) with an unchanged `statusUpdatedAt`, so a `busy` that follows an `idle` within the window is - not mistaken for readiness. Bound: `SWITCHBOARD_CLI_READY_WAIT_MS` (default - 60 000 ms) and the step's own deadline. -- **`waiting` (a dialog is open) is never typed into.** If the descriptor still - reads `waiting` when the bound expires, the step is NOT written: the result - is `ok: false`, `error` `not sent` (step 0) or `chain timeout` (later steps), - `reason` "the CLI reports a dialog open (waiting); nothing was written into - it", the step is recorded with `submitted: "no"`. -- **`busy` at the bound** keeps the #410 behaviour: the step is written anyway - with the warning `CLI not idle ... within N ms, writing chain step N anyway`. - Failing there instead would turn a stuck descriptor into a lost chain; the - submission proof and the recovery-Enter ban still apply to that write. + not mistaken for readiness. +- **The wait is bounded by the step's own deadline only** (the per-step + `timeout_ms`, capped by the chain's). `SWITCHBOARD_CLI_READY_WAIT_MS` is gone. + A parent session keeps its descriptor `busy` for as long as a delegated + agent runs (`cli-session-state.md`), so a shorter bound would write into the + very state this rule exists for. +- **Not idle at the deadline means not written, whatever the status**: + `busy`, `waiting` (a dialog is open) and any status this code does not know + (e.g. `shell`) are all not-idle and not-writable. The step fails: result + `ok: false`, `error` `not sent` (step 0) or `chain timeout` (later steps), + `submitted` the weakest of the chain so far, the step recorded with + `submitted: "no"`, and a `reason` naming the cause (dialog open, turn still + running, never idle). A dialog is reported when `waiting` was sampled + anywhere in the final settle window, not only on the last sample. +- **A step typed but not confirmed, with the recovery Enter withheld** (the + descriptor reads `busy` or `waiting` and showed no reaction to our Enter) + stops the chain: `ok: false`, `error` `step not confirmed`, nothing more is + typed into that composer. The step's text may be sitting there. - **No usable descriptor** (`getCliStatus` absent, `undefined`, or a `statusUpdatedAt` that is not an integer): no wait, today's behaviour. -- **Single triggers do not share this path.** Their own `wait` field - (`idle` by the level probe, or `none`) is unchanged and no descriptor wait - is added: `wait: "none"` is an explicit request not to wait. +- **Single triggers have the same exposure and it is not addressed here.** + They keep their own `wait` field (`idle` by the level probe, or `none`) and + no descriptor wait; they can still be typed into a busy composer. - **Busy-fall authority (#360).** `waitForBusyFall` receives the Enter's - timestamp (`submitWithVerify` returns `enterAt`). A descriptor `idle` with - `statusUpdatedAt >= enterAt`, held for the settle window, ends the wait even - when `_cliBusy` is stuck true (observed: 600 s stuck, CLI idle within a - minute, `chain timeout` after step 0). An idle older than the Enter proves - nothing (the Enter may have been absorbed) and leaves the `_cliBusy` logic in - charge, as it does when no usable descriptor exists. A descriptor `busy` - does not hold the wait open on its own. + timestamp. A descriptor `idle` with `statusUpdatedAt >= enterAt`, held for the + settle window, ends the wait even when `_cliBusy` is stuck true. An idle + older than the Enter proves nothing (the Enter may have been absorbed) and + leaves the `_cliBusy` logic in charge, as it does when no usable descriptor + exists. Not measured as fixed for sessions with background agents: the + descriptor stays `busy` until the last agent ends, so the busy-fall still + waits for it. Tests: `test/trigger-every-step-readiness.test.js` (the real watcher with a -fake descriptor, plus `waitForBusyFall` under mocked timers). +fake descriptor, plus the wait helpers under mocked timers). ### Why `composerEmptyAfterWrite` cannot be made to prove submission, even by feeding it our own writes diff --git a/CHANGELOG.md b/CHANGELOG.md index c0ab8d7e..31dfc272 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,8 +10,7 @@ What changes for you in each release of Switchboard. How to write an entry: [doc ### Changed - After three failed refreshes of a remote host in a row, a row that would have attached opens its transcript and says why in its tooltip, instead of failing when clicked. Stop is never disabled: it runs its own ssh. (#218) ### Fixed -- A step of a trigger chain, the first one included, now waits for the CLI to be at its prompt before it is written, so steps are no longer lost while background agents run; a step is never typed into an open dialog. A chain no longer times out after a step on a session that is idle but still shown as busy. (#407, #360) -- A step of a trigger chain that follows `/compact` now waits for the CLI to be back at its prompt before it is written, and a step whose Enter did not start a turn is retried once and then reported as "not confirmed submitted" in the log and the result instead of "sent". (#407) +- A step of a trigger chain, the first one included, is no longer typed while the CLI reads busy or waiting on a dialog: it waits for the CLI to be at its prompt, up to the step's deadline, then fails cleanly with a reason instead of being written; a step whose Enter did not start a turn is retried once, or stops the chain when the CLI is busy, and is reported as "not confirmed submitted" instead of "sent". Single triggers are not covered. (#407, #360) - Stopping a terminal twice in quick succession, or resizing it while it is being stopped, no longer closes the Windows pseudo console twice, which could kill the whole app with no error. (#405) - A sandboxed session, or a sandboxed schedule, whose Additional Directories include a `.claude` or `.git` directory, or a path inside one, is now refused instead of binding it read-write over its read-only protection; add the project directory instead. A session started in a `.claude` or `.git` directory is refused too, except below `.claude/worktrees`, and Additional Directories naming your home directory or a parent of it are refused however the path is written. A relative `add-dirs` entry in a schedule is taken from the schedule's directory. (#385) - A session that has exited no longer keeps a busy dot in the sidebar, and the status bar's running count drops as soon as the session ends instead of waiting for the next refresh. (#375) diff --git a/docs/automation.md b/docs/automation.md index e0c0cc9b..e3f2f0ac 100644 --- a/docs/automation.md +++ b/docs/automation.md @@ -263,7 +263,6 @@ spends the same budget. | `SWITCHBOARD_TRIGGER_MAX_AGE_MS` | The staleness limit | 300 000 | | `SWITCHBOARD_SUBMIT_ENTER_DELAY_MS` | Delay between the text and its Enter | 50 | | `SWITCHBOARD_SUBMIT_VERIFY_MS` | How long a submission is watched for a turn | 2 000 | -| `SWITCHBOARD_CLI_READY_WAIT_MS` | How long a chain step after `/compact` waits for the CLI to report idle | 60 000 | | `SWITCHBOARD_BUSY_FALL_SETTLE_MS` | How long "not busy" must hold between chain steps | 300 | The triggers directory does not move with `SWITCHBOARD_DATA_DIR`: an instance @@ -434,6 +433,7 @@ never in `error`: `not sent: input pending` is not `not sent`. |---|---|---| | `not sent` | **not one byte reached the session**: no idle came, politeness never allowed a write, or the trigger was refused before any write (stale, bad `wait`, bad `expectedCwd`, target guard) | nothing happened; it is safe to send again | | `chain timeout` | at least one step **was written**, and the expected effect was not observed before the deadline | assume the written steps landed | +| `step not confirmed` | a chain step **was written**, its submission was not confirmed by the CLI's descriptor, and the recovery Enter was withheld because the descriptor reads `busy` or `waiting`; the chain stopped there and nothing more was typed | the step may sit unsubmitted in the composer: look before sending again | | anything else | free text: `session not found`, `target process not running`, `missing required field`, `invalid timeout_ms`, `command and chain are mutually exclusive`, `trigger too large (max 64 KB)`, `command too long (max 4 KB)`, `trigger must be a regular file`, `pty write failed: …` | read `submitted` to know whether anything landed | The two reserved values mean opposite things: @@ -446,6 +446,7 @@ The two reserved values mean opposite things: `partial: false` for a `chain`. A session reports itself busy for as long as any subagent runs, so `idle` is often unreachable; `not sent` there tells the caller the payload never left. +- A chain step is held until the CLI's descriptor reads `idle`, up to the step's deadline. If it still reads `busy` or `waiting` (or any status other than `idle`) then, the step is not written: `not sent` for the first step, `chain timeout` for a later one, with the cause in `reason`. A session with delegated agents running keeps the parent descriptor `busy`, so such a chain fails cleanly instead of typing into a busy composer. Without a readable descriptor nothing is waited for. - A session that exits during that initial wait reports `submitted: "no"` and a `reason` saying nothing was written (`partial: false` on a chain). diff --git a/test/trigger-descriptor-proof.test.js b/test/trigger-descriptor-proof.test.js index 61c085ae..f6e92bc2 100644 --- a/test/trigger-descriptor-proof.test.js +++ b/test/trigger-descriptor-proof.test.js @@ -263,14 +263,14 @@ function chainSession(sessionId, { log, onEnter }) { return { ctx, written, desc, setBusy(v) { busy = v; } }; } -async function runChain(chain, session, uuid) { +async function runChain(chain, session, uuid, timeoutMs = 20000) { const tmp = mkTmp(); process.env.SWITCHBOARD_TRIGGERS_DIR = tmp; process.env.SWITCHBOARD_TRIGGER_IDLE_TIMEOUT_MS = '2000'; const watcher = start(session.ctx); try { fs.writeFileSync(path.join(tmp, uuid + '.json'), - JSON.stringify({ sessionId: uuid, wait: 'idle', chain, timeout_ms: 20000 }), 'utf8'); + JSON.stringify({ sessionId: uuid, wait: 'idle', chain, timeout_ms: timeoutMs }), 'utf8'); const resultPath = path.join(tmp, 'processed', uuid + '.result.json'); const deadline = Date.now() + 15000; while (!fs.existsSync(resultPath)) { @@ -321,38 +321,33 @@ test('chain: the step after /compact is held until the descriptor is idle after assert.ok(!log.lines.some((l) => /Chain step 1 sent/.test(l.text))); }); -test('chain: a CLI that never goes idle after /compact -> bounded wait, warning, step still written', async () => { - process.env.SWITCHBOARD_CLI_READY_WAIT_MS = '300'; - try { - const uuid = 'sess-desc-timeout-' + Date.now(); - const log = recordingLog(); - const session = chainSession(uuid, { - log, - onEnter(n, desc) { - if (n === 1) { - desc.status = 'busy'; desc.statusUpdatedAt = Date.now(); - setTimeout(() => session.setBusy(false), 60); - } - }, - }); - session.setBusy(false); +test('chain: a CLI that never goes idle after /compact -> held to the step deadline, step never written, chain fails', async () => { + const uuid = 'sess-desc-timeout-' + Date.now(); + const log = recordingLog(); + const session = chainSession(uuid, { + log, + onEnter(n, desc) { + if (n === 1) { + desc.status = 'busy'; desc.statusUpdatedAt = Date.now(); + setTimeout(() => session.setBusy(false), 60); + } + }, + }); + session.setBusy(false); - const started = Date.now(); - const result = await runChain([{ command: '/compact' }, { command: 'resume the work' }], session, uuid); + const started = Date.now(); + const result = await runChain([{ command: '/compact' }, { command: 'resume the work' }], session, uuid, 2500); - const nextText = session.written.find((w) => w.data === 'resume the work'); - assert.ok(nextText, 'the step must still be written after the bounded wait'); - assert.ok(log.lines.some((l) => l.level === 'warn' && /CLI not idle after \/compact/.test(l.text))); - assert.ok(nextText.at - started >= 300, 'the readiness wait must have been honoured up to its bound'); - assert.equal(result.ok, true); - } finally { - delete process.env.SWITCHBOARD_CLI_READY_WAIT_MS; - } + assert.ok(!session.written.some((w) => w.data === 'resume the work'), 'a step must never be typed while the CLI reads busy'); + assert.ok(Date.now() - started >= 2000, 'the wait must run to the step deadline'); + assert.equal(result.ok, false); + assert.equal(result.error, 'chain timeout'); + assert.match(result.reason, /busy/); + assert.equal(result.steps_completed, 1); }); test('chain: an Enter that never starts a turn is reported "not confirmed submitted", never "sent"', async () => { - process.env.SWITCHBOARD_CLI_READY_WAIT_MS = '200'; - try { + { const uuid = 'sess-desc-unconfirmed-' + Date.now(); const log = recordingLog(); const session = chainSession(uuid, { @@ -374,7 +369,5 @@ test('chain: an Enter that never starts a turn is reported "not confirmed submit assert.equal(result.steps[1].submitted, 'assumed'); assert.deepEqual(result.unconfirmed_steps, [1]); assert.equal(result.submitted, 'assumed'); - } finally { - delete process.env.SWITCHBOARD_CLI_READY_WAIT_MS; } }); diff --git a/test/trigger-every-step-readiness.test.js b/test/trigger-every-step-readiness.test.js index f2f2dcb5..44bc932f 100644 --- a/test/trigger-every-step-readiness.test.js +++ b/test/trigger-every-step-readiness.test.js @@ -16,7 +16,7 @@ const fs = require('fs'); const os = require('os'); const path = require('path'); -const { start, waitForBusyFall } = require('../trigger-watcher'); +const { start, waitForBusyFall, waitForCliIdleAfter } = require('../trigger-watcher'); function mkTmp() { return fs.realpathSync.native(fs.mkdtempSync(path.join(os.tmpdir(), 'sw-trigger-every-'))); @@ -82,8 +82,7 @@ function quickTurn(session) { } test('step 0 while the descriptor reads busy: nothing is written until it reads idle', async () => { - process.env.SWITCHBOARD_CLI_READY_WAIT_MS = '5000'; - try { + { const uuid = 'sess-every-busy-' + Date.now(); const session = chainSession(uuid, { log: recordingLog(), onEnter: (n, d) => quickTurn(session)(n, d) }); session.desc.status = 'busy'; @@ -97,20 +96,17 @@ test('step 0 while the descriptor reads busy: nothing is written until it reads assert.equal(session.written[0].data, 'first step'); assert.ok(session.written[0].at >= idleAt, `step 0 written ${idleAt - session.written[0].at} ms before the descriptor read idle`); assert.equal(result.ok, true); - } finally { - delete process.env.SWITCHBOARD_CLI_READY_WAIT_MS; } }); -test('a dialog open ("waiting"): never written into, the step fails at the bound with the dialog reason', async () => { - process.env.SWITCHBOARD_CLI_READY_WAIT_MS = '400'; - try { +test('a dialog open ("waiting"): never written into, the step fails at the deadline with the dialog reason', async () => { + { const uuid = 'sess-every-waiting-' + Date.now(); const session = chainSession(uuid, { log: recordingLog(), onEnter: () => {} }); session.desc.status = 'waiting'; session.desc.statusUpdatedAt = Date.now(); - const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid); + const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid, 1500); assert.deepEqual(session.written, []); assert.equal(result.ok, false); @@ -118,8 +114,6 @@ test('a dialog open ("waiting"): never written into, the step fails at the bound assert.match(result.reason, /dialog/); assert.equal(result.steps_completed, 0); assert.equal(result.steps[0].submitted, 'no'); - } finally { - delete process.env.SWITCHBOARD_CLI_READY_WAIT_MS; } }); @@ -174,3 +168,130 @@ test('waitForBusyFall: a descriptor idle that predates the Enter does not end th } assert.equal(result.timedOut, true); }); + +for (const status of ['busy', 'shell']) { + test(`step 0 while the descriptor reads "${status}" to the deadline: never written, the step fails "not sent" with a reason`, async () => { + const uuid = 'sess-every-never-' + status + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: () => {} }); + session.desc.status = status; + session.desc.statusUpdatedAt = Date.now(); + + const started = Date.now(); + const result = await runChain([{ command: 'first step' }], session, uuid, 1500); + await new Promise((r) => setTimeout(r, 300)); + + assert.deepEqual(session.written, []); + assert.ok(Date.now() - started >= 1400, 'the wait must run to the step deadline, not stop early'); + assert.equal(result.ok, false); + assert.equal(result.error, 'not sent'); + assert.ok(result.reason && result.reason.length > 0); + assert.equal(result.steps_completed, 0); + }); +} + +test('a later step held by a busy descriptor to the deadline: not written, "chain timeout", the first step stays completed', async () => { + const uuid = 'sess-every-later-' + Date.now(); + const session = chainSession(uuid, { + log: recordingLog(), + onEnter(n, desc) { + desc.status = 'busy'; desc.statusUpdatedAt = Date.now(); + session.setBusy(true); + setTimeout(() => session.setBusy(false), 100); + }, + }); + + const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid, 2500); + + assert.ok(!session.written.some((w) => w.data === 'second step')); + assert.equal(result.ok, false); + assert.equal(result.error, 'chain timeout'); + assert.match(result.reason, /busy/); + assert.equal(result.steps_completed, 1); +}); + +test('a step not confirmed with the recovery Enter withheld stops the chain: nothing more is typed', async () => { + const uuid = 'sess-every-stop-' + Date.now(); + const session = chainSession(uuid, { + log: recordingLog(), + onEnter(n, desc) { desc.status = 'busy'; }, + }); + + const result = await runChain([{ command: 'first step' }, { command: 'second step' }], session, uuid, 4000); + + assert.deepEqual(session.written.map((w) => w.data), ['first step', '\r']); + assert.equal(result.ok, false); + assert.equal(result.error, 'step not confirmed'); + assert.ok(result.reason && result.reason.length > 0); + assert.equal(result.steps_completed, 0); + assert.equal(result.steps[0].submit_confirmed, false); +}); + +function fakeClock(t) { + t.mock.timers.enable({ apis: ['Date', 'setTimeout'], now: 1_000_000 }); +} + +async function settleRun(t, promise, maxMs = 5000) { + let done = false; + let value; + promise.then((v) => { done = true; value = v; }); + for (let i = 0; i < maxMs && !done; i += 5) { + t.mock.timers.tick(5); + await new Promise((r) => setImmediate(r)); + } + assert.ok(done, 'still pending'); + return value; +} + +function stateCtx(state) { + return { getPtyForSession: () => ({}), getCliStatus: () => ({ ...state }) }; +} + +test('readiness settle: an idle followed by busy inside the settle window is not ready; ready only once idle has held', async (t) => { + fakeClock(t); + const state = { status: 'idle', statusUpdatedAt: 1_000_000 }; + setTimeout(() => { state.status = 'busy'; state.statusUpdatedAt = Date.now(); }, 150); + setTimeout(() => { state.status = 'idle'; state.statusUpdatedAt = Date.now(); }, 400); + const r = await settleRun(t, waitForCliIdleAfter('sid', stateCtx(state), -Infinity, 1_000_000 + 5000, 300)); + assert.equal(r.ready, true); + assert.ok(r.waited_ms >= 700, 'ready after ' + r.waited_ms + ' ms, expected the settle to restart at the second idle'); +}); + +test('readiness settle: a new statusUpdatedAt while idle restarts the settle window', async (t) => { + fakeClock(t); + const state = { status: 'idle', statusUpdatedAt: 1_000_000 }; + setTimeout(() => { state.statusUpdatedAt = Date.now(); }, 200); + const r = await settleRun(t, waitForCliIdleAfter('sid', stateCtx(state), -Infinity, 1_000_000 + 5000, 300)); + assert.equal(r.ready, true); + assert.ok(r.waited_ms >= 500, 'ready after ' + r.waited_ms + ' ms, expected the settle to restart at the new timestamp'); +}); + +test('readiness: a dialog seen anywhere in the final settle window is reported even when the last sample is busy', async (t) => { + fakeClock(t); + const state = { status: 'busy', statusUpdatedAt: 1_000_000 }; + setTimeout(() => { state.status = 'waiting'; state.statusUpdatedAt = Date.now(); }, 1800); + setTimeout(() => { state.status = 'busy'; state.statusUpdatedAt = Date.now(); }, 1900); + const r = await settleRun(t, waitForCliIdleAfter('sid', stateCtx(state), -Infinity, 1_000_000 + 2000, 300)); + assert.equal(r.ready, false); + assert.equal(r.timedOut, true); + assert.equal(r.lastStatus, 'busy'); + assert.equal(r.waitingSeen, true); +}); + +test('readiness: an unknown status is not idle', async (t) => { + fakeClock(t); + const state = { status: 'shell', statusUpdatedAt: 1_000_000 }; + const r = await settleRun(t, waitForCliIdleAfter('sid', stateCtx(state), -Infinity, 1_000_000 + 1000, 0)); + assert.equal(r.ready, false); + assert.equal(r.timedOut, true); +}); + +test('waitForBusyFall: an idle that flickers back to busy inside the settle window does not end the wait early', async (t) => { + fakeClock(t); + const state = { status: 'idle', statusUpdatedAt: 1_000_000 }; + setTimeout(() => { state.status = 'busy'; state.statusUpdatedAt = Date.now(); }, 20); + setTimeout(() => { state.status = 'idle'; state.statusUpdatedAt = Date.now(); }, 200); + const ctx = { getPtyForSession: () => ({}), isSessionBusy: () => true, getCliStatus: () => ({ ...state }) }; + const r = await settleRun(t, waitForBusyFall('sid', ctx, 1_000_000 + 5000, 1_000_000)); + assert.equal(r.timedOut, false); + assert.ok(r.waited_ms >= 240, 'ended after ' + r.waited_ms + ' ms, before the second idle had held'); +}); diff --git a/trigger-watcher.js b/trigger-watcher.js index 125daa8b..02a93fe8 100644 --- a/trigger-watcher.js +++ b/trigger-watcher.js @@ -88,7 +88,10 @@ const SUBMITTED_RANK = { const ERROR_NOT_SENT = 'not sent'; const ERROR_CHAIN_TIMEOUT = 'chain timeout'; +const ERROR_UNCONFIRMED = 'step not confirmed'; const REASON_DIALOG_OPEN = 'the CLI reports a dialog open (waiting); nothing was written into it'; +const REASON_CLI_BUSY = 'the CLI still reported a turn running (busy) at the deadline; nothing was written'; +const REASON_CLI_NOT_IDLE = 'the CLI never reported idle before the deadline; nothing was written'; const ACCEPTED_WAITS = ['idle', 'none']; @@ -342,13 +345,6 @@ function pollForBusyObserved(sessionId, ctx, windowMs, deadlineMs, probe) { }); } -// see .ai/contexts/trigger-watcher.md, "Readiness and edge proof from the CLI descriptor" -const DEFAULT_CLI_READY_WAIT_MS = 60_000; // ms -function getCliReadyWaitMs() { - const v = envNumber('SWITCHBOARD_CLI_READY_WAIT_MS'); - return v !== undefined ? v : DEFAULT_CLI_READY_WAIT_MS; -} - function readCliStatusRaw(ctx, sessionId) { if (typeof ctx.getCliStatus !== 'function') return null; try { @@ -384,10 +380,11 @@ function cliForbidsRecoveryEnter(ctx, sessionId) { * Wait until the CLI's own descriptor reports "idle" with a statusUpdatedAt * later than `afterMs`, held for `settleMs`, bounded by `deadlineMs`. * - * Returns { ready, available, timedOut, sessionExited, waited_ms, lastStatus }. - * `available: false` means no descriptor could be read (at the start or - * later): the caller keeps its pre-descriptor behaviour. `lastStatus` is the - * descriptor's status at the last sample. + * Returns { ready, available, timedOut, sessionExited, waited_ms, lastStatus, + * waitingSeen }. `available: false` means no descriptor could be read (at the + * start or later): the caller keeps its pre-descriptor behaviour. `lastStatus` + * is the descriptor's status at the last sample; `waitingSeen` is true when a + * dialog (`waiting`) was sampled within the last `settleMs` before the end. * * see .ai/contexts/trigger-watcher.md, "Readiness before every step" */ @@ -396,30 +393,33 @@ function waitForCliIdleAfter(sessionId, ctx, afterMs, deadlineMs, settleMs = 0) let idleSince = null; let idleStamp = null; let lastStatus = null; + let lastWaitingAt = null; return pollLoop((resolve, scheduleNext) => { const now = Date.now(); const waited_ms = now - start; + const waitingSeen = lastWaitingAt !== null && now - lastWaitingAt <= settleMs; if (!ctx.getPtyForSession(sessionId)) { - return resolve({ ready: false, available: true, timedOut: false, sessionExited: true, waited_ms, lastStatus }); + return resolve({ ready: false, available: true, timedOut: false, sessionExited: true, waited_ms, lastStatus, waitingSeen }); } const s = readCliStatus(ctx, sessionId); if (!s) { - return resolve({ ready: false, available: false, timedOut: false, sessionExited: false, waited_ms, lastStatus }); + return resolve({ ready: false, available: false, timedOut: false, sessionExited: false, waited_ms, lastStatus, waitingSeen }); } lastStatus = s.status; + if (s.status === 'waiting') lastWaitingAt = now; if (s.status === 'idle' && s.statusUpdatedAt > afterMs) { if (idleSince === null || idleStamp !== s.statusUpdatedAt) { idleSince = now; idleStamp = s.statusUpdatedAt; } if (now - idleSince >= settleMs) { - return resolve({ ready: true, available: true, timedOut: false, sessionExited: false, waited_ms, lastStatus }); + return resolve({ ready: true, available: true, timedOut: false, sessionExited: false, waited_ms, lastStatus, waitingSeen }); } } else { idleSince = null; } if (now >= deadlineMs) { - return resolve({ ready: false, available: true, timedOut: true, sessionExited: false, waited_ms, lastStatus }); + return resolve({ ready: false, available: true, timedOut: true, sessionExited: false, waited_ms, lastStatus, waitingSeen: lastWaitingAt !== null && now - lastWaitingAt <= settleMs }); } scheduleNext(); }); @@ -1233,7 +1233,6 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR // Inject the step command const stepSentAt = new Date().toISOString(); if (i === 0) step0SentAt = stepSentAt; - if (isCompactCommand(step.command)) compactSentAtMs = Date.parse(stepSentAt); // Per-step timeout_ms (if set) bounds THIS whole step (verify + retry + the // busy-fall wait for non-final steps), capped by the remaining global @@ -1285,8 +1284,7 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR if (!readCliStatus(ctx, sessionId)) { ctx.log.info(`[trigger-watcher] No usable CLI descriptor for ${sessionId}, readiness wait skipped before chain step ${i}`); } else { - const readyDeadline = Math.min(stepDeadline, Date.now() + getCliReadyWaitMs()); - const ready = await waitForCliIdleAfter(sessionId, ctx, readyAfterMs === null ? -Infinity : readyAfterMs, readyDeadline, getBusyFallSettleMs()); + const ready = await waitForCliIdleAfter(sessionId, ctx, readyAfterMs === null ? -Infinity : readyAfterMs, stepDeadline, getBusyFallSettleMs()); readyWaitedMs = ready.waited_ms; totalWaitedMs += readyWaitedMs; if (ready.sessionExited) { @@ -1297,8 +1295,10 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR if (!ready.available) { ctx.log.info(`[trigger-watcher] CLI descriptor vanished for ${sessionId}, readiness wait ended early before chain step ${i}`); } - if (ready.timedOut && ready.lastStatus === 'waiting') { - ctx.log.warn(`[trigger-watcher] CLI dialog still open after ${readyWaitedMs} ms, chain step ${i} not written:`, sessionId); + if (ready.timedOut) { + const dialog = ready.waitingSeen || ready.lastStatus === 'waiting'; + const reason = dialog ? REASON_DIALOG_OPEN : (ready.lastStatus === 'busy' ? REASON_CLI_BUSY : REASON_CLI_NOT_IDLE); + ctx.log.warn(`[trigger-watcher] CLI not ready (${ready.lastStatus}) after ${readyWaitedMs} ms, chain step ${i} not written:`, sessionId); steps.push({ idx: i, command: step.command, sent_at: stepSentAt, waited_ms: polite.waited_ms + readyWaitedMs, submit_retries: 0, submitted: SUBMITTED_NO, @@ -1307,15 +1307,12 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR ok: false, submitted: weakestSubmitted(chainSubmitted, SUBMITTED_NO), error: (i === 0) ? ERROR_NOT_SENT : ERROR_CHAIN_TIMEOUT, - reason: REASON_DIALOG_OPEN, + reason, partial: i > 0, steps_completed: i, sessionId, sent_at: step0SentAt, steps, total_waited_ms: totalWaitedMs, }); return; } - if (ready.timedOut) { - ctx.log.warn(`[trigger-watcher] CLI not idle${readyAfterMs === null ? '' : ' after /compact'} within ${readyWaitedMs} ms, writing chain step ${i} anyway:`, sessionId); - } } // Submit the step, then look for activity on the session. @@ -1341,6 +1338,9 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR await writeResult({ ok: false, error: 'pty write failed: ' + verify.writeError.message, partial: true, steps_completed: i, sessionId, sent_at: step0SentAt, steps, total_waited_ms: totalWaitedMs }); return; } + if (isCompactCommand(step.command)) { + compactSentAtMs = Number.isFinite(verify.enterAt) ? verify.enterAt : Date.parse(stepSentAt); + } submitRetries = verify.submit_retries; stepWaitedMs += verify.waited_ms; totalWaitedMs += verify.waited_ms; @@ -1378,6 +1378,19 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR return; } + if (stepConfirmed === false && verify.recoverySkipped) { + steps.push({ idx: i, command: step.command, sent_at: stepSentAt, waited_ms: stepWaitedMs, submit_retries: submitRetries, submitted: stepSubmitted, submit_confirmed: false }); + await writeResult({ + ok: false, + submitted: chainSubmitted, + error: ERROR_UNCONFIRMED, + reason: `chain step ${i} was typed but its submission was not confirmed and the recovery Enter was withheld (${verify.recoveryReason}); nothing more was typed`, + partial: true, steps_completed: i, sessionId, sent_at: step0SentAt, steps, + total_waited_ms: totalWaitedMs, + }); + return; + } + // For non-final steps, wait for the turn to FINISH (busy falling edge). // submitWithVerify already consumed the observation. If busy was never // observed (instant-reply / unconfirmed submit), busy is already false, From 399e89cb13e7d525308e200ba3b2f3f1df9ec29d Mon Sep 17 00:00:00 2001 From: Jean-Baptiste Date: Fri, 2 Oct 2026 17:09:37 +0200 Subject: [PATCH 3/4] (triggers): keep waiting when the descriptor vanishes, never write past the step deadline (#407, #360) A descriptor lost after it had been read ended the readiness wait and let the step be typed into a CLI last seen busy. It now counts as not idle until it reappears or the deadline passes. A settle completing at or after the deadline no longer reads as ready, and the deadline is checked again right before the write. Refs #360 Refs #407 --- .ai/contexts/trigger-watcher.md | 22 ++++- CHANGELOG.md | 2 +- docs/automation.md | 2 +- test/trigger-every-step-readiness.test.js | 107 ++++++++++++++++++++++ trigger-watcher.js | 65 ++++++++----- 5 files changed, 168 insertions(+), 30 deletions(-) diff --git a/.ai/contexts/trigger-watcher.md b/.ai/contexts/trigger-watcher.md index 73ab472b..badffb5a 100644 --- a/.ai/contexts/trigger-watcher.md +++ b/.ai/contexts/trigger-watcher.md @@ -923,9 +923,25 @@ state was the cause. - **A step typed but not confirmed, with the recovery Enter withheld** (the descriptor reads `busy` or `waiting` and showed no reaction to our Enter) stops the chain: `ok: false`, `error` `step not confirmed`, nothing more is - typed into that composer. The step's text may be sitting there. -- **No usable descriptor** (`getCliStatus` absent, `undefined`, or a - `statusUpdatedAt` that is not an integer): no wait, today's behaviour. + typed into that composer. The step's text may be sitting there. The + recovery Enter is also withheld when input of the user's own is pending in + the composer (`waitForComposerFree`), which stops the chain the same way. +- **No usable descriptor at the START of the wait** (`getCliStatus` absent, + `undefined`, or a `statusUpdatedAt` that is not an integer): no wait, today's + behaviour (`available: false`). A descriptor lost AFTER it was read (the CLI + rewriting its file, a failed pid probe, a momentary bad timestamp) is not the + same: it may reappear, so the wait goes on, counted as not idle, until the + deadline, then fails like any not-idle case. Nothing is typed on the strength + of a descriptor that merely vanished. +- **Never ready past the deadline, never written past it.** A settle that + completes at or after the deadline is a timeout, not readiness, and the + deadline is checked again immediately before the write (a step timeout of 0 + or a settle of 0 included): the step fails with `not sent`/`chain timeout` + and the reason "the step deadline passed before it could be written". +- **`waitForCliIdleAfter` return shape**: `{ ready, available, timedOut, + sessionExited, waited_ms, lastStatus, waitingSeen }`. `lastStatus` is the + status at the last sample; `waitingSeen` is true when `waiting` was sampled + within the last settle window before the end. - **Single triggers have the same exposure and it is not addressed here.** They keep their own `wait` field (`idle` by the level probe, or `none`) and no descriptor wait; they can still be typed into a busy composer. diff --git a/CHANGELOG.md b/CHANGELOG.md index 31dfc272..275cf499 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,7 +10,7 @@ What changes for you in each release of Switchboard. How to write an entry: [doc ### Changed - After three failed refreshes of a remote host in a row, a row that would have attached opens its transcript and says why in its tooltip, instead of failing when clicked. Stop is never disabled: it runs its own ssh. (#218) ### Fixed -- A step of a trigger chain, the first one included, is no longer typed while the CLI reads busy or waiting on a dialog: it waits for the CLI to be at its prompt, up to the step's deadline, then fails cleanly with a reason instead of being written; a step whose Enter did not start a turn is retried once, or stops the chain when the CLI is busy, and is reported as "not confirmed submitted" instead of "sent". Single triggers are not covered. (#407, #360) +- A step of a trigger chain, the first one included, is no longer typed while the CLI reads busy or waiting on a dialog: it waits for the CLI to be at its prompt, up to the step's deadline, then fails cleanly with a reason instead of being written; a step whose Enter did not start a turn is retried once, or stops the chain when that retry is withheld because the CLI is busy or waiting on a dialog, or you have typed input pending, and is reported as "not confirmed submitted" instead of "sent". Single triggers are not covered. (#407, #360) - Stopping a terminal twice in quick succession, or resizing it while it is being stopped, no longer closes the Windows pseudo console twice, which could kill the whole app with no error. (#405) - A sandboxed session, or a sandboxed schedule, whose Additional Directories include a `.claude` or `.git` directory, or a path inside one, is now refused instead of binding it read-write over its read-only protection; add the project directory instead. A session started in a `.claude` or `.git` directory is refused too, except below `.claude/worktrees`, and Additional Directories naming your home directory or a parent of it are refused however the path is written. A relative `add-dirs` entry in a schedule is taken from the schedule's directory. (#385) - A session that has exited no longer keeps a busy dot in the sidebar, and the status bar's running count drops as soon as the session ends instead of waiting for the next refresh. (#375) diff --git a/docs/automation.md b/docs/automation.md index e3f2f0ac..1eeb0285 100644 --- a/docs/automation.md +++ b/docs/automation.md @@ -433,7 +433,7 @@ never in `error`: `not sent: input pending` is not `not sent`. |---|---|---| | `not sent` | **not one byte reached the session**: no idle came, politeness never allowed a write, or the trigger was refused before any write (stale, bad `wait`, bad `expectedCwd`, target guard) | nothing happened; it is safe to send again | | `chain timeout` | at least one step **was written**, and the expected effect was not observed before the deadline | assume the written steps landed | -| `step not confirmed` | a chain step **was written**, its submission was not confirmed by the CLI's descriptor, and the recovery Enter was withheld because the descriptor reads `busy` or `waiting`; the chain stopped there and nothing more was typed | the step may sit unsubmitted in the composer: look before sending again | +| `step not confirmed` | a chain step **was written**, its submission was not confirmed by the CLI's descriptor, and the recovery Enter was withheld (the descriptor reads `busy` or `waiting`, or input of your own is pending in the composer); the chain stopped there and nothing more was typed | the step may sit unsubmitted in the composer: look before sending again | | anything else | free text: `session not found`, `target process not running`, `missing required field`, `invalid timeout_ms`, `command and chain are mutually exclusive`, `trigger too large (max 64 KB)`, `command too long (max 4 KB)`, `trigger must be a regular file`, `pty write failed: …` | read `submitted` to know whether anything landed | The two reserved values mean opposite things: diff --git a/test/trigger-every-step-readiness.test.js b/test/trigger-every-step-readiness.test.js index 44bc932f..94f9f2d5 100644 --- a/test/trigger-every-step-readiness.test.js +++ b/test/trigger-every-step-readiness.test.js @@ -295,3 +295,110 @@ test('waitForBusyFall: an idle that flickers back to busy inside the settle wind assert.equal(r.timedOut, false); assert.ok(r.waited_ms >= 240, 'ended after ' + r.waited_ms + ' ms, before the second idle had held'); }); + +test('a descriptor that vanishes after it was read keeps the wait going to the deadline: nothing is written', async () => { + const uuid = 'sess-every-vanish-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: () => {} }); + session.desc.status = 'busy'; + session.desc.statusUpdatedAt = Date.now(); + setTimeout(() => { session.ctx.getCliStatus = () => undefined; }, 500); + + const started = Date.now(); + const result = await runChain([{ command: 'first step' }], session, uuid, 1800); + await new Promise((r) => setTimeout(r, 300)); + + assert.deepEqual(session.written, []); + assert.ok(Date.now() - started >= 1700, 'the wait must run to the deadline'); + assert.equal(result.ok, false); + assert.equal(result.error, 'not sent'); +}); + +test('a descriptor that vanishes and reappears idle: the wait resumes and the step is written', async () => { + const uuid = 'sess-every-reappear-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: (n, d) => quickTurn(session)(n, d) }); + session.desc.status = 'busy'; + session.desc.statusUpdatedAt = Date.now(); + const started = Date.now(); + const original = session.ctx.getCliStatus; + setTimeout(() => { session.ctx.getCliStatus = () => undefined; }, 200); + setTimeout(() => { + session.desc.status = 'idle'; session.desc.statusUpdatedAt = Date.now(); + session.ctx.getCliStatus = original; + }, 700); + + const result = await runChain([{ command: 'first step' }], session, uuid, 5000); + + assert.equal(result.ok, true); + assert.ok(session.written[0].at - started >= 650, 'written before the descriptor reappeared idle'); +}); + +test('readiness: a settle that completes after the deadline is a timeout, never ready', async (t) => { + fakeClock(t); + const state = { status: 'idle', statusUpdatedAt: 1_000_000 }; + const r = await settleRun(t, waitForCliIdleAfter('sid', stateCtx(state), -Infinity, 1_000_000 + 290, 300)); + assert.equal(r.ready, false); + assert.equal(r.timedOut, true); +}); + +test('readiness: a deadline already passed is a timeout even for an idle descriptor with no settle', async (t) => { + fakeClock(t); + const state = { status: 'idle', statusUpdatedAt: 1_000_000 }; + const r = await settleRun(t, waitForCliIdleAfter('sid', stateCtx(state), -Infinity, 1_000_000, 0)); + assert.equal(r.ready, false); + assert.equal(r.timedOut, true); +}); + +test('a step whose deadline has passed is not written, even with no descriptor to wait for', async () => { + const uuid = 'sess-every-expired-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), withDescriptor: false, onEnter: () => {} }); + session.ctx.getComposerState = () => { + const t = Date.now(); + while (Date.now() - t < 5) { /* let the 1 ms step budget lapse */ } + return { pending: 0, lastInputAt: 0 }; + }; + const tmp = mkTmp(); + process.env.SWITCHBOARD_TRIGGERS_DIR = tmp; + const watcher = start(session.ctx); + try { + fs.writeFileSync(path.join(tmp, uuid + '.json'), + JSON.stringify({ sessionId: uuid, wait: 'none', chain: [{ command: 'first step', timeout_ms: 1 }], timeout_ms: 20000 }), 'utf8'); + const resultPath = path.join(tmp, 'processed', uuid + '.result.json'); + const deadline = Date.now() + 10000; + while (!fs.existsSync(resultPath)) { + if (Date.now() > deadline) throw new Error('no result file'); + await new Promise((r) => setTimeout(r, 20)); + } + await new Promise((r) => setTimeout(r, 20)); + const result = JSON.parse(fs.readFileSync(resultPath, 'utf8')); + assert.deepEqual(session.written, []); + assert.equal(result.ok, false); + assert.equal(result.error, 'not sent'); + } finally { + watcher.close(); + delete process.env.SWITCHBOARD_TRIGGERS_DIR; + fs.rmSync(tmp, { recursive: true, force: true }); + } +}); + +test('post-compact readiness is anchored on the compact\'s own Enter, not on when the step began', async () => { + process.env.SWITCHBOARD_SUBMIT_ENTER_DELAY_MS = '250'; + try { + const uuid = 'sess-every-anchor-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: () => {} }); + const realWrite = session.ctx.getPtyForSession(uuid).ptyProcess.write; + session.ctx.getPtyForSession(uuid).ptyProcess.write = function (data) { + realWrite.call(this, data); + if (data === '/compact') { + setTimeout(() => { session.desc.status = 'idle'; session.desc.statusUpdatedAt = Date.now(); }, 60); + } + }; + + const result = await runChain([{ command: '/compact' }, { command: 'second step' }], session, uuid, 3500); + + assert.ok(!session.written.some((w) => w.data === 'second step'), 'an idle older than the compact Enter must not release the next step'); + assert.equal(result.ok, false); + assert.equal(result.error, 'chain timeout'); + } finally { + process.env.SWITCHBOARD_SUBMIT_ENTER_DELAY_MS = '1'; + } +}); diff --git a/trigger-watcher.js b/trigger-watcher.js index 02a93fe8..123a09c6 100644 --- a/trigger-watcher.js +++ b/trigger-watcher.js @@ -90,6 +90,7 @@ const ERROR_NOT_SENT = 'not sent'; const ERROR_CHAIN_TIMEOUT = 'chain timeout'; const ERROR_UNCONFIRMED = 'step not confirmed'; const REASON_DIALOG_OPEN = 'the CLI reports a dialog open (waiting); nothing was written into it'; +const REASON_DEADLINE_BEFORE_WRITE = 'the step deadline passed before it could be written; nothing was written'; const REASON_CLI_BUSY = 'the CLI still reported a turn running (busy) at the deadline; nothing was written'; const REASON_CLI_NOT_IDLE = 'the CLI never reported idle before the deadline; nothing was written'; @@ -376,24 +377,14 @@ function cliForbidsRecoveryEnter(ctx, sessionId) { return !!s && (s.status === 'waiting' || s.status === 'busy'); } -/** - * Wait until the CLI's own descriptor reports "idle" with a statusUpdatedAt - * later than `afterMs`, held for `settleMs`, bounded by `deadlineMs`. - * - * Returns { ready, available, timedOut, sessionExited, waited_ms, lastStatus, - * waitingSeen }. `available: false` means no descriptor could be read (at the - * start or later): the caller keeps its pre-descriptor behaviour. `lastStatus` - * is the descriptor's status at the last sample; `waitingSeen` is true when a - * dialog (`waiting`) was sampled within the last `settleMs` before the end. - * - * see .ai/contexts/trigger-watcher.md, "Readiness before every step" - */ +// see .ai/contexts/trigger-watcher.md, "Readiness before every step" (return shape, descriptor loss, deadline) function waitForCliIdleAfter(sessionId, ctx, afterMs, deadlineMs, settleMs = 0) { const start = Date.now(); let idleSince = null; let idleStamp = null; let lastStatus = null; let lastWaitingAt = null; + let everRead = false; return pollLoop((resolve, scheduleNext) => { const now = Date.now(); const waited_ms = now - start; @@ -402,21 +393,28 @@ function waitForCliIdleAfter(sessionId, ctx, afterMs, deadlineMs, settleMs = 0) return resolve({ ready: false, available: true, timedOut: false, sessionExited: true, waited_ms, lastStatus, waitingSeen }); } const s = readCliStatus(ctx, sessionId); - if (!s) { + if (!s && !everRead) { return resolve({ ready: false, available: false, timedOut: false, sessionExited: false, waited_ms, lastStatus, waitingSeen }); } - lastStatus = s.status; - if (s.status === 'waiting') lastWaitingAt = now; - if (s.status === 'idle' && s.statusUpdatedAt > afterMs) { - if (idleSince === null || idleStamp !== s.statusUpdatedAt) { - idleSince = now; - idleStamp = s.statusUpdatedAt; - } - if (now - idleSince >= settleMs) { - return resolve({ ready: true, available: true, timedOut: false, sessionExited: false, waited_ms, lastStatus, waitingSeen }); - } - } else { + let idleHeld = false; + if (!s) { idleSince = null; + } else { + everRead = true; + lastStatus = s.status; + if (s.status === 'waiting') lastWaitingAt = now; + if (s.status === 'idle' && s.statusUpdatedAt > afterMs) { + if (idleSince === null || idleStamp !== s.statusUpdatedAt) { + idleSince = now; + idleStamp = s.statusUpdatedAt; + } + idleHeld = now - idleSince >= settleMs; + } else { + idleSince = null; + } + } + if (idleHeld && now < deadlineMs) { + return resolve({ ready: true, available: true, timedOut: false, sessionExited: false, waited_ms, lastStatus, waitingSeen }); } if (now >= deadlineMs) { return resolve({ ready: false, available: true, timedOut: true, sessionExited: false, waited_ms, lastStatus, waitingSeen: lastWaitingAt !== null && now - lastWaitingAt <= settleMs }); @@ -1293,7 +1291,7 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR return; } if (!ready.available) { - ctx.log.info(`[trigger-watcher] CLI descriptor vanished for ${sessionId}, readiness wait ended early before chain step ${i}`); + ctx.log.info(`[trigger-watcher] No usable CLI descriptor for ${sessionId} at the start of the readiness wait before chain step ${i}`); } if (ready.timedOut) { const dialog = ready.waitingSeen || ready.lastStatus === 'waiting'; @@ -1315,6 +1313,23 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR } } + if (Date.now() >= stepDeadline) { + ctx.log.warn(`[trigger-watcher] Step deadline passed before chain step ${i} could be written:`, sessionId); + steps.push({ + idx: i, command: step.command, sent_at: stepSentAt, waited_ms: polite.waited_ms + readyWaitedMs, + submit_retries: 0, submitted: SUBMITTED_NO, + }); + await writeResult({ + ok: false, + submitted: weakestSubmitted(chainSubmitted, SUBMITTED_NO), + error: (i === 0) ? ERROR_NOT_SENT : ERROR_CHAIN_TIMEOUT, + reason: REASON_DEADLINE_BEFORE_WRITE, + partial: i > 0, steps_completed: i, sessionId, sent_at: step0SentAt, steps, + total_waited_ms: totalWaitedMs, + }); + return; + } + // Submit the step, then look for activity on the session. // The verify poll IS this step's Phase 1 — for non-final steps we proceed // straight to the busy-FALL wait, never re-observing busy. From 34786f8a0cbcba3560d733c5417b1d2d016fef5e Mon Sep 17 00:00:00 2001 From: Jean-Baptiste Date: Fri, 2 Oct 2026 17:22:15 +0200 Subject: [PATCH 4/4] (triggers): let the readiness wait own the descriptor start decision (#407, #360) A separate precheck read could succeed and the wait's own first read then fail, which sent the step down the no-descriptor path and wrote it without any idle confirmation. The precheck is gone: once any read succeeded, a later failure is "not idle" and the wait goes on to the deadline. Refs #360 Refs #407 --- .ai/contexts/trigger-watcher.md | 2 +- CHANGELOG.md | 2 +- docs/automation.md | 2 +- test/trigger-every-step-readiness.test.js | 17 +++++++++++++++++ trigger-watcher.js | 4 +--- 5 files changed, 21 insertions(+), 6 deletions(-) diff --git a/.ai/contexts/trigger-watcher.md b/.ai/contexts/trigger-watcher.md index badffb5a..388e7471 100644 --- a/.ai/contexts/trigger-watcher.md +++ b/.ai/contexts/trigger-watcher.md @@ -926,7 +926,7 @@ state was the cause. typed into that composer. The step's text may be sitting there. The recovery Enter is also withheld when input of the user's own is pending in the composer (`waitForComposerFree`), which stops the chain the same way. -- **No usable descriptor at the START of the wait** (`getCliStatus` absent, +- **No usable descriptor at the FIRST read of the wait** (the wait owns this decision: there is no separate precheck, so a descriptor read once and lost at the next sample is "not idle", never the legacy path) (`getCliStatus` absent, `undefined`, or a `statusUpdatedAt` that is not an integer): no wait, today's behaviour (`available: false`). A descriptor lost AFTER it was read (the CLI rewriting its file, a failed pid probe, a momentary bad timestamp) is not the diff --git a/CHANGELOG.md b/CHANGELOG.md index 275cf499..de3fce6b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,7 +10,7 @@ What changes for you in each release of Switchboard. How to write an entry: [doc ### Changed - After three failed refreshes of a remote host in a row, a row that would have attached opens its transcript and says why in its tooltip, instead of failing when clicked. Stop is never disabled: it runs its own ssh. (#218) ### Fixed -- A step of a trigger chain, the first one included, is no longer typed while the CLI reads busy or waiting on a dialog: it waits for the CLI to be at its prompt, up to the step's deadline, then fails cleanly with a reason instead of being written; a step whose Enter did not start a turn is retried once, or stops the chain when that retry is withheld because the CLI is busy or waiting on a dialog, or you have typed input pending, and is reported as "not confirmed submitted" instead of "sent". Single triggers are not covered. (#407, #360) +- A step of a trigger chain, the first one included, is no longer typed while the CLI reads busy or waiting on a dialog: it waits for the CLI to be at its prompt, up to the step's deadline, then fails cleanly with a reason instead of being written; a step whose Enter did not start a turn is retried once, or stops the chain when that retry is withheld because the CLI is busy or waiting on a dialog, or you have typed input pending, and is reported as "not confirmed submitted" instead of "sent". Without a readable CLI descriptor a step is still written as before, but no longer once its own deadline has passed. Single triggers are not covered. (#407, #360) - Stopping a terminal twice in quick succession, or resizing it while it is being stopped, no longer closes the Windows pseudo console twice, which could kill the whole app with no error. (#405) - A sandboxed session, or a sandboxed schedule, whose Additional Directories include a `.claude` or `.git` directory, or a path inside one, is now refused instead of binding it read-write over its read-only protection; add the project directory instead. A session started in a `.claude` or `.git` directory is refused too, except below `.claude/worktrees`, and Additional Directories naming your home directory or a parent of it are refused however the path is written. A relative `add-dirs` entry in a schedule is taken from the schedule's directory. (#385) - A session that has exited no longer keeps a busy dot in the sidebar, and the status bar's running count drops as soon as the session ends instead of waiting for the next refresh. (#375) diff --git a/docs/automation.md b/docs/automation.md index 1eeb0285..74e3ea1b 100644 --- a/docs/automation.md +++ b/docs/automation.md @@ -446,7 +446,7 @@ The two reserved values mean opposite things: `partial: false` for a `chain`. A session reports itself busy for as long as any subagent runs, so `idle` is often unreachable; `not sent` there tells the caller the payload never left. -- A chain step is held until the CLI's descriptor reads `idle`, up to the step's deadline. If it still reads `busy` or `waiting` (or any status other than `idle`) then, the step is not written: `not sent` for the first step, `chain timeout` for a later one, with the cause in `reason`. A session with delegated agents running keeps the parent descriptor `busy`, so such a chain fails cleanly instead of typing into a busy composer. Without a readable descriptor nothing is waited for. +- A chain step is held until the CLI's descriptor reads `idle`, up to the step's deadline. If it still reads `busy` or `waiting` (or any status other than `idle`) then, the step is not written: `not sent` for the first step, `chain timeout` for a later one, with the cause in `reason`. A session with delegated agents running keeps the parent descriptor `busy`, so such a chain fails cleanly instead of typing into a busy composer. Without a readable descriptor at the first read nothing is waited for, but a step is never written once its own deadline has passed (it then fails `not sent` or `chain timeout`). - A session that exits during that initial wait reports `submitted: "no"` and a `reason` saying nothing was written (`partial: false` on a chain). diff --git a/test/trigger-every-step-readiness.test.js b/test/trigger-every-step-readiness.test.js index 94f9f2d5..4a3a6ffa 100644 --- a/test/trigger-every-step-readiness.test.js +++ b/test/trigger-every-step-readiness.test.js @@ -402,3 +402,20 @@ test('post-compact readiness is anchored on the compact\'s own Enter, not on whe process.env.SWITCHBOARD_SUBMIT_ENTER_DELAY_MS = '1'; } }); + +test('the only readable sample is the first one, then the descriptor is unreadable: the wait owns the start decision, nothing is written', async () => { + const uuid = 'sess-every-first-read-' + Date.now(); + const session = chainSession(uuid, { log: recordingLog(), onEnter: () => {} }); + let reads = 0; + session.ctx.getCliStatus = () => { + reads += 1; + return reads === 1 ? { status: 'busy', statusUpdatedAt: Date.now() } : undefined; + }; + + const result = await runChain([{ command: 'first step' }], session, uuid, 1500); + await new Promise((r) => setTimeout(r, 300)); + + assert.deepEqual(session.written, []); + assert.equal(result.ok, false); + assert.equal(result.error, 'not sent'); +}); diff --git a/trigger-watcher.js b/trigger-watcher.js index 123a09c6..0e021d99 100644 --- a/trigger-watcher.js +++ b/trigger-watcher.js @@ -1279,9 +1279,7 @@ async function processTriggerFile(name, ctx, triggersDir, processedDir, onEntryR } let readyWaitedMs = 0; - if (!readCliStatus(ctx, sessionId)) { - ctx.log.info(`[trigger-watcher] No usable CLI descriptor for ${sessionId}, readiness wait skipped before chain step ${i}`); - } else { + { const ready = await waitForCliIdleAfter(sessionId, ctx, readyAfterMs === null ? -Infinity : readyAfterMs, stepDeadline, getBusyFallSettleMs()); readyWaitedMs = ready.waited_ms; totalWaitedMs += readyWaitedMs;