From 33d24cd6a234b6ebb936d6babb0b7060d0374585 Mon Sep 17 00:00:00 2001 From: kjgbot Date: Sat, 5 Sep 2026 18:01:39 +0200 Subject: [PATCH 1/3] fix(cli): a running run is not a protocol error `flows run` intermittently failed a healthy run with: FAILED [protocol_error] relayflowd could not complete the run request: relayflowd returned status parked without a classifiable completion Reproduced locally: 1 failure in 12 runs, and 1 in 4 on another pass. Instrumenting the fall-through branch named the state exactly: PROBE_D unclassifiable inspection={"status":"running","needsHuman":false} `classifyOutcome` loops while the run is parked, asking `inspectOutOfBandStep` what to do. That helper reports a step only when a non-deterministic step is `needs_human`, `runnable` or `running`. When a worker has just completed the step the run parked on, there is a window where none of those hold while the snapshot's own status is still `running` -- the daemon has not yet finished driving what follows. Every branch missed that window, so the loop broke with `status === 'parked'` and no `parkedStep`, and the tail reported an unclassifiable completion. The run was healthy and about to succeed. A run that reports `running` is progressing, so it is now polled rather than abandoned: bounded at 40 x 50ms = 2s, which is far longer than the sub-second window observed and short enough that a genuinely stuck run still reports instead of hanging. The unchanged `break` below keeps it failing closed if it never resolves. Evidence: * before: 1 fail / 12, then 1 fail / 4 * after: 0 fail / 40 * full SDK suite: 31 files passed, 649 tests passed, 3 skipped * typecheck clean This is #179's `live-kernel > follows a live worker dispatch` flake, and also explains the earlier `cli-hn-monitor` failure shape: both are the CLI treating a transient, healthy state as terminal. Reproduction environment, since it is not obvious: surface must be built with `bun install --frozen-lockfile --ignore-scripts && bun run build` BEFORE the sdk (npm there fails -- surface has no package-lock.json), then `npm ci --prefix sdk --ignore-scripts`, a release `relayflowd` for RELAYFLOWD_BIN, and RELAYFLOWS_ALLOW_ANALYZER_SKIP=1. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01FtQSAcGDta5VH9xiZFT4sR Session-Id: c228933d-4f94-4d83-9a9a-daf3c83b94f1 --- sdk/src/cli/run.ts | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) diff --git a/sdk/src/cli/run.ts b/sdk/src/cli/run.ts index a3fb1519a..0c3c246fa 100644 --- a/sdk/src/cli/run.ts +++ b/sdk/src/cli/run.ts @@ -178,6 +178,7 @@ async function classifyOutcome( let current = outcome; let parkedStep: ParkedStep | undefined; let needsHuman = false; + let unclassifiedPolls = 0; while (current.status === 'parked') { const inspection = await inspectOutOfBandStep(client, current.run_id); if (inspection?.parkedStep !== undefined) { @@ -194,6 +195,28 @@ async function classifyOutcome( current = await client.runResume(current.run_id); continue; } + // The run is still RUNNING but no step is identifiable at this instant. + // + // That is a healthy state, not a protocol error. It happens when a worker + // has just completed the step this run parked on and the daemon has not yet + // finished driving what follows: nothing is `needs_human`, `runnable` or + // `running` for a moment, while the snapshot's own status is `running`. + // Breaking here left `status === 'parked'` with no `parkedStep`, so the + // tail reported `parked without a classifiable completion` -- a spurious + // failure on a run that was about to succeed (#179). Reproduced 1 in 4-15 + // locally; the probe that caught it printed + // `inspection={"status":"running","needsHuman":false}`. + // + // So poll it, bounded. Resuming immediately would spin, since the daemon + // needs a moment to advance. + if (inspection?.status === 'running' && unclassifiedPolls < MAX_UNCLASSIFIED_POLLS) { + unclassifiedPolls += 1; + await new Promise((resolve) => setTimeout(resolve, UNCLASSIFIED_POLL_MS)); + current = await client.runResume(current.run_id); + continue; + } + // Fail closed rather than loop forever: if it never resolves, the original + // error below still fires and says so. break; } @@ -253,6 +276,12 @@ interface RunningStep extends ParkedStep { leaseDeadlineMs: number; } +/// Bound on re-polling a run that reports `running` with no identifiable step. +/// 40 x 50ms = 2s, far longer than the sub-second window observed in #179, and +/// short enough that a genuinely stuck run still reports rather than hangs. +const MAX_UNCLASSIFIED_POLLS = 40; +const UNCLASSIFIED_POLL_MS = 50; + async function inspectOutOfBandStep( client: JournalClient, runId: string, From 598673d968af02cb47c58f1de07364901761e73a Mon Sep 17 00:00:00 2001 From: kjgbot Date: Sat, 5 Sep 2026 18:14:33 +0200 Subject: [PATCH 2/3] fix(cli): make the new poll cancel-aware, as the rest of the file is The maintainability lens caught a regression I introduced: the poll used a bare `setTimeout`, while every other wait in this file goes through the cancel-aware `delay(ms, signal)`. A Ctrl-C or lifecycle abort during the 2-second window would have been ignored and the CLI would have kept polling the daemon after being told to stop. Now `throwIfCanceled(options.signal, ...)` then `delay(..., options.signal)`, matching `waitForRunningStep` directly above it. Also stated the contract the loop leans on -- `run.resume` is idempotent on a run already progressing, returning current state rather than re-dispatching -- because up to 41 resumes in 2 seconds is a load-bearing assumption that was written nowhere. Style: the constants used `///`, a Rust doc comment, in a file that uses `//`. Re-verified after the change: 20/20 on the previously-flaking test, and the full SDK suite still 31 files / 649 tests passed, 3 skipped. Still outstanding from that review, and NOT done here: the new branch has no unit test. `classifyOutcome` is unexported with no test file, so pinning it means making it injectable or exported first -- a design change that deserves its own pass rather than a rushed one. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01FtQSAcGDta5VH9xiZFT4sR Session-Id: c228933d-4f94-4d83-9a9a-daf3c83b94f1 --- sdk/src/cli/run.ts | 16 ++++++++++++---- 1 file changed, 12 insertions(+), 4 deletions(-) diff --git a/sdk/src/cli/run.ts b/sdk/src/cli/run.ts index 0c3c246fa..32c9e5f6f 100644 --- a/sdk/src/cli/run.ts +++ b/sdk/src/cli/run.ts @@ -211,7 +211,15 @@ async function classifyOutcome( // needs a moment to advance. if (inspection?.status === 'running' && unclassifiedPolls < MAX_UNCLASSIFIED_POLLS) { unclassifiedPolls += 1; - await new Promise((resolve) => setTimeout(resolve, UNCLASSIFIED_POLL_MS)); + // `delay(ms, signal)`, not a bare setTimeout: every other wait in this + // file is cancel-aware, and an uncancellable one here would keep polling + // the daemon for up to 2s after a Ctrl-C or a lifecycle abort. + throwIfCanceled(options.signal, current.run_id); + await delay(UNCLASSIFIED_POLL_MS, options.signal); + // Redundant resumes are safe: `run.resume` is idempotent on a run that + // is already progressing -- it returns the current state rather than + // re-dispatching. This loop leans on that up to MAX_UNCLASSIFIED_POLLS + // times while the daemon is mid-transition. current = await client.runResume(current.run_id); continue; } @@ -276,9 +284,9 @@ interface RunningStep extends ParkedStep { leaseDeadlineMs: number; } -/// Bound on re-polling a run that reports `running` with no identifiable step. -/// 40 x 50ms = 2s, far longer than the sub-second window observed in #179, and -/// short enough that a genuinely stuck run still reports rather than hangs. +// Bound on re-polling a run that reports `running` with no identifiable step. +// 40 x 50ms = 2s, far longer than the sub-second window observed in #179, and +// short enough that a genuinely stuck run still reports rather than hangs. const MAX_UNCLASSIFIED_POLLS = 40; const UNCLASSIFIED_POLL_MS = 50; From ae04d2a5e8141157647553e9865aa5ce5ff9ff65 Mon Sep 17 00:00:00 2001 From: kjgbot Date: Sat, 5 Sep 2026 18:17:26 +0200 Subject: [PATCH 3/3] test(sdk): pin the running-run branch the review asked for The maintainability lens wanted the new branch tested, and was right that without one a refactor of `inspectOutOfBandStep` -- or a tightening of the outer `while (current.status === 'parked')` guard -- would kill it silently and regress #179. `classifyOutcome` is now exported for tests. The branch only occurs in a sub-second window against a live daemon, so pinning it needs a stubbed client rather than a real run: the integration test that found the bug reproduced it roughly 1 time in 12, which is not a gate. Two cases, and they state the rule together: * a run reporting `running` with no identifiable step is waited out and then classified normally -- no `protocol_error`, exit 3, the parked step identified * a run that NEVER becomes classifiable still reports rather than polling forever, which is what keeping the original `break` buys Mutation: disabling the branch (`if (false && ...)`) fails the first test with the exact production string -- expected [ 'protocol_error' ] to not include 'protocol_error' "relayflowd returned status parked without a classifiable completion" -- while the bound test still passes. sha256 8124009e -> e80ee063 -> restored 8124009e, no `if (false &&` left in the tree. Full SDK suite at this head: 32 files passed, 651 tests passed, 3 skipped; typecheck clean. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01FtQSAcGDta5VH9xiZFT4sR Session-Id: c228933d-4f94-4d83-9a9a-daf3c83b94f1 --- sdk/src/cli/run.ts | 6 +- sdk/tests/classify-outcome.test.ts | 88 ++++++++++++++++++++++++++++++ 2 files changed, 93 insertions(+), 1 deletion(-) create mode 100644 sdk/tests/classify-outcome.test.ts diff --git a/sdk/src/cli/run.ts b/sdk/src/cli/run.ts index 32c9e5f6f..d78c3ddb7 100644 --- a/sdk/src/cli/run.ts +++ b/sdk/src/cli/run.ts @@ -167,7 +167,11 @@ export async function connect( } } -async function classifyOutcome( +/// Exported for tests. The `running`-with-no-identifiable-step branch (#179) +/// only occurs in a sub-second window against a live daemon, so pinning it +/// needs a stubbed client rather than a real run -- the integration test that +/// found it reproduced the bug roughly 1 time in 12. +export async function classifyOutcome( client: JournalClient, command: RunCommand, outcome: RunOutcome, diff --git a/sdk/tests/classify-outcome.test.ts b/sdk/tests/classify-outcome.test.ts new file mode 100644 index 000000000..95a5d9be2 --- /dev/null +++ b/sdk/tests/classify-outcome.test.ts @@ -0,0 +1,88 @@ +import { describe, expect, it } from 'vitest'; + +import { classifyOutcome } from '../src/cli/run.js'; +import type { JournalClient } from '../src/journal-client.js'; +import type { RunGetResult, RunOutcome } from '../src/protocol.js'; + +const RUN_ID = 'run-179'; + +const parked: RunOutcome = { + run_id: RUN_ID, + status: 'parked', + completion_reason: null, + completed_steps: 1, +}; + +const base = { + command: 'run' as const, + ok: true, + specPath: 'spec.yaml', + diagnostics: [], +}; + +/// A client that answers `run.get` from a scripted queue and always reports the +/// run as still parked on `run.resume` -- which is what the daemon does while a +/// worker completion is being driven. +function clientReturning(snapshots: RunGetResult[]): { client: JournalClient; resumes: () => number } { + let index = 0; + let resumes = 0; + const fake = { + runGet: async (): Promise => + snapshots[Math.min(index++, snapshots.length - 1)]!, + runResume: async (): Promise => { + resumes += 1; + return parked; + }, + }; + return { client: fake as unknown as JournalClient, resumes: () => resumes }; +} + +const runningNoStep: RunGetResult = { + run_id: RUN_ID, + status: 'running', + steps: {}, + budget: { tokens_in: 0, tokens_out: 0, dollars: '0' }, +}; + +const parkedOnLlm: RunGetResult = { + run_id: RUN_ID, + status: 'parked', + steps: { answer: { type: 'llm', state: 'runnable' } as never }, + budget: { tokens_in: 0, tokens_out: 0, dollars: '0' }, +}; + +describe('classifyOutcome', () => { + /// #179. A run that reports `running` with no identifiable step is mid-stride, + /// not broken: a worker has just completed the step the run parked on and the + /// daemon has not yet driven what follows. Treating that instant as terminal + /// failed healthy runs with `parked without a classifiable completion`. + it('waits out a running run with no identifiable step instead of failing it', async () => { + const { client, resumes } = clientReturning([ + runningNoStep, + runningNoStep, + runningNoStep, + parkedOnLlm, + ]); + + const execution = await classifyOutcome(client, 'run', parked, base as never, '/tmp/sock', {}); + + expect( + execution.report.diagnostics.map((d) => d.kind), + JSON.stringify(execution.report.diagnostics), + ).not.toContain('protocol_error'); + expect(execution.exitCode).toBe(3); + expect(execution.report.parkedStep?.id).toBe('answer'); + expect(resumes()).toBeGreaterThan(0); + }); + + /// The bound must hold: a run that NEVER resolves still reports rather than + /// polling forever. Fail closed is the point of keeping the original break. + it('gives up and reports when a running run never becomes classifiable', async () => { + const { client } = clientReturning([runningNoStep]); + + const execution = await classifyOutcome(client, 'run', parked, base as never, '/tmp/sock', {}); + + expect(execution.exitCode).not.toBe(0); + expect(execution.report.parkedStep).toBeUndefined(); + }); +});