From a5c7f458bcf1ea752ca3a57826c8adb072241997 Mon Sep 17 00:00:00 2001 From: Relayflow Date: Sun, 20 Sep 2026 17:33:17 +0000 Subject: [PATCH 1/4] fix: report every failed attempt in retries_exhausted, not only the last MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A step refused by a pre-receive hook, then retried into a different error, reported only the retry's error. "The push was rejected" and "nothing was staged" point at different bugs, and the first one was invisible without reading the journal by hand. The kernel already appends a step.completed per attempt; the reader kept one candidate and overwrote it. It now accumulates a per-step history, compares the attempts' unbounded journal records rather than their display excerpts, and says so explicitly when they differ — a retry that fails differently usually means the earlier attempt had a side effect. The same rewrite covers agent and llm steps, which the deterministic-only reader returned nothing for, reading the daemon's bounded render when the kernel nulled their output. Additive throughout: no new diagnostic kind, the scalar fields still describe the terminal attempt, and a single-attempt failure renders unchanged. Co-Authored-By: Claude --- docs/CLOUD.md | 11 + docs/SURFACE.md | 43 +- kernel/relayflowd-core/src/machine/tests.rs | 177 +++++++++ packages/sdk/src/authored-node-runner.ts | 76 +++- packages/sdk/src/authored-worker-step.ts | 2 + packages/sdk/src/cli/step-evidence.ts | 273 +++++++++++++ packages/sdk/src/cli/step-failure.ts | 147 +++---- packages/sdk/src/failure-kinds.ts | 61 +++ packages/sdk/tests/cloud-read.test.ts | 28 ++ .../sdk/tests/retried-step-failure.test.ts | 77 ++++ .../sdk/tests/step-attempt-history.test.ts | 369 ++++++++++++++++++ 11 files changed, 1157 insertions(+), 107 deletions(-) create mode 100644 packages/sdk/src/cli/step-evidence.ts create mode 100644 packages/sdk/tests/retried-step-failure.test.ts create mode 100644 packages/sdk/tests/step-attempt-history.test.ts diff --git a/docs/CLOUD.md b/docs/CLOUD.md index 575405efb..38c3001f1 100644 --- a/docs/CLOUD.md +++ b/docs/CLOUD.md @@ -186,6 +186,17 @@ frame this vocabulary has no opinion about is reported as one line naming its type and size, and a line that is not JSON is printed as written, so `--raw` is never the only way to find out that something ran. +A retried step that failed differently each time shows every attempt's error +here, because the runner log is the `flows` process's own captured output and +the step-failure diagnostic it writes lists every failed attempt (see +[Reading a failed step](SURFACE.md#reading-a-failed-step)). Nothing is elided +on the way out: the runner log is printed line for line. The limit is that the +log is a *recording* — there is no journal-export endpoint, so `flows logs` +can only show what the `flows` binary that ran the workflow printed at the +time. A run executed by a build predating this diagnostic carries only the +terminal attempt in its log, and no later reader can recover the earlier ones +from Cloud. + `flows status --cloud ` is the local `flows status` view, sourced from the run record and the step list instead of a journal: the `RUN` header with status, completion reason and summed spend, a `steps N` count, and one diff --git a/docs/SURFACE.md b/docs/SURFACE.md index 4620b56ea..d9101064f 100644 --- a/docs/SURFACE.md +++ b/docs/SURFACE.md @@ -702,6 +702,9 @@ uses the opening shown here; an authored child failure opens with ```text FAILED [step_failed] Run "" failed with completionReason: step_failed. Step "" () completionReason: attempt=/ exit=. +Attempts: failed; + attempt 1: exit= — stderr: + attempt 2: exit= — stderr: Detail: Stdout (last 1,024 bytes): @@ -715,9 +718,43 @@ Journal: /runs/.sqlite3 Each clause is present only when the journal holds the fact behind it; nothing is defaulted. The same fields appear as named keys on the `--json` diagnostic (`stepId`, `stepType`, `completionReason`, `attempt`, `maxIterations`, -`exitCode`, `stdoutTail`, `stderrTail`, `detail`, `transcriptPath`, `hint`, -`journalPath`), so the rendered line and the machine-readable record carry the -same facts rather than the message being the only copy. +`exitCode`, `stdoutTail`, `stderrTail`, `detail`, `transcriptPath`, `attempts`, +`attemptEvidence`, `hint`, `journalPath`), so the rendered line and the +machine-readable record carry the same facts rather than the message being the +only copy. + +The scalar clauses always describe the **terminal** attempt. `Attempts:` is +additive and appears only when the journal held more than one failed attempt of +that step, so a step that failed once renders exactly as it did before. Every +failed attempt is listed, oldest first, from its own `step.completed` entry — +the kernel appends one per attempt, so a retry that failed differently from the +first attempt is a journaled fact rather than something the last attempt's +output has to be read for. Each entry carries the attempt's reason, its exit +code when it had one, and up to 256 bytes of whichever of `detail`, `stderr` +and `stdout` that attempt actually recorded; `(excerpt truncated)` marks an +account that was cut, and an attempt that recorded nothing says so rather than +printing empty fields. Attempt excerpts are redacted before they are bounded. +The corresponding `attempts` entries in `--json` use the keys `attempt`, +`completionReason`, `disposition`, `exitCode`, `stdoutTail`, `stderrTail`, +`detail` and `truncated`. + +`attemptEvidence` says whether the attempts failed for the same reason, and is +one of: + +- `differs` — the journaled evidence is not the same across attempts. A retry + that fails differently usually means an earlier attempt already had a side + effect, so the message adds *An earlier attempt may have had side effects.* +- `unchanged` — every attempt recorded evidence and all of it agrees. +- `unknown` — at least one attempt journaled nothing about why it failed, or + its evidence reached the journal already truncated by the daemon, so whether + the causes differ cannot be decided. + +The comparison runs on the journal record before any display bound, and reads +the verification gate, verdict and detail as well as the exit codes and output +tails, so two attempts whose visible excerpts are identical are still reported +as differing when the records behind them are not. `verification_failed` on a +retry and `retries_exhausted` at the budget limit are the kernel's label for +the same fallback, so that pair alone is not counted as a changed cause. `attempt=/` is read from the journal, not from the spec: `n` is the `step.attempt.started` envelope's attempt number and `budget` is the diff --git a/kernel/relayflowd-core/src/machine/tests.rs b/kernel/relayflowd-core/src/machine/tests.rs index 6add8aa32..22d3ca2d0 100644 --- a/kernel/relayflowd-core/src/machine/tests.rs +++ b/kernel/relayflowd-core/src/machine/tests.rs @@ -691,3 +691,180 @@ fn deterministic_lease_rejects_invalid_and_foreign_fields() { ); } } + +/// Pin the journal contract the `retries_exhausted` diagnostic reads. +/// +/// A retried step appends one `step.completed` PER ATTEMPT, each carrying its +/// own attempt envelope and — for a deterministic step — its own preserved +/// `{exit_code, stdout_tail, stderr_tail}`. Without that, the first attempt's +/// error would not exist to report and the reader could only ever show the +/// last one. Nothing about retry policy is asserted or changed here. +/// +/// The two attempts below fail with the SAME exit code and DIFFERENT stderr, +/// which is the shape that matters: the kernel's own verification record is +/// byte-identical across them ("exit code was 1; output did not contain +/// \"hello\""), so a reader comparing only that record would call two +/// different failures the same failure. The distinguishing evidence lives in +/// the preserved output. +#[test] +fn each_failed_attempt_journals_its_own_output_beside_an_identical_verdict() { + let spec = retrying_spec(); + let mut step = spec.steps[0].clone(); + step.max_iterations = 2; + + let first_output = json!({ + "exit_code": 1, + "stdout_tail": "", + "stderr_tail": "remote: GitLab: You cannot push commits for 'factory@example.com'", + }); + let first = completion_actions( + "run", + &step, + 1, + 0, + AttemptResult::successful(first_output.clone(), "kernel"), + 1_000, + ); + let Action::Append(first_entry) = &first[0] else { + panic!("a failed attempt must append its own completion"); + }; + let first_payload: StepCompletedPayload = + serde_json::from_value(first_entry.payload.clone()).unwrap(); + assert_eq!(first_entry.attempt, Some(1)); + assert_eq!(first_payload.disposition, Disposition::Retry); + assert_eq!( + first_payload.completion_reason, + CompletionReason::VerificationFailed + ); + assert_eq!(first_payload.output, first_output); + + let second_output = json!({ + "exit_code": 1, + "stdout_tail": "", + "stderr_tail": "nothing staged inside the declared scope", + }); + let second = completion_actions( + "run", + &step, + 2, + 1, + AttemptResult::successful(second_output.clone(), "kernel"), + 2_000, + ); + let Action::Append(second_entry) = &second[0] else { + panic!("the terminal attempt must append its own completion"); + }; + let second_payload: StepCompletedPayload = + serde_json::from_value(second_entry.payload.clone()).unwrap(); + assert_eq!(second_entry.attempt, Some(2)); + assert_eq!(second_payload.disposition, Disposition::StepDone); + assert_eq!( + second_payload.completion_reason, + CompletionReason::RetriesExhausted + ); + assert_eq!(second_payload.output, second_output); + + // Both attempts survive, and only the output tells them apart. + assert_ne!(first_payload.output, second_payload.output); + assert_eq!(first_payload.verification, second_payload.verification); + let verification = first_payload.verification.expect("a failure names itself"); + assert_eq!(verification.gate, "exit_code+output_contains"); + assert_eq!(verification.verdict, crate::entry::VerificationVerdict::Fail); +} + +/// The label change at the budget limit is POLICY, not a different cause. +/// +/// Identical deterministic failures are labelled `verification_failed` while +/// an iteration remains and `retries_exhausted` once it does not, because +/// `completion_actions` picks the fallback reason from the branch it took. A +/// reader that compared the raw labels would report "the retry failed for a +/// different reason" on every ordinary repeated failure, so this pins that +/// the two labels can sit over byte-identical evidence. +#[test] +fn the_exhaustion_label_replaces_verification_failed_over_identical_evidence() { + let spec = retrying_spec(); + let mut step = spec.steps[0].clone(); + step.max_iterations = 2; + let output = json!({"exit_code": 1, "stdout_tail": "", "stderr_tail": "same failure"}); + + let mut payloads = Vec::new(); + for (attempt, semantic_executions, now_ms) in [(1, 0, 1_000), (2, 1, 2_000)] { + let actions = completion_actions( + "run", + &step, + attempt, + semantic_executions, + AttemptResult::successful(output.clone(), "kernel"), + now_ms, + ); + let Action::Append(entry) = &actions[0] else { + panic!("every attempt appends a completion"); + }; + assert_eq!(entry.attempt, Some(attempt)); + payloads.push( + serde_json::from_value::(entry.payload.clone()).unwrap(), + ); + } + + assert_eq!( + payloads[0].completion_reason, + CompletionReason::VerificationFailed + ); + assert_eq!( + payloads[1].completion_reason, + CompletionReason::RetriesExhausted + ); + assert_eq!(payloads[0].output, payloads[1].output); + assert_eq!(payloads[0].verification, payloads[1].verification); +} + +/// A worker-reported failure keeps its OWN label on both attempts. +/// +/// `failure_reason` is supplied, so neither fallback applies: the retry and +/// the terminal completion both read `worker_error`, and each carries the +/// worker's own detail. Only the `verification_failed` → `retries_exhausted` +/// pair is a policy-only transition; every other label difference across +/// attempts is a real difference in what the worker reported. +#[test] +fn a_worker_reported_reason_is_not_rewritten_by_the_retry_branch() { + let spec = retrying_spec(); + let mut step = spec.steps[0].clone(); + step.max_iterations = 2; + let result = |detail: &str| AttemptResult { + failure_reason: Some(CompletionReason::WorkerError), + failure_detail: Some(detail.to_owned()), + ..AttemptResult::successful(Value::Null, "kernel") + }; + + let retry = completion_actions("run", &step, 1, 0, result("push rejected"), 1_000); + let Action::Append(retry_entry) = &retry[0] else { + panic!("a worker failure appends a completion"); + }; + let retry_payload: StepCompletedPayload = + serde_json::from_value(retry_entry.payload.clone()).unwrap(); + assert_eq!(retry_payload.completion_reason, CompletionReason::WorkerError); + assert_eq!(retry_payload.disposition, Disposition::Retry); + assert_eq!( + retry_payload.verification.as_ref().map(|v| v.detail.as_str()), + Some("push rejected") + ); + + let terminal = completion_actions("run", &step, 2, 1, result("nothing staged"), 2_000); + let Action::Append(terminal_entry) = &terminal[0] else { + panic!("the terminal worker failure appends a completion"); + }; + let terminal_payload: StepCompletedPayload = + serde_json::from_value(terminal_entry.payload.clone()).unwrap(); + assert_eq!( + terminal_payload.completion_reason, + CompletionReason::WorkerError + ); + assert_eq!(terminal_payload.disposition, Disposition::StepDone); + assert_eq!( + terminal_payload + .verification + .as_ref() + .map(|v| v.detail.as_str()), + Some("nothing staged") + ); +} diff --git a/packages/sdk/src/authored-node-runner.ts b/packages/sdk/src/authored-node-runner.ts index 1dd97944a..4a8f27918 100644 --- a/packages/sdk/src/authored-node-runner.ts +++ b/packages/sdk/src/authored-node-runner.ts @@ -13,7 +13,7 @@ import { AuthoredFlowExecutionError, AuthoredHumanParked, type AuthoredFlowExecutionErrorCode, type AuthoredHumanWait, } from './authored-flow-error.js'; -import type { StepFailedDetails } from './failure-kinds.js'; +import type { AttemptEvidenceComparison, StepAttemptFailure, StepFailedDetails } from './failure-kinds.js'; import { HUMAN_WAIT_ID } from './authored-human.js'; import { assertAuthoredPromiseHooks } from './authored-runtime-capability.js'; @@ -183,26 +183,76 @@ function isHumanWaitFrame(value: unknown): value is AuthoredHumanWait { * evidence frame would replace the answer with a worse one. */ export function stepFailedFrame(value: unknown): StepFailedDetails | undefined { - if (typeof value !== 'object' || value === null || Array.isArray(value)) return undefined; - const frame = value as Record; - const text = (key: string): string | undefined => - typeof frame[key] === 'string' ? (frame[key] as string).slice(0, 8192) : undefined; - const count = (key: string): number | undefined => - typeof frame[key] === 'number' && Number.isSafeInteger(frame[key]) ? frame[key] as number : undefined; + const frame = frameRecord(value); + if (frame === undefined) return undefined; const details: StepFailedDetails = {}; for (const [key, parsed] of [ - ['stepId', text('stepId')], ['stepType', text('stepType')], - ['completionReason', text('completionReason')], ['attempt', count('attempt')], - ['maxIterations', count('maxIterations')], ['exitCode', count('exitCode')], - ['stdoutTail', text('stdoutTail')], ['stderrTail', text('stderrTail')], - ['detail', text('detail')], ['transcriptPath', text('transcriptPath')], - ['hint', text('hint')], ['journalPath', text('journalPath')], + ['stepId', frameText(frame, 'stepId')], ['stepType', frameText(frame, 'stepType')], + ['completionReason', frameText(frame, 'completionReason')], ['attempt', frameCount(frame, 'attempt')], + ['maxIterations', frameCount(frame, 'maxIterations')], ['exitCode', frameCount(frame, 'exitCode')], + ['stdoutTail', frameText(frame, 'stdoutTail')], ['stderrTail', frameText(frame, 'stderrTail')], + ['detail', frameText(frame, 'detail')], ['transcriptPath', frameText(frame, 'transcriptPath')], + ['attempts', attemptFrames(frame['attempts'])], + ['attemptEvidence', comparisonFrame(frame['attemptEvidence'])], + ['hint', frameText(frame, 'hint')], ['journalPath', frameText(frame, 'journalPath')], ] as const) { if (parsed !== undefined) (details as Record)[key] = parsed; } return Object.keys(details).length === 0 ? undefined : details; } +/** + * The attempt history, reduced element by element on the same terms as the + * frame that carries it. An element that is not an object contributes nothing + * rather than voiding the whole history: a report naming three of four + * attempts is still the first attempt's error, which is the fact the terminal + * scalars cannot supply. + */ +function attemptFrames(value: unknown): StepAttemptFailure[] | undefined { + if (!Array.isArray(value)) return undefined; + const attempts: StepAttemptFailure[] = []; + for (const element of value) { + const source = frameRecord(element); + if (source === undefined) continue; + const attempt: StepAttemptFailure = {}; + for (const [key, parsed] of [ + ['attempt', frameCount(source, 'attempt')], + ['completionReason', frameText(source, 'completionReason')], + ['disposition', frameText(source, 'disposition')], + ['exitCode', frameCount(source, 'exitCode')], + ['stdoutTail', frameText(source, 'stdoutTail')], + ['stderrTail', frameText(source, 'stderrTail')], + ['detail', frameText(source, 'detail')], + // Only a literal `true` claims truncation; anything else leaves the + // excerpt unlabelled rather than labelling a complete one as cut. + ['truncated', source['truncated'] === true ? true : undefined], + ] as const) { + if (parsed !== undefined) (attempt as Record)[key] = parsed; + } + if (Object.keys(attempt).length > 0) attempts.push(attempt); + } + return attempts.length === 0 ? undefined : attempts; +} + +/** An unrecognised verdict is dropped, and rendering then says `unknown`. */ +function comparisonFrame(value: unknown): AttemptEvidenceComparison | undefined { + return value === 'differs' || value === 'unchanged' || value === 'unknown' ? value : undefined; +} + +function frameRecord(value: unknown): Record | undefined { + return typeof value === 'object' && value !== null && !Array.isArray(value) + ? value as Record : undefined; +} + +function frameText(frame: Record, key: string): string | undefined { + return typeof frame[key] === 'string' ? (frame[key] as string).slice(0, 8192) : undefined; +} + +function frameCount(frame: Record, key: string): number | undefined { + return typeof frame[key] === 'number' && Number.isSafeInteger(frame[key]) + ? frame[key] as number : undefined; +} + /** The IPC frame is a claim, not a durable terminal fact or a sandbox boundary. */ export async function verifyAuthoredNodeResult( result: AuthoredFlowExecutionResult, metadata: AuthoredRootMetadata, diff --git a/packages/sdk/src/authored-worker-step.ts b/packages/sdk/src/authored-worker-step.ts index bd85fac07..3f21d9c71 100644 --- a/packages/sdk/src/authored-worker-step.ts +++ b/packages/sdk/src/authored-worker-step.ts @@ -265,6 +265,8 @@ function stepDetails( ...(found.stderrTail === undefined ? {} : { stderrTail: found.stderrTail }), ...(found.detail === undefined ? {} : { detail: found.detail }), ...(found.transcriptPath === undefined ? {} : { transcriptPath: found.transcriptPath }), + ...(found.attempts === undefined ? {} : { attempts: found.attempts }), + ...(found.attemptEvidence === undefined ? {} : { attemptEvidence: found.attemptEvidence }), ...(found.hint === undefined ? {} : { hint: found.hint }), ...(found.journalPath === undefined ? {} : { journalPath: found.journalPath }), }; diff --git a/packages/sdk/src/cli/step-evidence.ts b/packages/sdk/src/cli/step-evidence.ts new file mode 100644 index 000000000..8f5177eea --- /dev/null +++ b/packages/sdk/src/cli/step-evidence.ts @@ -0,0 +1,273 @@ +import { redact } from '../redact.js'; +import type { + AttemptEvidenceComparison, + StepAttemptFailure, + StepFailedDetails, +} from '../failure-kinds.js'; + +/** The terminal attempt's bound, unchanged: it is the primary account. */ +export const TAIL_BYTES = 1_024; + +/** Per-attempt history is context beside that account, not a second copy of it. */ +export const ATTEMPT_TAIL_BYTES = 256; + +/** + * What the daemon appends when it cut a render before journaling it + * (`worker_failure_detail`, relayflowd/src/engine/remote.rs). Evidence that + * arrived already truncated cannot establish that two attempts failed + * identically, however equal the surviving bytes are. + */ +const PRODUCER_TRUNCATED = /…\s*\((?:render bounded|[\d,]+ bytes truncated)\)$/u; + +/** + * The evidence fields a step failure reports, as the journal held them. + * + * Extraction and display bounds are separated deliberately. The terminal + * attempt renders at 1,024 bytes and each historical attempt at 256, but the + * COMPARISON that decides whether a retry failed differently runs on the + * unbounded record (`failureCause`): two different errors can share a 256-byte + * suffix, and calling those the same failure is the bug this reader exists to + * avoid. + */ +export interface SelectedEvidence { + exitCode?: number; + /** Present only when nonempty. */ + stdoutTail?: string; + /** Present whenever the journal carried one, including the empty string. */ + stderrTail?: string; + detail?: string; + transcriptPath?: string; +} + +/** + * Pull the process-shaped fields out of whichever field carried them. + * + * `verification.detail` is last because it is the daemon's own render rather + * than the worker's structured report — but for an agent step it is the only + * thing that survives, so it is parsed when it parses and kept verbatim when + * it does not. A truncated render (the daemon caps at 2,000 chars and appends + * a truncation note) will not parse; that falls through to the raw string, + * which is still the account of what went wrong. + * + * An agent or llm completion now also carries `trajectory_tail.transcript` + * (agent-transcript.ts) on every attempt. That object is not process-shaped, + * so it must not shadow the render that is: the first candidate that carries + * an exit code or a tail wins. The digest contributes what only it has — the + * failure excerpt the worker picked out of the provider's frames, and the + * path of the transcript file. + */ +export function selectEvidence(payload: Record): SelectedEvidence { + const detail = record(payload['verification'])?.['detail']; + const candidates = [ + record(payload['output']), + record(payload['trajectory_tail']), + typeof detail === 'string' ? parsed(detail) : undefined, + ].filter((candidate): candidate is Record => candidate !== undefined); + const structured = candidates.find(processShaped) ?? candidates[0]; + const exitCode = structured?.['exit_code']; + const stdout = structured?.['stdout_tail']; + const stderr = structured?.['stderr_tail']; + const structuredShape = structured !== undefined && processShaped(structured); + const transcript = record(record(payload['trajectory_tail'])?.['transcript']); + const failure = record(transcript?.['failure']); + const excerpt = failure?.['excerpt']; + const transcriptPath = record(transcript?.['file'])?.['path']; + // The excerpt is the worker's own pick of the failure; a `stderr` excerpt + // is the same bytes as `stderrTail`, so it is not printed twice. + const excerptDetail = typeof excerpt === 'string' && excerpt.length > 0 + && !(failure?.['kind'] === 'stderr' && typeof stderr === 'string') + ? excerpt : undefined; + return { + ...(typeof exitCode === 'number' && Number.isSafeInteger(exitCode) ? { exitCode } : {}), + ...(typeof stdout === 'string' && stdout.length > 0 ? { stdoutTail: stdout } : {}), + ...(typeof stderr === 'string' ? { stderrTail: stderr } : {}), + // Keep the daemon's account only when it was NOT just a render of the + // fields above — otherwise the same bytes print twice. + ...(excerptDetail !== undefined ? { detail: excerptDetail } + : typeof detail === 'string' && detail.length > 0 && !structuredShape + ? { detail } : {}), + ...(typeof transcriptPath === 'string' && transcriptPath.length > 0 ? { transcriptPath } : {}), + }; +} + +/** The `StepFailedDetails` scalars for one completion, at the terminal bound. */ +export function terminalEvidence(payload: Record): Partial { + const selected = selectEvidence(payload); + return { + ...(selected.exitCode === undefined ? {} : { exitCode: selected.exitCode }), + ...(selected.stdoutTail === undefined ? {} : { stdoutTail: tail(selected.stdoutTail) }), + ...(selected.stderrTail === undefined ? {} : { stderrTail: tail(selected.stderrTail) }), + ...(selected.detail === undefined ? {} : { detail: tail(selected.detail) }), + ...(selected.transcriptPath === undefined ? {} : { transcriptPath: selected.transcriptPath }), + }; +} + +/** + * One historical attempt's record, redacted and then bounded. + * + * Redaction runs first so a credential cannot survive by sitting outside the + * excerpt window on one attempt and inside it on another. Control-character + * replacement alone is not redaction: an agent that echoed `rk_live_...` into + * its stderr would otherwise reach a terminal through this new field. + */ +export function attemptFailure( + attempt: unknown, + completionReason: string, + disposition: unknown, + payload: Record, +): StepAttemptFailure { + const selected = selectEvidence(payload); + let truncated = false; + const bound = (value: string): string => { + const redacted = redact(value); + if (Buffer.byteLength(redacted, 'utf8') > ATTEMPT_TAIL_BYTES) truncated = true; + return tail(redacted, ATTEMPT_TAIL_BYTES); + }; + const record_: StepAttemptFailure = { + ...(typeof attempt === 'number' && Number.isSafeInteger(attempt) && attempt > 0 + ? { attempt } : {}), + completionReason, + ...(typeof disposition === 'string' && disposition.length > 0 ? { disposition } : {}), + ...(selected.exitCode === undefined ? {} : { exitCode: selected.exitCode }), + ...(selected.stdoutTail === undefined ? {} : { stdoutTail: bound(selected.stdoutTail) }), + ...(selected.stderrTail === undefined ? {} : { stderrTail: bound(selected.stderrTail) }), + ...(selected.detail === undefined ? {} : { detail: bound(selected.detail) }), + }; + return truncated ? { ...record_, truncated } : record_; +} + +/** + * Everything about a completion that bears on WHY it failed, unbounded. + * + * Deliberately not the display selection: `selectEvidence` suppresses the + * daemon's render when process-shaped output exists, and prefers a transcript + * excerpt over both, so two attempts can show identical excerpts over + * different gate verdicts. Everything the journal recorded about the failure + * is read here instead, before any bound is applied. + * + * Timestamps, transcript paths, dispositions and attempt numbers are NOT + * causes and are excluded: they differ on every attempt by construction. + */ +export function failureCause( + completionReason: string, + payload: Record, +): AttemptCause { + const verification = record(payload['verification']); + const output = record(payload['output']); + const trajectory = record(payload['trajectory_tail']); + const failure = record(record(trajectory?.['transcript'])?.['failure']); + const verificationDetail = text(verification?.['detail']); + const accounts = [ + verificationDetail, + text(output?.['stdout_tail']), text(output?.['stderr_tail']), + text(trajectory?.['stdout_tail']), text(trajectory?.['stderr_tail']), + text(failure?.['excerpt']), + ]; + const exitCodes = [output?.['exit_code'], trajectory?.['exit_code']] + .filter(value => typeof value === 'number'); + return { + key: JSON.stringify([ + // `verification_failed` on a retry and `retries_exhausted` at the budget + // limit are the SAME fallback over the same failure: `completion_actions` + // picks the label from the branch it took, not from the cause. Comparing + // them literally would report "the retry failed differently" on every + // ordinary repeated failure. No other pair of labels is collapsed. + completionReason === 'verification_failed' || completionReason === 'retries_exhausted' + ? 'kernel_rejected' : completionReason, + text(verification?.['gate']), text(verification?.['verdict']), verificationDetail, + ...exitCodes, ...accounts, text(failure?.['kind']), + ]), + // An attempt that journaled nothing about itself cannot agree with + // another one; it can only fail to disagree. + recorded: exitCodes.length > 0 || accounts.some(account => account !== undefined), + producerTruncated: verificationDetail !== undefined + && PRODUCER_TRUNCATED.test(verificationDetail), + }; +} + +export interface AttemptCause { + readonly key: string; + readonly recorded: boolean; + readonly producerTruncated: boolean; +} + +export function compareAttempts(causes: readonly AttemptCause[]): AttemptEvidenceComparison { + if (new Set(causes.map(cause => cause.key)).size > 1) return 'differs'; + return causes.every(cause => cause.recorded && !cause.producerTruncated) + ? 'unchanged' : 'unknown'; +} + +const COMPARISON_CLAUSE: Record = { + differs: 'recorded failure evidence differs. An earlier attempt may have had side effects.', + unchanged: 'recorded failure evidence is unchanged across them.', + unknown: 'recorded failure evidence is incomplete, so whether the causes differ is unknown.', +}; + +/** + * Every failed attempt, oldest first, under one line saying whether they + * agree. Rendered in full rather than elided: `flows logs` prints the runner + * log without eliding it, so an attempt dropped here is an attempt that + * reaches no reader at all. + */ +export function renderAttemptHistory(details: StepFailedDetails): string { + const attempts = details.attempts; + if (attempts === undefined || attempts.length < 2) return ''; + const comparison = COMPARISON_CLAUSE[details.attemptEvidence ?? 'unknown']; + return [`\nAttempts: ${attempts.length} failed; ${comparison}`, ...attempts.map(renderAttempt)] + .join('\n'); +} + +function renderAttempt(attempt: StepAttemptFailure): string { + const head = ` attempt ${attempt.attempt ?? '?'}: ${attempt.completionReason ?? 'unknown'}` + + (attempt.exitCode === undefined ? '' : ` exit=${attempt.exitCode}`) + + (attempt.truncated ? ' (excerpt truncated)' : ''); + // An empty `stderrTail` is a journaled fact but not an account of anything, + // so it never displaces useful stdout the way `detail ?? stderr ?? stdout` + // would. Both are kept when both exist. + const accounts: Array<[string, string]> = [ + ['detail', attempt.detail], ['stderr', attempt.stderrTail], ['stdout', attempt.stdoutTail], + ].filter((pair): pair is [string, string] => typeof pair[1] === 'string' && pair[1].length > 0); + if (accounts.length === 0) return `${head} — no failure evidence recorded`; + const [only] = accounts; + if (accounts.length === 1 && !only![1].includes('\n')) return `${head} — ${only![0]}: ${only![1]}`; + return [head, ...accounts.map(([label, value]) => indent(`${label}: ${value}`))].join('\n'); +} + +/** Continuation lines are indented past the label so the list stays readable. */ +function indent(block: string): string { + const [first, ...rest] = block.split('\n'); + return [` ${first}`, ...rest.map(line => ` ${line}`)].join('\n'); +} + +function text(value: unknown): string | undefined { + return typeof value === 'string' && value.length > 0 ? value : undefined; +} + +function processShaped(value: Record): boolean { + return typeof value['exit_code'] === 'number' + || typeof value['stdout_tail'] === 'string' || typeof value['stderr_tail'] === 'string'; +} + +function parsed(value: string): Record | undefined { + try { + return record(JSON.parse(value)); + } catch { + return undefined; + } +} + +export function record(value: unknown): Record | undefined { + return value !== null && typeof value === 'object' && !Array.isArray(value) + ? value as Record : undefined; +} + +export function tail(value: string, limit = TAIL_BYTES): string { + const bytes = Buffer.from(value, 'utf8'); + let start = Math.max(0, bytes.length - limit); + // Drop a partial leading code point, avoiding replacement-byte expansion. + while (start < bytes.length && (bytes[start]! & 0xc0) === 0x80) start += 1; + // Preserve tabs/newlines; replace binary controls (including ESC and CR), + // C1 controls and Unicode formatting controls without growing the excerpt. + return bytes.subarray(start).toString('utf8') + .replace(/[\p{Cc}\p{Cf}]/gu, character => character === '\n' || character === '\t' ? character : '?'); +} diff --git a/packages/sdk/src/cli/step-failure.ts b/packages/sdk/src/cli/step-failure.ts index d04e10ba1..d6e25d4eb 100644 --- a/packages/sdk/src/cli/step-failure.ts +++ b/packages/sdk/src/cli/step-failure.ts @@ -1,9 +1,22 @@ import { join } from 'node:path'; import { DEFAULT_DATA_DIR } from '../daemon-connection.js'; -import type { StepFailedDetails } from '../failure-kinds.js'; +import type { StepAttemptFailure, StepFailedDetails } from '../failure-kinds.js'; import type { JournalClient } from '../journal-client.js'; +import { + attemptFailure, + compareAttempts, + failureCause, + record, + renderAttemptHistory, + terminalEvidence, + type AttemptCause, +} from './step-evidence.js'; -const TAIL_BYTES = 1_024; +/** Every failed attempt of one step, in journal order, with its causes. */ +interface AttemptHistory { + records: StepAttemptFailure[]; + causes: AttemptCause[]; +} /** * Read what a failed step left in the journal — for any step type. @@ -22,10 +35,16 @@ const TAIL_BYTES = 1_024; * agent or llm step the worker's `{exit_code, stdout_tail, stderr_tail}` is * nulled out of `output` and survives only as the bounded render the daemon * captured into `verification.detail` (`worker_failure_detail`, - * relayflowd/src/engine/remote.rs). Both are read, in that order, and the - * daemon's render is re-parsed when it carries that same shape: an exit code - * the daemon stringified on its way into the journal is still an exit code, - * and printing it as one is the difference between a diagnosis and a blob. + * relayflowd/src/engine/remote.rs). Both are read by `selectEvidence`, in that + * order, and the daemon's render is re-parsed when it carries that same shape. + * + * EVERY failed attempt is collected, not only the terminal one. The kernel + * appends a `step.completed` per attempt, so a retried step's first failure is + * in the journal — but `retries_exhausted` reported only the last attempt, and + * a retry that fails differently (because the first attempt already had a side + * effect) is exactly when the last attempt is the least informative record + * there is. The scalar fields still describe the terminal attempt; `attempts` + * is additive. */ export async function stepFailureDetails( client: JournalClient, @@ -41,6 +60,9 @@ export async function stepFailureDetails( // enforcing (relayflowd-core/src/entry.rs `AttemptStartedPayload`). They are // collected on the same walk and reported only when the journal held them. const budgets = new Map(); + // Keyed by step, so interleaved steps never pool their attempts and a page + // boundary never splits one step's history. + const histories = new Map(); while (true) { const { entries } = await client.journalRead(runId, fromSeq, 100); if (entries.length === 0) break; @@ -64,15 +86,27 @@ export async function stepFailureDetails( // A later completion supersedes an earlier failed attempt. failures.delete(stepId); const payload = record(entry['payload']); - if (payload === undefined) continue; - const completionReason = payload['completionReason']; + const completionReason = payload?.['completionReason']; + // A success — or a completion this reader cannot read — ends the failure + // history too: what a step that eventually succeeded printed on the way + // is not the diagnosis of a later, different failure. The journal still + // holds every entry; only this diagnostic's candidate is cleared. + if (payload === undefined || typeof completionReason !== 'string' || completionReason === 'success') { + histories.delete(stepId); + continue; + } + const history = histories.get(stepId) ?? { records: [], causes: [] }; + // Recorded for `retry` and `park` alike: the kernel's disposition says + // what it did next, not whether the attempt failed. + history.records.push(attemptFailure(entry['attempt'], completionReason, payload['disposition'], payload)); + history.causes.push(failureCause(completionReason, payload)); + histories.set(stepId, history); // A terminal completion that is not a success is the failure, whatever // its step type. The old predicate also demanded a non-zero `exit_code`, // which no agent completion carries and which a deterministic step that // exits 0 and then fails its gate does not carry either — both were // silently skipped. - if (payload['disposition'] !== 'step_done' - || typeof completionReason !== 'string' || completionReason === 'success') continue; + if (payload['disposition'] !== 'step_done') continue; const stepType = snapshot.steps[stepId]?.type; const attempt = entry['attempt']; const maxIterations = budgets.get(stepId); @@ -82,7 +116,13 @@ export async function stepFailureDetails( ...(stepType === undefined ? {} : { stepType }), ...(typeof attempt === 'number' && Number.isSafeInteger(attempt) && attempt > 0 ? { attempt } : {}), ...(maxIterations === undefined ? {} : { maxIterations }), - ...evidence(payload), + ...terminalEvidence(payload), + // A single failed attempt is already fully described by the scalars + // above; repeating it as a one-element history would add a clause to + // every ordinary failure report without adding a fact. + ...(history.records.length > 1 + ? { attempts: history.records, attemptEvidence: compareAttempts(history.causes) } + : {}), }); } } @@ -105,6 +145,10 @@ export async function stepFailureDetails( * stops it being misread. Unknown values are omitted rather than defaulted — * an absent budget must not be reported as one attempt. * + * The attempt history follows that line and precedes the terminal attempt's + * own clauses, so the first error is visible without scrolling past the last + * one's output tails. + * * Lives next to `StepFailedDetails`'s extractor rather than in `cli/run.ts` so * the authored `f.run` path can render the same grammar without importing the * run lifecycle (which would be a cycle). @@ -116,6 +160,7 @@ export function renderStepEvidence(details: StepFailedDetails): string { + renderAttempt(details) + (details.exitCode === undefined ? '' : ` exit=${details.exitCode}`) + '.' + + renderAttemptHistory(details) + (details.detail === undefined ? '' : `\nDetail: ${details.detail}`) + (details.stdoutTail ? `\nStdout (last 1,024 bytes):\n${details.stdoutTail}` : '') + (details.stderrTail ? `\nStderr (last 1,024 bytes):\n${details.stderrTail}` : '') @@ -164,86 +209,6 @@ export function inspectionHint( }; } -/** - * Pull the process-shaped fields out of whichever field carried them. - * - * `verification.detail` is last because it is the daemon's own render rather - * than the worker's structured report — but for an agent step it is the only - * thing that survives, so it is parsed when it parses and kept verbatim when - * it does not. A truncated render (the daemon caps at 2,000 chars and appends - * a truncation note) will not parse; that falls through to the raw string, - * which is still the account of what went wrong. - * - * An agent or llm completion now also carries `trajectory_tail.transcript` - * (agent-transcript.ts) on every attempt. That object is not process-shaped, - * so it must not shadow the render that is: the first candidate that carries - * an exit code or a tail wins. The digest contributes what only it has — the - * failure excerpt the worker picked out of the provider's frames, and the - * path of the transcript file. - */ -function evidence(payload: Record): Partial { - const detail = record(payload['verification'])?.['detail']; - const candidates = [ - record(payload['output']), - record(payload['trajectory_tail']), - typeof detail === 'string' ? parsed(detail) : undefined, - ].filter((candidate): candidate is Record => candidate !== undefined); - const structured = candidates.find(processShaped) ?? candidates[0]; - const exitCode = structured?.['exit_code']; - const stdout = structured?.['stdout_tail']; - const stderr = structured?.['stderr_tail']; - const structuredShape = structured !== undefined && processShaped(structured); - const transcript = record(record(payload['trajectory_tail'])?.['transcript']); - const failure = record(transcript?.['failure']); - const excerpt = failure?.['excerpt']; - const transcriptPath = record(transcript?.['file'])?.['path']; - // The excerpt is the worker's own pick of the failure; a `stderr` excerpt - // is the same bytes as `stderrTail`, so it is not printed twice. - const excerptDetail = typeof excerpt === 'string' && excerpt.length > 0 - && !(failure?.['kind'] === 'stderr' && typeof stderr === 'string') - ? tail(excerpt) : undefined; - return { - ...(typeof exitCode === 'number' && Number.isSafeInteger(exitCode) ? { exitCode } : {}), - ...(typeof stdout === 'string' && stdout.length > 0 ? { stdoutTail: tail(stdout) } : {}), - ...(typeof stderr === 'string' ? { stderrTail: tail(stderr) } : {}), - // Keep the daemon's account only when it was NOT just a render of the - // fields above — otherwise the same bytes print twice. - ...(excerptDetail !== undefined ? { detail: excerptDetail } - : typeof detail === 'string' && detail.length > 0 && !structuredShape - ? { detail: tail(detail) } : {}), - ...(typeof transcriptPath === 'string' && transcriptPath.length > 0 ? { transcriptPath } : {}), - }; -} - -function processShaped(value: Record): boolean { - return typeof value['exit_code'] === 'number' - || typeof value['stdout_tail'] === 'string' || typeof value['stderr_tail'] === 'string'; -} - -function parsed(value: string): Record | undefined { - try { - return record(JSON.parse(value)); - } catch { - return undefined; - } -} - -function record(value: unknown): Record | undefined { - return value !== null && typeof value === 'object' && !Array.isArray(value) - ? value as Record : undefined; -} - -function tail(value: string): string { - const bytes = Buffer.from(value, 'utf8'); - let start = Math.max(0, bytes.length - TAIL_BYTES); - // Drop a partial leading code point, avoiding replacement-byte expansion. - while (start < bytes.length && (bytes[start]! & 0xc0) === 0x80) start += 1; - // Preserve tabs/newlines; replace binary controls (including ESC and CR), - // C1 controls and Unicode formatting controls without growing the excerpt. - return bytes.subarray(start).toString('utf8') - .replace(/[\p{Cc}\p{Cf}]/gu, character => character === '\n' || character === '\t' ? character : '?'); -} - function shellQuote(value: string): string { return /^[A-Za-z0-9_-]+$/.test(value) && !value.startsWith('-') ? value : `'${value.replace(/'/g, "'\\''")}'`; diff --git a/packages/sdk/src/failure-kinds.ts b/packages/sdk/src/failure-kinds.ts index 46b704693..55a25cb04 100644 --- a/packages/sdk/src/failure-kinds.ts +++ b/packages/sdk/src/failure-kinds.ts @@ -146,6 +146,55 @@ export type PreflightWarningKind = (typeof PREFLIGHT_WARNING_KINDS)[number]; export type RunFailureKind = (typeof RUN_FAILURE_KINDS)[number]; export type RunWarningKind = (typeof RUN_WARNING_KINDS)[number]; +/** + * One failed attempt of a step, as the journal recorded it. + * + * The kernel appends a `step.completed` PER ATTEMPT (relayflowd-core/src/machine.rs + * `completion_actions`), so a step that was retried leaves an ordered account + * of every failure — not just the one that ran out of budget. Reporting only + * the last is how a push rejected by a pre-receive hook was reported as + * "nothing staged inside the declared scope": the retry failed for a different + * reason than the original attempt, and the original reason was the diagnosis. + * + * Excerpts here are bounded harder than the terminal attempt's (256 bytes + * rather than 1,024): this is history beside the primary account, not a + * replacement for it. + */ +export interface StepAttemptFailure { + /** + * The journal entry envelope's attempt number. Absent when the journal did + * not carry one; the position in the list is not a substitute, because a + * crashed attempt that consumed no iteration is still its own record. + */ + attempt?: number; + /** The kernel's label for THIS attempt, e.g. `verification_failed`. */ + completionReason?: string; + /** `retry`, `step_done` or `park`: what the kernel did next, not why it failed. */ + disposition?: string; + exitCode?: number; + /** Redacted, terminal-safe UTF-8 excerpt, at most 256 bytes. */ + stdoutTail?: string; + /** Redacted, terminal-safe UTF-8 excerpt, at most 256 bytes. */ + stderrTail?: string; + /** This attempt's own account, from the same fields the terminal one reads. */ + detail?: string; + /** Set when an excerpt above was cut to fit the per-attempt bound. */ + truncated?: boolean; +} + +/** + * What comparing the attempts' recorded evidence established — and no more. + * + * `differs` means the journal's own failure evidence is not the same across + * attempts, which usually means an earlier attempt had a side effect the retry + * then tripped over. `unchanged` is a statement about the RECORD, not a proof + * that the underlying causes were identical. `unknown` is the honest answer + * when an attempt journaled no account of itself, or when its account was + * already truncated by its producer: equal evidence that was never complete is + * not evidence of equality. + */ +export type AttemptEvidenceComparison = 'differs' | 'unchanged' | 'unknown'; + /** * Optional evidence on the existing step_failed diagnostic, not a new kind. * @@ -154,6 +203,9 @@ export type RunWarningKind = (typeof RUN_WARNING_KINDS)[number]; * agent or llm step leaves `completionReason` and whatever the daemon captured * into `detail` (see cli/step-failure.ts). Absent means "not journaled", never * "zero" — an exit code is only ever reported when one was actually recorded. + * + * The scalar evidence fields always describe the TERMINAL attempt. `attempts` + * is additive history and is present only when the step failed more than once. */ export interface StepFailedDetails { stepId?: string; @@ -189,6 +241,15 @@ export interface StepFailedDetails { detail?: string; /** The attempt's redacted `stream-json` transcript on disk, when the worker wrote one. */ transcriptPath?: string; + /** + * Every failed attempt of the step this failure names, oldest first, present + * only when there was more than one. The last element is the same attempt the + * scalar fields above describe; the first is the one `retries_exhausted` + * alone used to hide. + */ + attempts?: StepAttemptFailure[]; + /** What comparing those attempts' recorded evidence established. */ + attemptEvidence?: AttemptEvidenceComparison; /** A runnable `flows replay` invocation for this run. */ hint?: string; /** The on-disk journal for this run, when the data dir is known. */ diff --git a/packages/sdk/tests/cloud-read.test.ts b/packages/sdk/tests/cloud-read.test.ts index 548772530..cbc41e666 100644 --- a/packages/sdk/tests/cloud-read.test.ts +++ b/packages/sdk/tests/cloud-read.test.ts @@ -13,6 +13,7 @@ import { runCli } from '../src/cli.js'; import { errorLines, parseLogsArgs, parseRunsArgs, runCloudLogsCli, runCloudRunsCli, runCloudStatusCli, } from '../src/cli/cloud-read.js'; +import { renderStepEvidence } from '../src/cli/step-failure.js'; import { parseStatusArgs } from '../src/cli/status.js'; const RUN = '20d04c99-3fa8-48c9-9286-92d364a5bc2e'; @@ -261,6 +262,33 @@ describe('flows logs', () => { expect(server.requests[0]!.query).toBe(''); }); + it('prints every attempt of a retried step the runner log captured', async () => { + // `flows logs ` has no journal to read: Cloud keeps the runner's + // captured stderr and there is no journal-export endpoint. So every + // attempt reaches a hosted reader only if the CLI printed every attempt in + // the first place — which is why the log content here is built by the real + // producer, `renderStepEvidence`, rather than written out by hand. + const attempts = Array.from({ length: 7 }, (_unused, index) => ({ + attempt: index + 1, completionReason: 'verification_failed', exitCode: 1, + stderrTail: `attempt ${index + 1} rejected by the pre-receive hook`, + })); + const diagnostic = renderStepEvidence({ + stepId: 'commit-and-push', stepType: 'deterministic', completionReason: 'retries_exhausted', + attempt: 7, maxIterations: 7, exitCode: 1, attempts, attemptEvidence: 'differs', + }); + const runner = `[bootstrap] Starting workflow execution (per-step-sandbox)\nFAILED [step_failed]${diagnostic}\n`; + wholeCloud({ runner }); + const out = io(); + expect(await runCloudLogsCli(parseLogsArgs([RUN])!, out.io, CONNECTION)).toBe(0); + const rendered = out.stdout.join('\n'); + // Not one attempt elided: the runner log is printed line for line, so the + // first rejection is as readable here as the last. + for (let attempt = 1; attempt <= 7; attempt += 1) { + expect(rendered).toContain(`attempt ${attempt} rejected by the pre-receive hook`); + } + expect(rendered).toContain('An earlier attempt may have had side effects.'); + }); + it('renders an agent step’s transcript: session header, prose, one line per tool call, footer', async () => { const server = wholeCloud(); const out = io(); diff --git a/packages/sdk/tests/retried-step-failure.test.ts b/packages/sdk/tests/retried-step-failure.test.ts new file mode 100644 index 000000000..acf3c5a11 --- /dev/null +++ b/packages/sdk/tests/retried-step-failure.test.ts @@ -0,0 +1,77 @@ +import { writeFileSync } from 'node:fs'; +import { join } from 'node:path'; +import { afterEach, describe, expect, it } from 'vitest'; +import type { RunDiagnostic, RunReport } from '../src/cli/run.js'; +import { chainFixture } from './flow-chain-fixture.js'; + +const cleanup: Array<() => Promise> = []; +afterEach(async () => { for (const close of cleanup.splice(0)) await close(); }); + +const REJECTION = "remote: GitLab: You cannot push commits for 'factory@example.com'"; +const NOTHING_STAGED = 'nothing staged inside the declared scope'; + +/** + * The reported failure, reproduced: the first attempt is refused by a hook and + * the second dies because the first attempt already had its side effect. The + * marker file is that side effect — without one, a retried command fails the + * same way twice and the bug is invisible. + */ +function divergentCommand(marker: string): string { + return `if [ -f ${marker} ]; then printf %s ${JSON.stringify(NOTHING_STAGED)} >&2; ` + + `else : > ${marker}; printf %s ${JSON.stringify(REJECTION)} >&2; fi; exit 1`; +} + +describe('a retried step failing differently through the live kernel', () => { + it('reports both attempts and says the evidence differs', async () => { + const fixture = chainFixture(); + cleanup.push(() => fixture.close()); + let journal = await fixture.connect(); + const flowPath = join(fixture.root, 'retried.flow.yaml'); + writeFileSync(flowPath, `version: '0.1.0' +name: retried-commit +steps: + - id: commit-and-push + type: deterministic + maxIterations: 2 + command: ${JSON.stringify(divergentCommand(join(fixture.root, 'already-pushed')))} +`); + + const result = fixture.invoke('run', flowPath, '--data-dir', fixture.data, '--json'); + expect(result.status, result.stderr + result.stdout).toBe(1); + const report = JSON.parse(result.stdout) as RunReport; + const diagnostic = report.diagnostics.at(-1) as RunDiagnostic; + + expect(diagnostic).toMatchObject({ + kind: 'step_failed', stepId: 'commit-and-push', stepType: 'deterministic', + completionReason: 'retries_exhausted', attempt: 2, maxIterations: 2, + // The scalars remain the terminal attempt's, as they always were. + exitCode: 1, stderrTail: NOTHING_STAGED, + attemptEvidence: 'differs', + }); + expect(diagnostic.attempts).toMatchObject([ + { attempt: 1, disposition: 'retry', exitCode: 1, stderrTail: REJECTION }, + { attempt: 2, disposition: 'step_done', exitCode: 1, stderrTail: NOTHING_STAGED }, + ]); + // The account of what actually went wrong is in the rendered message, not + // only in a field a machine reader has to know to ask for. + expect(diagnostic.message).toContain(REJECTION); + expect(diagnostic.message).toContain('An earlier attempt may have had side effects.'); + + // The kernel journals each attempt's own captured output. Nothing above is + // reconstructed by the reader; it is read back here from the daemon that + // wrote it, after the process that ran the command is gone. + journal = await fixture.restart(); + const { entries } = await journal.journalRead(report.runId, 1, 100); + const completions = (entries as Array<{ + entry_type: string; attempt?: number; + payload?: { completionReason?: string; disposition?: string; output?: { stderr_tail?: string } }; + }>).filter(entry => entry.entry_type === 'step.completed'); + expect(completions.map(entry => [ + entry.attempt, entry.payload?.completionReason, entry.payload?.disposition, + entry.payload?.output?.stderr_tail, + ])).toEqual([ + [1, 'verification_failed', 'retry', REJECTION], + [2, 'retries_exhausted', 'step_done', NOTHING_STAGED], + ]); + }, 60_000); +}); diff --git a/packages/sdk/tests/step-attempt-history.test.ts b/packages/sdk/tests/step-attempt-history.test.ts new file mode 100644 index 000000000..12c3e4699 --- /dev/null +++ b/packages/sdk/tests/step-attempt-history.test.ts @@ -0,0 +1,369 @@ +import { describe, expect, it, vi } from 'vitest'; +import { stepFailedFrame } from '../src/authored-node-runner.js'; +import { classifyOutcome, emptyReport, type RunDiagnostic } from '../src/cli/run.js'; +import type { JournalClient } from '../src/journal-client.js'; +import type { RunOutcome } from '../src/protocol.js'; + +// The field report this pins: a commit-and-push step was refused by a GitLab +// pre-receive hook, the retry re-ran a commit that had already landed and died +// for a different reason, and `retries_exhausted` reported only the second. +const REJECTION = "remote: GitLab: You cannot push commits for 'factory@example.com'"; +const NOTHING_STAGED = 'nothing staged inside the declared scope'; + +const failure: RunOutcome = { + run_id: 'run-failed', status: 'failed', completion_reason: 'step_failed', completed_steps: 0, +}; + +const DETERMINISTIC = { 'commit-and-push': { type: 'deterministic', state: 'done' } }; +const AGENT = { 'commit-and-push': { type: 'agent', state: 'done' } }; +const TWO_STEPS = { ...DETERMINISTIC, other: { type: 'deterministic', state: 'done' } }; + +interface Completion { + seq: number; + attempt?: number; + stepId?: string; + reason?: string; + disposition?: string; + output?: unknown; + verification?: unknown; + trajectory?: unknown; +} + +/** One `step.completed` entry in the shape `completion_actions` appends. */ +function completed(entry: Completion) { + return { + seq: entry.seq, entry_type: 'step.completed', step_id: entry.stepId ?? 'commit-and-push', + ...(entry.attempt === undefined ? {} : { attempt: entry.attempt }), + payload: { + completionReason: entry.reason ?? 'verification_failed', + disposition: entry.disposition ?? 'step_done', + output: entry.output ?? null, + ...(entry.verification === undefined ? {} : { verification: entry.verification }), + ...(entry.trajectory === undefined ? {} : { trajectory_tail: entry.trajectory }), + }, + }; +} + +/** `preserve_failure_output`'s shape for a failed deterministic attempt. */ +function captured(exitCode: number, stderr: string, stdout = '') { + return { exit_code: exitCode, stdout_tail: stdout, stderr_tail: stderr }; +} + +/** The daemon's bounded render, which is all an agent attempt leaves behind. */ +function render(stderr: string, stdout = '') { + return { + gate: 'execution', verdict: 'fail', + detail: JSON.stringify({ exit_code: 1, stdout_tail: stdout, stderr_tail: stderr }), + }; +} + +function stub(pages: unknown[][], steps: Record = DETERMINISTIC) { + const runGet = vi.fn(async () => ({ steps })); + const journalRead = vi.fn(async () => ({ entries: pages.shift() ?? [] })); + return { client: { runGet, journalRead } as unknown as JournalClient, journalRead }; +} + +async function diagnose(pages: unknown[][], steps?: Record) { + const { client, journalRead } = stub(pages, steps); + const execution = await classifyOutcome( + client, 'run', failure, emptyReport('run'), '/tmp/attempts.sock', {}); + return { + diagnostic: execution.report.diagnostics.at(-1) as RunDiagnostic, + journalRead, + }; +} + +/** A retried step, failing differently each time — the reported scenario. */ +function divergentRetry() { + return [ + completed({ seq: 1, attempt: 1, disposition: 'retry', output: captured(1, REJECTION) }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output: captured(1, NOTHING_STAGED), + }), + ]; +} + +describe('attempt history in a retried step failure', () => { + it("reports the first attempt's error beside the last and says they differ", async () => { + const { diagnostic } = await diagnose([divergentRetry()]); + expect(diagnostic.attempts).toEqual([ + { + attempt: 1, completionReason: 'verification_failed', disposition: 'retry', + exitCode: 1, stderrTail: REJECTION, + }, + { + attempt: 2, completionReason: 'retries_exhausted', disposition: 'step_done', + exitCode: 1, stderrTail: NOTHING_STAGED, + }, + ]); + expect(diagnostic.attemptEvidence).toBe('differs'); + // The scalars still describe the terminal attempt; the history is additive. + expect(diagnostic).toMatchObject({ + completionReason: 'retries_exhausted', exitCode: 1, stderrTail: NOTHING_STAGED, + }); + const message = diagnostic.message; + expect(message).toContain('Attempts: 2 failed; recorded failure evidence differs.'); + expect(message).toContain('An earlier attempt may have had side effects.'); + // Oldest first: the rejection that actually caused the failure is readable + // without scrolling past the consequence of retrying it. + expect(message.indexOf(REJECTION)).toBeLessThan(message.indexOf(NOTHING_STAGED)); + expect(message).toContain(` attempt 1: verification_failed exit=1 — stderr: ${REJECTION}`); + }); + + it('does not call the exhaustion label a different failure', async () => { + // `completion_actions` picks `verification_failed` on the retry branch and + // `retries_exhausted` at the budget limit for the SAME cause. Comparing + // the labels literally would announce side effects on every ordinary + // repeated failure, which is the noise that makes a real one unreadable. + const same = captured(1, REJECTION); + const { diagnostic } = await diagnose([[ + completed({ seq: 1, attempt: 1, disposition: 'retry', output: same }), + completed({ seq: 2, attempt: 2, reason: 'retries_exhausted', output: same }), + ]]); + expect(diagnostic.attemptEvidence).toBe('unchanged'); + expect(diagnostic.message).toContain('recorded failure evidence is unchanged across them'); + expect(diagnostic.message).not.toContain('side effects'); + }); + + it('compares the unbounded record, not the excerpt two attempts share', async () => { + const shared = 'x'.repeat(400); + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, disposition: 'retry', output: captured(1, `${REJECTION}\n${shared}`), + }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', + output: captured(1, `${NOTHING_STAGED}\n${shared}`), + }), + ]]); + // Both 256-byte excerpts are the same bytes. The difference survives only + // because the comparison ran on the journal record, before the bound. + expect(diagnostic.attempts![0]!.stderrTail).toBe(diagnostic.attempts![1]!.stderrTail); + expect(diagnostic.attemptEvidence).toBe('differs'); + expect(diagnostic.attempts!.every(attempt => attempt.truncated)).toBe(true); + expect(diagnostic.message).toContain('(excerpt truncated)'); + }); + + it('sees a changed gate verdict behind identical process output', async () => { + const output = captured(1, 'build failed'); + const gate = (detail: string) => ({ gate: 'exit_code+output_contains', verdict: 'fail', detail }); + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, disposition: 'retry', output, + verification: gate('exit_code: expected 0, got 1'), + }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output, + verification: gate('output_contains: missing "done"'), + }), + ]]); + // The render is suppressed for display because the output is process + // shaped — it is still read for the comparison. + expect(diagnostic.attempts![0]).not.toHaveProperty('detail'); + expect(diagnostic.attemptEvidence).toBe('differs'); + }); + + it('keeps stdout when stderr is empty rather than reporting nothing', async () => { + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, disposition: 'retry', + output: captured(1, '', 'pre-receive hook declined'), + }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output: captured(1, '', 'nothing to commit'), + }), + ]]); + expect(diagnostic.message).toContain('stdout: pre-receive hook declined'); + expect(diagnostic.message).toContain('stdout: nothing to commit'); + }); + + it('labels both accounts when an attempt left a detail and a tail', async () => { + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, reason: 'worker_error', disposition: 'retry', + verification: render('process stderr'), + trajectory: { transcript: { failure: { kind: 'result', excerpt: 'Claude: budget exhausted' } } }, + }), + completed({ seq: 2, attempt: 2, reason: 'worker_error', verification: render('rate limited') }), + ]], AGENT); + expect(diagnostic.attempts![0]).toMatchObject({ + detail: 'Claude: budget exhausted', stderrTail: 'process stderr', + }); + expect(diagnostic.message).toContain(' detail: Claude: budget exhausted'); + expect(diagnostic.message).toContain(' stderr: process stderr'); + }); + + it('reads each agent attempt out of the render the kernel kept', async () => { + // The kernel nulls `output` on a failed non-deterministic completion, so + // every attempt of a retried agent step survives only as this render. + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, reason: 'worker_error', disposition: 'retry', + verification: render('no such model'), + }), + completed({ seq: 2, attempt: 2, reason: 'worker_error', verification: render('rate limited') }), + ]], AGENT); + expect(diagnostic.attempts).toMatchObject([ + { attempt: 1, exitCode: 1, stderrTail: 'no such model' }, + { attempt: 2, exitCode: 1, stderrTail: 'rate limited' }, + ]); + expect(diagnostic.attemptEvidence).toBe('differs'); + }); + + it('will not call two renders the daemon already cut identical', async () => { + // `worker_failure_detail` caps at 2,000 chars. Two attempts whose renders + // agree up to the cut may have disagreed past it, and claiming they were + // the same failure would be a claim the journal does not support. + const detail = `analyzer exited 1: ${'y'.repeat(50)}… (2,048 bytes truncated)`; + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, reason: 'worker_error', disposition: 'retry', + verification: { gate: 'execution', verdict: 'fail', detail }, + }), + completed({ + seq: 2, attempt: 2, reason: 'worker_error', + verification: { gate: 'execution', verdict: 'fail', detail }, + }), + ]], AGENT); + expect(diagnostic.attemptEvidence).toBe('unknown'); + expect(diagnostic.message).toContain('whether the causes differ is unknown'); + }); + + it('names the attempts it cannot account for instead of inventing evidence', async () => { + const { diagnostic } = await diagnose([[ + completed({ seq: 1, reason: 'crashed', disposition: 'retry' }), + completed({ seq: 2, reason: 'crashed' }), + ]]); + expect(diagnostic.attempts).toEqual([ + { completionReason: 'crashed', disposition: 'retry' }, + { completionReason: 'crashed', disposition: 'step_done' }, + ]); + // Two attempts that recorded nothing cannot agree; they can only fail to + // disagree, and `unchanged` would be an assertion about what was lost. + expect(diagnostic.attemptEvidence).toBe('unknown'); + expect(diagnostic.message).toContain('attempt ?: crashed — no failure evidence recorded'); + }); + + it('records a parked attempt as a failure of that attempt', async () => { + const { diagnostic } = await diagnose([[ + completed({ seq: 1, attempt: 1, disposition: 'park', output: captured(1, REJECTION) }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output: captured(1, NOTHING_STAGED), + }), + ]]); + expect(diagnostic.attempts).toMatchObject([ + { attempt: 1, disposition: 'park', stderrTail: REJECTION }, + { attempt: 2, disposition: 'step_done', stderrTail: NOTHING_STAGED }, + ]); + }); + + it('renders every failed attempt rather than eliding the middle', async () => { + // `flows logs` prints the runner log without eliding it, so an attempt + // dropped here is an attempt that reaches no reader at all. + const entries = Array.from({ length: 7 }, (_unused, index) => completed({ + seq: index + 1, attempt: index + 1, + reason: index === 6 ? 'retries_exhausted' : 'verification_failed', + disposition: index === 6 ? 'step_done' : 'retry', + output: captured(1, `failure ${index + 1}`), + })); + const { diagnostic } = await diagnose([entries]); + expect(diagnostic.attempts).toHaveLength(7); + expect(diagnostic.message).toContain('Attempts: 7 failed'); + for (let attempt = 1; attempt <= 7; attempt += 1) { + expect(diagnostic.message).toContain(`attempt ${attempt}: `); + expect(diagnostic.message).toContain(`failure ${attempt}`); + } + }); + + it("keeps one step's history across a page boundary and apart from another's", async () => { + const { diagnostic, journalRead } = await diagnose([ + [ + completed({ seq: 1, attempt: 1, disposition: 'retry', output: captured(1, REJECTION) }), + completed({ + seq: 2, attempt: 1, stepId: 'other', disposition: 'retry', output: captured(1, 'unrelated'), + }), + ], + [ + completed({ + seq: 3, attempt: 2, stepId: 'other', reason: 'retries_exhausted', + output: captured(1, 'unrelated'), + }), + completed({ + seq: 4, attempt: 2, reason: 'retries_exhausted', output: captured(1, NOTHING_STAGED), + }), + ], + ], TWO_STEPS); + expect(diagnostic.stepId).toBe('commit-and-push'); + expect(diagnostic.attempts).toMatchObject([ + { attempt: 1, stderrTail: REJECTION }, { attempt: 2, stderrTail: NOTHING_STAGED }, + ]); + expect(journalRead.mock.calls).toEqual([ + ['run-failed', 1, 100], ['run-failed', 3, 100], ['run-failed', 5, 100], + ]); + }); + + it('drops the attempts of a step that eventually succeeded', async () => { + const { diagnostic } = await diagnose([[ + completed({ seq: 1, attempt: 1, disposition: 'retry', output: captured(1, REJECTION) }), + completed({ seq: 2, attempt: 2, reason: 'success', output: captured(0, '') }), + completed({ + seq: 3, attempt: 1, stepId: 'other', reason: 'retries_exhausted', + output: captured(1, 'a later, different failure'), + }), + ]], TWO_STEPS); + expect(diagnostic.stepId).toBe('other'); + expect(diagnostic).not.toHaveProperty('attempts'); + expect(diagnostic.message).not.toContain(REJECTION); + }); + + it('redacts a credential an attempt echoed before bounding the excerpt', async () => { + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, disposition: 'retry', + output: captured(1, 'push failed for rk_live_0123456789abcdef0123456789abcdef'), + }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output: captured(1, NOTHING_STAGED), + }), + ]]); + expect(diagnostic.attempts![0]!.stderrTail).toBe('push failed for [redacted]'); + expect(diagnostic.message).not.toContain('rk_live_'); + }); + + it('adds nothing at all to a single failed attempt', async () => { + const { diagnostic } = await diagnose([[ + completed({ seq: 1, attempt: 1, reason: 'retries_exhausted', output: captured(7, 'only error') }), + ]]); + expect(diagnostic).not.toHaveProperty('attempts'); + expect(diagnostic).not.toHaveProperty('attemptEvidence'); + expect(diagnostic.message).not.toContain('Attempts:'); + expect(diagnostic.message).toContain('Stderr (last 1,024 bytes):\nonly error'); + }); +}); + +describe('attempt history over the authored runtime IPC frame', () => { + it('carries the history a child run read from its own journal', () => { + const details = { + stepId: 'commit-and-push', completionReason: 'retries_exhausted', attemptEvidence: 'differs', + attempts: [ + { + attempt: 1, completionReason: 'verification_failed', disposition: 'retry', + exitCode: 1, stderrTail: REJECTION, truncated: true, + }, + { attempt: 2, completionReason: 'retries_exhausted', disposition: 'step_done', detail: NOTHING_STAGED }, + ], + }; + expect(stepFailedFrame(details)).toEqual(details); + }); + + it('drops malformed attempts without voiding the ones it can read', () => { + expect(stepFailedFrame({ + attempts: ['nope', null, [], { attempt: 2.5, stderrTail: 'real', truncated: 'yes' }], + attemptEvidence: 'maybe', + })).toEqual({ attempts: [{ stderrTail: 'real' }] }); + }); + + it('ignores an attempts field that is not a list', () => { + expect(stepFailedFrame({ stepId: 'x', attempts: { attempt: 1 } })).toEqual({ stepId: 'x' }); + }); +}); From 4d1a21371da061001a869da139fd99e0f9d397be Mon Sep 17 00:00:00 2001 From: Relayflow Date: Sun, 20 Sep 2026 17:54:08 +0000 Subject: [PATCH 2/4] fix: keep a gate's verdict in the attempt history instead of dropping it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review P2: the new per-attempt history could still hide the first error. A first attempt rejected by `output_contains` journals exit 0, empty tails and the verdict that is the entire reason it failed — and `selectEvidence` dropped `verification.detail` whenever any field happened to be process-shaped, so that attempt rendered as "exit=0 — no failure evidence recorded". The error was in the journal and in neither the attempt object nor the message, which `flows logs` then cannot recover: Cloud keeps the printed bytes and nothing else. The detail is now withheld only when it would repeat bytes printed beside it — the daemon's `{exit_code, stdout_tail, stderr_tail}` render of a worker failure (`worker_failure_detail`), and the `exit_code` gate's bare `exit code was ` next to the exit code it restates (`verify.rs`). Every other verdict is kept, on each attempt and on the terminal clause. Also from the review's case 2: `compareAttempts` called an attempt that journaled nothing a changed cause, so a crash followed by a real error reported "an earlier attempt may have had side effects" on no evidence at all. Only attempts that recorded something are compared now; a missing account makes the comparison `unknown`, which is what docs/SURFACE.md already promised. A truncated render is still compared — truncation can only make two accounts look more alike than they were. Co-Authored-By: Claude --- docs/SURFACE.md | 25 +++++- packages/sdk/src/cli/step-evidence.ts | 49 +++++++++-- packages/sdk/tests/cloud-read.test.ts | 42 ++++++++- .../sdk/tests/step-attempt-history.test.ts | 88 +++++++++++++++++-- 4 files changed, 186 insertions(+), 18 deletions(-) diff --git a/docs/SURFACE.md b/docs/SURFACE.md index d9101064f..7f7843f53 100644 --- a/docs/SURFACE.md +++ b/docs/SURFACE.md @@ -705,7 +705,7 @@ FAILED [step_failed] Run "" failed with completionReason: step_failed. Attempts: failed; attempt 1: exit= — stderr: attempt 2: exit= — stderr: -Detail: +Detail: Stdout (last 1,024 bytes): Stderr (last 1,024 bytes): @@ -738,17 +738,34 @@ The corresponding `attempts` entries in `--json` use the keys `attempt`, `completionReason`, `disposition`, `exitCode`, `stdoutTail`, `stderrTail`, `detail` and `truncated`. +`detail` — on the terminal clause and on each attempt — is the verification +record's account: the gate's verdict for a deterministic step (`output did not +contain "READY"`), or what the worker reported for an agent or llm step. A gate +can refuse output that a command produced happily, so an attempt can report +exit 0, empty tails and a verdict that is the entire reason it failed. It is +withheld only when it would repeat bytes already printed beside it: the +daemon's `{exit_code, stdout_tail, stderr_tail}` render of a worker failure, +and the `exit_code` gate's bare `exit code was ` next to the exit code +it restates. + `attemptEvidence` says whether the attempts failed for the same reason, and is one of: -- `differs` — the journaled evidence is not the same across attempts. A retry - that fails differently usually means an earlier attempt already had a side - effect, so the message adds *An earlier attempt may have had side effects.* +- `differs` — two attempts that each recorded evidence recorded different + evidence. A retry that fails differently usually means an earlier attempt + already had a side effect, so the message adds *An earlier attempt may have + had side effects.* - `unchanged` — every attempt recorded evidence and all of it agrees. - `unknown` — at least one attempt journaled nothing about why it failed, or its evidence reached the journal already truncated by the daemon, so whether the causes differ cannot be decided. +Only attempts that recorded something are compared: an attempt that journaled +no account of itself is unequal to every other one on paper while establishing +nothing, and would otherwise put the side-effect warning on a crash that is +evidence of nothing. A render the daemon truncated is compared, because +truncation can only make two accounts look more alike than they were. + The comparison runs on the journal record before any display bound, and reads the verification gate, verdict and detail as well as the exit codes and output tails, so two attempts whose visible excerpts are identical are still reported diff --git a/packages/sdk/src/cli/step-evidence.ts b/packages/sdk/src/cli/step-evidence.ts index 8f5177eea..aac0cb27e 100644 --- a/packages/sdk/src/cli/step-evidence.ts +++ b/packages/sdk/src/cli/step-evidence.ts @@ -58,16 +58,16 @@ export interface SelectedEvidence { */ export function selectEvidence(payload: Record): SelectedEvidence { const detail = record(payload['verification'])?.['detail']; + const rendered = typeof detail === 'string' ? parsed(detail) : undefined; const candidates = [ record(payload['output']), record(payload['trajectory_tail']), - typeof detail === 'string' ? parsed(detail) : undefined, + rendered, ].filter((candidate): candidate is Record => candidate !== undefined); const structured = candidates.find(processShaped) ?? candidates[0]; const exitCode = structured?.['exit_code']; const stdout = structured?.['stdout_tail']; const stderr = structured?.['stderr_tail']; - const structuredShape = structured !== undefined && processShaped(structured); const transcript = record(record(payload['trajectory_tail'])?.['transcript']); const failure = record(transcript?.['failure']); const excerpt = failure?.['excerpt']; @@ -81,15 +81,39 @@ export function selectEvidence(payload: Record): SelectedEviden ...(typeof exitCode === 'number' && Number.isSafeInteger(exitCode) ? { exitCode } : {}), ...(typeof stdout === 'string' && stdout.length > 0 ? { stdoutTail: stdout } : {}), ...(typeof stderr === 'string' ? { stderrTail: stderr } : {}), - // Keep the daemon's account only when it was NOT just a render of the - // fields above — otherwise the same bytes print twice. ...(excerptDetail !== undefined ? { detail: excerptDetail } - : typeof detail === 'string' && detail.length > 0 && !structuredShape + : typeof detail === 'string' && detail.length > 0 && !duplicates(detail, rendered, exitCode) ? { detail } : {}), ...(typeof transcriptPath === 'string' && transcriptPath.length > 0 ? { transcriptPath } : {}), }; } +/** + * Whether printing `verification.detail` would print bytes already printed. + * + * Only two shapes do. The daemon's render of a worker failure IS the + * `{exit_code, stdout_tail, stderr_tail}` report (`worker_failure_detail`, + * relayflowd/src/engine/remote.rs), which a deterministic step journals + * alongside its preserved `output`; and the `exit_code` gate's verdict on its + * own is the exit code that is already reported beside it (`exit code was 1`, + * relayflowd-core/src/verify.rs). + * + * Every other verdict is the ONLY account of its failure. `output did not + * contain "READY"` accompanies exit 0 and empty tails, so suppressing the + * detail whenever some field happened to be process-shaped left the attempt + * saying `exit=0 — no failure evidence recorded` while the journal held the + * gate error — the first attempt hidden again, inside the diagnostic that + * exists to surface it. + */ +function duplicates( + detail: string, + rendered: Record | undefined, + exitCode: unknown, +): boolean { + if (rendered !== undefined && processShaped(rendered)) return true; + return typeof exitCode === 'number' && detail === `exit code was ${exitCode}`; +} + /** The `StepFailedDetails` scalars for one completion, at the terminal bound. */ export function terminalEvidence(payload: Record): Partial { const selected = selectEvidence(payload); @@ -191,9 +215,20 @@ export interface AttemptCause { readonly producerTruncated: boolean; } +/** + * Only attempts that recorded something can establish a difference. + * + * An attempt that journaled no account of itself differs from every other one + * on paper while saying nothing about why it failed, and reporting that as + * `differs` would put "an earlier attempt may have had side effects" on a + * crash that is evidence of nothing. Truncation is not the same case: two + * renders the daemon already cut can only look MORE alike than they were, so + * surviving bytes that disagree still prove the causes disagreed. + */ export function compareAttempts(causes: readonly AttemptCause[]): AttemptEvidenceComparison { - if (new Set(causes.map(cause => cause.key)).size > 1) return 'differs'; - return causes.every(cause => cause.recorded && !cause.producerTruncated) + const recorded = causes.filter(cause => cause.recorded); + if (new Set(recorded.map(cause => cause.key)).size > 1) return 'differs'; + return recorded.length === causes.length && causes.every(cause => !cause.producerTruncated) ? 'unchanged' : 'unknown'; } diff --git a/packages/sdk/tests/cloud-read.test.ts b/packages/sdk/tests/cloud-read.test.ts index cbc41e666..a519d725a 100644 --- a/packages/sdk/tests/cloud-read.test.ts +++ b/packages/sdk/tests/cloud-read.test.ts @@ -13,8 +13,9 @@ import { runCli } from '../src/cli.js'; import { errorLines, parseLogsArgs, parseRunsArgs, runCloudLogsCli, runCloudRunsCli, runCloudStatusCli, } from '../src/cli/cloud-read.js'; -import { renderStepEvidence } from '../src/cli/step-failure.js'; +import { renderStepEvidence, stepFailureDetails } from '../src/cli/step-failure.js'; import { parseStatusArgs } from '../src/cli/status.js'; +import type { JournalClient } from '../src/journal-client.js'; const RUN = '20d04c99-3fa8-48c9-9286-92d364a5bc2e'; const CONNECTION = { apiUrl: 'https://cloud-contract.example', token: 'test-scoped-cloud-token', env: {} }; @@ -289,6 +290,45 @@ describe('flows logs', () => { expect(rendered).toContain('An earlier attempt may have had side effects.'); }); + it('carries a first attempt whose only account is a gate verdict', async () => { + // An attempt refused by a gate exits 0 with empty tails: the verdict is + // the whole account of it. Read here with the production reader and + // rendered with the production renderer, because a gate error dropped at + // extraction is a gate error no hosted log can recover — Cloud keeps the + // printed bytes and nothing else. + const completion = (seq: number, attempt: number, payload: unknown) => ({ + seq, entry_type: 'step.completed', step_id: 'check', attempt, payload, + }); + const entries = [ + completion(1, 1, { + completionReason: 'verification_failed', disposition: 'retry', + output: { exit_code: 0, stdout_tail: '', stderr_tail: '' }, + verification: { + gate: 'output_contains', verdict: 'fail', detail: 'output did not contain "READY"', + }, + }), + completion(2, 2, { + completionReason: 'retries_exhausted', disposition: 'step_done', + output: { exit_code: 1, stdout_tail: '', stderr_tail: 'nothing staged in the declared scope' }, + verification: { gate: 'exit_code', verdict: 'fail', detail: 'exit code was 1' }, + }), + ]; + const client = { + runGet: async () => ({ steps: { check: { type: 'deterministic', state: 'done' } } }), + journalRead: async (_run: string, from: number) => ({ + entries: entries.filter(entry => entry.seq >= from), + }), + } as unknown as JournalClient; + const details = await stepFailureDetails(client, RUN); + const runner = `FAILED [step_failed]${renderStepEvidence(details!)}\n`; + wholeCloud({ runner }); + const out = io(); + expect(await runCloudLogsCli(parseLogsArgs([RUN])!, out.io, CONNECTION)).toBe(0); + const rendered = out.stdout.join('\n'); + expect(rendered).toContain('output did not contain "READY"'); + expect(rendered).toContain('nothing staged in the declared scope'); + }); + it('renders an agent step’s transcript: session header, prose, one line per tool call, footer', async () => { const server = wholeCloud(); const out = io(); diff --git a/packages/sdk/tests/step-attempt-history.test.ts b/packages/sdk/tests/step-attempt-history.test.ts index 12c3e4699..98609d11d 100644 --- a/packages/sdk/tests/step-attempt-history.test.ts +++ b/packages/sdk/tests/step-attempt-history.test.ts @@ -144,25 +144,83 @@ describe('attempt history in a retried step failure', () => { expect(diagnostic.message).toContain('(excerpt truncated)'); }); - it('sees a changed gate verdict behind identical process output', async () => { + it('shows the changed gate verdict behind identical process output', async () => { const output = captured(1, 'build failed'); const gate = (detail: string) => ({ gate: 'exit_code+output_contains', verdict: 'fail', detail }); const { diagnostic } = await diagnose([[ completed({ seq: 1, attempt: 1, disposition: 'retry', output, - verification: gate('exit_code: expected 0, got 1'), + verification: gate('output did not contain "done"'), }), completed({ seq: 2, attempt: 2, reason: 'retries_exhausted', output, - verification: gate('output_contains: missing "done"'), + verification: gate('JSON schema rejected output: 123 is not of type "string"'), }), ]]); - // The render is suppressed for display because the output is process - // shaped — it is still read for the comparison. - expect(diagnostic.attempts![0]).not.toHaveProperty('detail'); + // The verdict is the only thing that changed, so it is the only account of + // why these two attempts were not the same failure. Suppressing it because + // `output` happened to be process-shaped left the message asserting the + // evidence differs while printing two identical-looking attempts. + expect(diagnostic.attempts![0]).toMatchObject({ detail: 'output did not contain "done"' }); + expect(diagnostic.message).toContain('detail: output did not contain "done"'); + expect(diagnostic.message).toContain('detail: JSON schema rejected output:'); expect(diagnostic.attemptEvidence).toBe('differs'); }); + it('rejects a first attempt on a gate alone and still names the reason', async () => { + // The shape that hid a first error even with the history in place: the + // gate refused output the command produced happily, so that attempt's + // process report is exit 0 with empty tails and the verdict is the whole + // diagnosis. The retry then failed for an entirely different reason. + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, disposition: 'retry', output: captured(0, ''), + verification: { + gate: 'output_contains', verdict: 'fail', detail: 'output did not contain "READY"', + }, + }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output: captured(1, NOTHING_STAGED), + verification: { + gate: 'exit_code+output_contains', verdict: 'fail', + detail: 'exit code was 1; output did not contain "READY"', + }, + }), + ]]); + expect(diagnostic.attempts![0]).toMatchObject({ + attempt: 1, exitCode: 0, detail: 'output did not contain "READY"', + }); + // Both actual errors, each attributed to the attempt that produced it. + expect(diagnostic.message).toContain( + ' attempt 1: verification_failed exit=0 — detail: output did not contain "READY"'); + expect(diagnostic.message).not.toContain('no failure evidence recorded'); + expect(diagnostic.message).toContain(NOTHING_STAGED); + expect(diagnostic.attemptEvidence).toBe('differs'); + }); + + it('prints an account the process report already made exactly once', async () => { + // Two shapes restate what is printed beside them: the `exit_code` gate's + // bare verdict (verify.rs), and the daemon's JSON render of a worker + // failure (`worker_failure_detail`), which a deterministic step journals + // beside the preserved output that render was made from. + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, disposition: 'retry', output: captured(1, REJECTION), + verification: { gate: 'exit_code', verdict: 'fail', detail: 'exit code was 1' }, + }), + completed({ + seq: 2, attempt: 2, reason: 'worker_error', output: captured(1, NOTHING_STAGED), + verification: render(NOTHING_STAGED), + }), + ]]); + expect(diagnostic.attempts![0]).not.toHaveProperty('detail'); + expect(diagnostic.attempts![1]).not.toHaveProperty('detail'); + expect(diagnostic.message) + .toContain(`attempt 1: verification_failed exit=1 — stderr: ${REJECTION}`); + expect(diagnostic.message).toContain(`attempt 2: worker_error exit=1 — stderr: ${NOTHING_STAGED}`); + expect(diagnostic.message).not.toContain('exit code was 1'); + }); + it('keeps stdout when stderr is empty rather than reporting nothing', async () => { const { diagnostic } = await diagnose([[ completed({ @@ -244,6 +302,24 @@ describe('attempt history in a retried step failure', () => { expect(diagnostic.message).toContain('attempt ?: crashed — no failure evidence recorded'); }); + it('does not call a missing account a changed cause', async () => { + // One attempt journaled nothing and the next journaled an error. The + // records are not equal, but an attempt that said nothing about why it + // failed cannot establish that the causes differ — and `differs` carries + // "an earlier attempt may have had side effects", which this does not + // support. The attempt is still listed; only the verdict is withheld. + const { diagnostic } = await diagnose([[ + completed({ seq: 1, attempt: 1, reason: 'crashed', disposition: 'retry' }), + completed({ + seq: 2, attempt: 2, reason: 'retries_exhausted', output: captured(1, NOTHING_STAGED), + }), + ]]); + expect(diagnostic.attemptEvidence).toBe('unknown'); + expect(diagnostic.message).toContain('whether the causes differ is unknown'); + expect(diagnostic.message).not.toContain('side effects'); + expect(diagnostic.attempts).toMatchObject([{ attempt: 1 }, { attempt: 2 }]); + }); + it('records a parked attempt as a failure of that attempt', async () => { const { diagnostic } = await diagnose([[ completed({ seq: 1, attempt: 1, disposition: 'park', output: captured(1, REJECTION) }), From c997e3189cac93b6ce07623c6a1282e7adb3d300 Mon Sep 17 00:00:00 2001 From: Relayflow Date: Sun, 20 Sep 2026 17:57:46 +0000 Subject: [PATCH 3/4] test: pin the live-kernel attempt line whole, not just its stderr MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Asserting only that the first rejection appears left the rest of the line free to say anything. Against the real daemon a deterministic step's verdict is `exit code was 1` — the same number printed two words to its left — so pinning the whole line is what proves the suppression rule fires end to end rather than only over hand-built journal entries. --- packages/sdk/tests/retried-step-failure.test.ts | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/packages/sdk/tests/retried-step-failure.test.ts b/packages/sdk/tests/retried-step-failure.test.ts index acf3c5a11..36e7677ae 100644 --- a/packages/sdk/tests/retried-step-failure.test.ts +++ b/packages/sdk/tests/retried-step-failure.test.ts @@ -53,8 +53,12 @@ steps: { attempt: 2, disposition: 'step_done', exitCode: 1, stderrTail: NOTHING_STAGED }, ]); // The account of what actually went wrong is in the rendered message, not - // only in a field a machine reader has to know to ask for. - expect(diagnostic.message).toContain(REJECTION); + // only in a field a machine reader has to know to ask for. The line is + // pinned whole: the real kernel journals `exit code was 1` as this step's + // verdict, which is the exit code printed two words to its left, so it is + // the one account the attempt does NOT repeat. + expect(diagnostic.message) + .toContain(` attempt 1: verification_failed exit=1 — stderr: ${REJECTION}`); expect(diagnostic.message).toContain('An earlier attempt may have had side effects.'); // The kernel journals each attempt's own captured output. Nothing above is From 66c1a458f6533f638c24a29c450dcaf8a59c4e69 Mon Sep 17 00:00:00 2001 From: khaliqgant Date: Tue, 22 Sep 2026 22:44:22 -0700 Subject: [PATCH 4/4] fix(sdk): honor transcript failure truncation before unchanged verdict --- packages/sdk/src/cli/step-evidence.ts | 5 ++- .../sdk/tests/step-attempt-history.test.ts | 43 +++++++++++++++++++ 2 files changed, 47 insertions(+), 1 deletion(-) diff --git a/packages/sdk/src/cli/step-evidence.ts b/packages/sdk/src/cli/step-evidence.ts index 4d4408767..480711af2 100644 --- a/packages/sdk/src/cli/step-evidence.ts +++ b/packages/sdk/src/cli/step-evidence.ts @@ -204,7 +204,10 @@ export function failureCause( recorded: exitCodes.length > 0 || accounts.some(account => account !== undefined), producerTruncated: (verificationDetail !== undefined && PRODUCER_TRUNCATED.test(verificationDetail)) - + // The transcript digest's own flag (`boundTranscriptDigest`, + // agent-transcript.ts): the worker already cut this excerpt, so equal + // survivors cannot establish identical failures either. + || failure?.['truncated'] === true, }; } diff --git a/packages/sdk/tests/step-attempt-history.test.ts b/packages/sdk/tests/step-attempt-history.test.ts index 766fa6bbc..845694090 100644 --- a/packages/sdk/tests/step-attempt-history.test.ts +++ b/packages/sdk/tests/step-attempt-history.test.ts @@ -287,6 +287,49 @@ describe('attempt history in a retried step failure', () => { expect(diagnostic.message).toContain('whether the causes differ is unknown'); }); + it('honors the transcript digest truncation flag before calling excerpts unchanged', async () => { + // `boundTranscriptDigest` (agent-transcript.ts) marks an excerpt it cut + // with `failure.truncated`. Two different tool errors reduced to the same + // surviving bytes are then evidence that cannot establish `unchanged` — + // the flag says so even when the daemon's own render shows no suffix. + const shared = 'shared diagnostic context '.repeat(30); + const transcript = { + transcript: { failure: { kind: 'tool_result', excerpt: shared, truncated: true } }, + }; + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, reason: 'worker_error', disposition: 'retry', + verification: render('x'), trajectory: transcript, + }), + completed({ + seq: 2, attempt: 2, reason: 'worker_error', + verification: render('x'), trajectory: transcript, + }), + ]], AGENT); + expect(diagnostic.attemptEvidence).toBe('unknown'); + expect(diagnostic.message).toContain('whether the causes differ is unknown'); + expect(diagnostic.message).not.toContain('unchanged across them'); + }); + + it('still calls surviving differences in truncated excerpts different', async () => { + // Truncation only hides what was cut; two excerpts that already disagree + // in the surviving bytes still prove the causes disagreed. + const transcript = (excerpt: string) => ({ + transcript: { failure: { kind: 'tool_result', excerpt, truncated: true } }, + }); + const { diagnostic } = await diagnose([[ + completed({ + seq: 1, attempt: 1, reason: 'worker_error', disposition: 'retry', + verification: render('x'), trajectory: transcript('first tool error'), + }), + completed({ + seq: 2, attempt: 2, reason: 'worker_error', + verification: render('x'), trajectory: transcript('second tool error'), + }), + ]], AGENT); + expect(diagnostic.attemptEvidence).toBe('differs'); + }); + it('names the attempts it cannot account for instead of inventing evidence', async () => { const { diagnostic } = await diagnose([[ completed({ seq: 1, reason: 'crashed', disposition: 'retry' }),