diff --git a/docs/SURFACE.md b/docs/SURFACE.md index 8b98dad6f..3d21ebb4c 100644 --- a/docs/SURFACE.md +++ b/docs/SURFACE.md @@ -796,15 +796,44 @@ uses the opening shown here; an authored child failure opens with FAILED [step_failed] Run "" failed with completionReason: step_failed. Step "" () completionReason: attempt=/ exit=. Detail: -Stdout (last 1,024 bytes): - -Stderr (last 1,024 bytes): - +Stdout (captured excerpt): + +Stderr (captured excerpt): + Transcript: Inspect: flows replay --at Journal: /runs/.sqlite3 ``` +An excerpt is at most 4,096 UTF-8 bytes of the stream the journal carried. A +stream that fits is printed whole and carries no marker; one that does not is +printed as a head, the lines from the elided middle that match a built-in +failure marker (TAP `not ok`, `FAIL`/`FAILED`, a vitest or jest failure glyph, +cargo's `... FAILED` and `---- stdout ----` headings, and Rust's +`panicked at`), and a tail — with the elision stated in band: + +```text +Stdout (captured excerpt): +TAP version 13 +ok 1 - pty: spawns +… 61,204 bytes elided; 2 lines matched a failure marker … +not ok 5 - pty-exit: child reaped twice +not ok 9 - pty-exit: fd leak +… end of elided region … +1..14 +# tests 14 +# fail 2 +``` + +The markers are hints, not a parser: an unrecognised format still gets head and +tail context, and prose can match one. Two limits bound what any excerpt can +show. The absence of an elision marker means the field the journal carried fit +whole, not that the command printed nothing more: a deterministic step's +capture is itself the last 64 KiB of each stream, and an `agent` or `llm` +step's evidence survives only as the daemon's bounded render in +`verification.detail`. A failure printed before those windows is not in the +journal to be excerpted. + 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`, diff --git a/packages/sdk/src/cli/step-excerpt.ts b/packages/sdk/src/cli/step-excerpt.ts new file mode 100644 index 000000000..b3b6d0656 --- /dev/null +++ b/packages/sdk/src/cli/step-excerpt.ts @@ -0,0 +1,332 @@ +/** + * One captured stream, cut to something a terminal can print WITHOUT throwing + * away the line that says what failed. + * + * The render this replaces kept the last 1,024 bytes. For any runner that + * streams results and prints its summary last — TAP (`node --test`), cargo, + * vitest, pytest — the last kilobyte is by construction the totals and the + * final few passing cases, so the one `not ok` was always the part that got + * cut. A report that proves a failure happened and withholds which one costs + * the reader a local re-run, which is the loop the gate exists to avoid. + * + * So the excerpt is three disjoint ranges of the same source, in source order: + * a head, the lines in the elided middle that look like a failing case, and a + * tail. The elision is stated in band, in bytes, so the reader is never left + * guessing whether what they are looking at is all of it. + * + * What this can and cannot promise: + * + * - It selects from the field the journal carried, which for a deterministic + * step is the last 64 KiB the kernel captured (`OUTPUT_TAIL_BYTES`, + * relayflowd/src/exec_det.rs). A failure printed before that window is not + * here to be found, and no marker can say so — hence `captured excerpt` + * rather than a claim about the command's whole output. + * - The absence of an elision marker means the supplied field fit whole. It + * does not mean the command printed nothing more. + * - The markers are hints, not a parser. They find the common runners' failing + * lines; ordinary prose can match one, and an unknown format matches none + * and still gets head-and-tail context. + */ + +/** Default excerpt budget, in UTF-8 bytes, for one captured stream. */ +export const EXCERPT_BYTES = 4_096; + +/** + * Below this there is no room to both elide and say so, and an excerpt that + * silently drops the claim it makes about itself is the bug being fixed. The + * budget is a constant of this module, not configuration, so a caller that + * asks for less has made a programming error and is told at the call. + */ +export const MIN_EXCERPT_BYTES = 256; + +/** How many matched lines the elided middle may contribute. */ +const MAX_HIGHLIGHT_LINES = 20; + +/** A highlight cut short is only worth showing if some of the line survives. */ +const MIN_HIGHLIGHT_BYTES = 24; + +/** Newlines this module inserts between ranges and markers. */ +const SEPARATOR_RESERVE = 16; + +const END_MARKER = '… end of elided region …'; +const TRUNCATED_MARKER = '… line truncated …'; + +/** + * Lines that name a failing case, for the runners this repo actually runs. + * + * Each is anchored after optional indentation (nested TAP indents its + * subtests) and is matched against a comparison view of the line with + * terminal escapes removed, so a coloured `FAIL` header still matches. They + * are constants rather than user input, which is why `RegExp` is correct + * here; a spec-supplied pattern would be untrusted and would have to go + * through `re2js`. + */ +const FAILURE_MARKERS: readonly RegExp[] = [ + /^\s*not ok\b/u, // TAP: node --test, prove + /^\s*FAILED\b/u, // pytest short test summary: `FAILED tests/x.py::y - ...` + /^\s*FAIL\b/u, // vitest / jest file header: `FAIL src/x.test.ts` + /^\s*[✖✗×]\s/u, // vitest / jest failure glyph + /\.\.\.\s*FAILED\b/u, // cargo: `test pty::exit ... FAILED` + /^\s*---- .* ----\s*$/u, // cargo: `---- pty::exit stdout ----` + /\bpanicked at\b/u, // rust panic +]; + +interface Range { start: number; end: number } + +/** + * Cut `value` to at most `budget` UTF-8 bytes, markers included. + * + * A stream that already fits is returned whole (sanitised) with no marker. One + * that does not keeps a head of whole lines, up to `MAX_HIGHLIGHT_LINES` + * matched lines from the elided middle, and a tail that fills what is left. + * Every cut is at a code-point boundary, so slicing never invents a U+FFFD. + */ +export function formatStepExcerpt(value: string, budget: number = EXCERPT_BYTES): string { + if (!Number.isSafeInteger(budget) || budget < MIN_EXCERPT_BYTES) { + throw new Error(`step excerpt budget must be an integer of at least ${MIN_EXCERPT_BYTES} bytes`); + } + const source = Buffer.from(value, 'utf8'); + // Sanitised from the original string, not from the round trip: a lone + // surrogate the wire delivered is the caller's to keep, and re-encoding it + // would be this module inventing a replacement character. + if (source.length <= budget) return sanitise(value); + + const lines = lineRanges(source); + const matches = lines.filter(isFailureLine(source)); + // Content space is what is left after the markers can be afforded at their + // widest, so the excerpt can always state its own elision. + const content = Math.max(0, budget - markerReserve(source.length, matches.length)); + const tailShare = Math.floor(content / 2); + const headShare = Math.floor(content / 4); + const highlightShare = content - tailShare - headShare; + + const head = headRange(source, lines, headShare); + // Provisional tail, which with the head defines the middle the highlights + // are drawn from. + const highlights = selectHighlights(source, matches, highlightShare, + head.end, tailRange(source, tailShare, head.end).start); + + // Every byte the head and the highlights did not need goes to the tail, + // which is where a runner puts the summary. The tail may not cross the last + // highlight, so the ranges stay disjoint and in source order. + const spare = headShare - size(head) + + highlightShare - highlights.reduce((sum, highlight) => sum + size(highlight.range), 0); + let tail = tailRange(source, tailShare + spare, highlights.at(-1)?.range.end ?? head.end); + // A highlight the tail resumes at the very byte it ends is not a range of + // its own: the two are one unbroken run of source, so the tail starts at + // the highlight instead. The same bytes either way, with no marker between + // them claiming a cut the reader can see did not happen. + while (highlights.length > 0 && highlights.at(-1)!.range.end === tail.start) { + tail = { start: highlights.pop()!.range.start, end: tail.end }; + } + + const selected = [head, ...highlights.map(highlight => highlight.range), tail] + .filter(range => size(range) > 0); + const elided = source.length - selected.reduce((sum, range) => sum + size(range), 0); + // Positional, not textual: two identical failing lines at two positions are + // two observations, and one of them may be visible while the other is not. + // Shown means the line's own start is on screen, because the start is what + // names the failing case: a highlight cut short still reports it, while a + // range that begins in the middle of the line — a tail whose cut landed + // there — shows only the part after the name and reports nothing. + const omitted = matches.filter(match => + !selected.some(range => range.start <= match.start && range.end > match.start)).length; + + const parts: string[] = []; + const terminated = (chunk: string): string => chunk.endsWith('\n') ? chunk : `${chunk}\n`; + if (size(head) > 0) parts.push(terminated(text(source, head))); + parts.push(`${openMarker(elided, highlights.length, omitted)}\n`); + for (const highlight of highlights) { + parts.push(terminated(text(source, highlight.range) + (highlight.truncated ? ` ${TRUNCATED_MARKER}` : ''))); + } + if (highlights.length > 0) { + if (omitted > 0) parts.push(`${moreMarker(omitted)}\n`); + parts.push(`${END_MARKER}\n`); + } + if (size(tail) > 0) parts.push(text(source, tail)); + // Sanitising replaces, never expands, so it cannot push the result over the + // budget; the clamp is where the byte bound is enforced, for every path. + return clampBytes(sanitise(parts.join('')), budget); +} + +/** + * `N bytes elided` counts raw source bytes represented by no selected range, + * including the omitted portion of a line shown only in part. Source bytes + * shown plus source bytes elided is the input, exactly; the markers this + * module inserts are not source bytes, and sanitising can shrink what is + * displayed without changing what was selected. + */ +function openMarker(elided: number, shown: number, omitted: number): string { + const matched = shown > 0 + ? `; ${plural(shown, 'line')} matched a failure marker` + : omitted > 0 ? `; ${plural(omitted, 'line')} matched a failure marker, none shown` : ''; + return `… ${group(elided)} bytes elided${matched} …`; +} + +function moreMarker(omitted: number): string { + return `… +${group(omitted)} more matching ${omitted === 1 ? 'line' : 'lines'} …`; +} + +/** Every marker at its widest, so content space can be assigned once. */ +function markerReserve(sourceBytes: number, matches: number): number { + const open = Math.max( + byteLength(openMarker(sourceBytes, matches, matches)), + byteLength(openMarker(sourceBytes, 0, matches)), + byteLength(openMarker(sourceBytes, 0, 0)), + ); + const highlighted = matches === 0 ? 0 + : byteLength(moreMarker(matches)) + byteLength(END_MARKER) + byteLength(TRUNCATED_MARKER) + 1; + return open + highlighted + SEPARATOR_RESERVE; +} + +/** + * Matched lines from the middle, in source order, bounded by both the line cap + * and the byte share. A whole line is preferred; when the first candidate does + * not fit at all, a code-point-safe prefix of it is shown under a truncation + * marker, because a cut failing line still names the failing case and no + * highlight at all does not. + * + * The middle ends where the tail begins, but a line the tail begins in the + * middle of belongs to the middle: the tail shows its tail, and the marker + * that names the failing case is ahead of the cut. Such a line is a candidate + * like any other, and the caller keeps the ranges disjoint by starting the + * tail after whatever prefix is kept. + */ +function selectHighlights( + source: Buffer, matches: readonly Range[], share: number, from: number, to: number, +): Array<{ range: Range; truncated: boolean }> { + const selected: Array<{ range: Range; truncated: boolean }> = []; + let remaining = share; + for (const match of matches) { + // Reported once, at its own position: a line whose own start is already + // on screen — inside the head, or at or after the start of the tail — + // needs no highlight. + if (match.start < from || match.start >= to) continue; + if (selected.length >= MAX_HIGHLIGHT_LINES) break; + if (size(match) <= remaining) { + selected.push({ range: match, truncated: false }); + remaining -= size(match); + continue; + } + if (selected.length === 0 && remaining >= MIN_HIGHLIGHT_BYTES) { + const end = floorBoundary(source, match.start + remaining); + if (end > match.start) selected.push({ range: { start: match.start, end }, truncated: true }); + } + break; + } + return selected; +} + +/** + * Whole lines from the start, or a bounded prefix when the first line alone is + * longer than the share — a long first line must not consume the excerpt. + * Whatever whole lines leave unspent is returned to the tail by the caller. + */ +function headRange(source: Buffer, lines: readonly Range[], limit: number): Range { + let end = 0; + for (const line of lines) { + if (line.end > limit) break; + end = line.end; + } + return { start: 0, end: end === 0 ? floorBoundary(source, limit) : end }; +} + +/** + * The last `limit` bytes, cut at a code-point boundary and never crossing + * `stop` (the end of the head or of the last highlight). + * + * Unlike the head, the tail fills its share rather than stopping at a line + * boundary. A stream can be one enormous line followed by a one-byte last + * line; taking whole lines only would spend one byte of a two-kilobyte share + * and drop the summary that the old last-1,024-bytes render always kept. + */ +function tailRange(source: Buffer, limit: number, stop: number): Range { + return { start: Math.max(ceilBoundary(source, source.length - limit), stop), end: source.length }; +} + +function isFailureLine(source: Buffer): (line: Range) => boolean { + return line => { + const comparable = comparableLine(text(source, line)); + return FAILURE_MARKERS.some(marker => marker.test(comparable)); + }; +} + +/** + * The view a marker is matched against: terminal escape sequences and control + * characters removed so a coloured `not ok` or `FAIL` header still matches. + * This never touches what is rendered — journal data is not mutated, and the + * display sanitiser is a separate, later step. + */ +function comparableLine(line: string): string { + return line + .replace(/\u001b\[[0-9;:?]*[ -/]*[@-~]|\u001b[@-Z\\-_]|\u009b[0-9;:?]*[ -/]*[@-~]/gu, '') + .replace(/[\p{Cc}\p{Cf}]/gu, character => character === '\t' ? ' ' : ''); +} + +/** Line ranges over the raw bytes; each end includes its own `\n` when it has one. */ +function lineRanges(source: Buffer): Range[] { + const ranges: Range[] = []; + let start = 0; + for (let index = 0; index < source.length; index++) { + if (source[index] === 0x0a) { + ranges.push({ start, end: index + 1 }); + start = index + 1; + } + } + if (start < source.length) ranges.push({ start, end: source.length }); + return ranges; +} + +/** + * Preserve tabs and newlines; replace binary controls (including ESC and CR), + * C1 controls and Unicode formatting controls without growing the excerpt. + * Applied on every path, short inputs included: a control sequence in a + * two-line stderr is as able to rewrite the terminal as one in a long stream. + */ +function sanitise(value: string): string { + return value.replace(/[\p{Cc}\p{Cf}]/gu, character => + character === '\n' || character === '\t' ? character : '?'); +} + +function clampBytes(value: string, budget: number): string { + const bytes = Buffer.from(value, 'utf8'); + if (bytes.length <= budget) return value; + return bytes.subarray(0, floorBoundary(bytes, budget)).toString('utf8'); +} + +function text(source: Buffer, range: Range): string { + return source.subarray(range.start, range.end).toString('utf8'); +} + +function size(range: Range): number { + return range.end - range.start; +} + +function isBoundary(source: Buffer, index: number): boolean { + return index >= source.length || (source[index]! & 0xc0) !== 0x80; +} + +function floorBoundary(source: Buffer, index: number): number { + let at = Math.max(0, Math.min(index, source.length)); + while (at > 0 && !isBoundary(source, at)) at -= 1; + return at; +} + +function ceilBoundary(source: Buffer, index: number): number { + let at = Math.max(0, Math.min(index, source.length)); + while (at < source.length && !isBoundary(source, at)) at += 1; + return at; +} + +function byteLength(value: string): number { + return Buffer.byteLength(value, 'utf8'); +} + +function plural(count: number, noun: string): string { + return `${group(count)} ${noun}${count === 1 ? '' : 's'}`; +} + +/** Locale-independent digit grouping: the same excerpt everywhere it is read. */ +function group(value: number): string { + return String(value).replace(/\B(?=(\d{3})+(?!\d))/gu, ','); +} diff --git a/packages/sdk/src/cli/step-failure.ts b/packages/sdk/src/cli/step-failure.ts index d04e10ba1..5e8187639 100644 --- a/packages/sdk/src/cli/step-failure.ts +++ b/packages/sdk/src/cli/step-failure.ts @@ -2,8 +2,7 @@ import { join } from 'node:path'; import { DEFAULT_DATA_DIR } from '../daemon-connection.js'; import type { StepFailedDetails } from '../failure-kinds.js'; import type { JournalClient } from '../journal-client.js'; - -const TAIL_BYTES = 1_024; +import { formatStepExcerpt } from './step-excerpt.js'; /** * Read what a failed step left in the journal — for any step type. @@ -117,8 +116,8 @@ export function renderStepEvidence(details: StepFailedDetails): string { + (details.exitCode === undefined ? '' : ` exit=${details.exitCode}`) + '.' + (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}` : '') + + (details.stdoutTail ? `\nStdout (captured excerpt):\n${details.stdoutTail}` : '') + + (details.stderrTail ? `\nStderr (captured excerpt):\n${details.stderrTail}` : '') + (details.transcriptPath === undefined ? '' : `\nTranscript: ${details.transcriptPath}`); } @@ -195,22 +194,22 @@ function evidence(payload: Record): Partial const structuredShape = structured !== undefined && processShaped(structured); const transcript = record(record(payload['trajectory_tail'])?.['transcript']); const failure = record(transcript?.['failure']); - const excerpt = failure?.['excerpt']; + const failureExcerpt = 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 + const excerptDetail = typeof failureExcerpt === 'string' && failureExcerpt.length > 0 && !(failure?.['kind'] === 'stderr' && typeof stderr === 'string') - ? tail(excerpt) : undefined; + ? formatStepExcerpt(failureExcerpt) : undefined; return { ...(typeof exitCode === 'number' && Number.isSafeInteger(exitCode) ? { exitCode } : {}), - ...(typeof stdout === 'string' && stdout.length > 0 ? { stdoutTail: tail(stdout) } : {}), - ...(typeof stderr === 'string' ? { stderrTail: tail(stderr) } : {}), + ...(typeof stdout === 'string' && stdout.length > 0 ? { stdoutTail: formatStepExcerpt(stdout) } : {}), + ...(typeof stderr === 'string' ? { stderrTail: formatStepExcerpt(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) } : {}), + ? { detail: formatStepExcerpt(detail) } : {}), ...(typeof transcriptPath === 'string' && transcriptPath.length > 0 ? { transcriptPath } : {}), }; } @@ -233,16 +232,6 @@ function record(value: unknown): Record | undefined { ? 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('-') diff --git a/packages/sdk/src/failure-kinds.ts b/packages/sdk/src/failure-kinds.ts index 46b704693..72f3d0af5 100644 --- a/packages/sdk/src/failure-kinds.ts +++ b/packages/sdk/src/failure-kinds.ts @@ -177,9 +177,17 @@ export interface StepFailedDetails { */ maxIterations?: number; exitCode?: number; - /** Terminal-safe UTF-8 excerpt, at most 1,024 bytes. */ + /** + * Terminal-safe UTF-8 excerpt of the captured stdout, at most + * `EXCERPT_BYTES` (cli/step-excerpt.ts). The field name is kept for + * compatibility; it is no longer a plain tail. When the captured field did + * not fit, the excerpt keeps a head, the lines from the elided middle that + * match a failure marker, and a tail, and states the elision in band. The + * absence of an elision marker means the field the journal carried fit + * whole — not that the command printed no more than this. + */ stdoutTail?: string; - /** Terminal-safe UTF-8 excerpt, at most 1,024 bytes. */ + /** Terminal-safe UTF-8 excerpt of the captured stderr; see `stdoutTail`. */ stderrTail?: string; /** * The daemon's own account when it was not a render of the fields above, or diff --git a/packages/sdk/tests/authored-node-result.test.ts b/packages/sdk/tests/authored-node-result.test.ts index 9a6e2d9d5..8b9c57528 100644 --- a/packages/sdk/tests/authored-node-result.test.ts +++ b/packages/sdk/tests/authored-node-result.test.ts @@ -1,6 +1,7 @@ import { beforeEach, describe, expect, it, vi } from 'vitest'; import { stepFailedFrame, verifyAuthoredNodeResult } from '../src/authored-node-runner.js'; import { parseAuthoredParentPid } from '../src/authored-runtime-capability.js'; +import { EXCERPT_BYTES, formatStepExcerpt } from '../src/cli/step-excerpt.js'; import type { AuthoredFlowExecutionResult } from '../src/authored-flow-executor.js'; import type { AuthoredRootMetadata } from '../src/authored-root.js'; @@ -162,6 +163,27 @@ describe('step evidence crossing the authored IPC boundary', () => { // of `{}` still marks the diagnostic as carrying evidence it does not have. expect(stepFailedFrame(frame)).toBeUndefined(); }); + it('carries a rendered excerpt across the bridge byte for byte', () => { + // The live `executeAuthoredFlow` fixture never crosses the Bun-to-Node IPC + // hop, and this is where a second, silent truncation would happen: the + // frame reader re-cuts every string field at 8,192 code units. A 4,096 + // UTF-8-byte excerpt is at most 4,096 code units, so it must survive + // whole — a cut here would land mid-marker and say nothing about it. + const lines = ['TAP version 13']; + for (let index = 1; index <= 400; index++) { + lines.push(index === 200 ? `not ok ${index} - the one that matters` + : `ok ${index} - pty: a passing case with a realistically long name`); + } + lines.push('1..400', '# fail 1'); + const stdoutTail = formatStepExcerpt(lines.join('\n') + '\n'); + expect(Buffer.byteLength(stdoutTail)).toBeGreaterThan(1_024); + expect(Buffer.byteLength(stdoutTail)).toBeLessThanOrEqual(EXCERPT_BYTES); + expect(stdoutTail).toContain('not ok 200 - the one that matters'); + + const details = stepFailedFrame({ stepId: 'run-1', stdoutTail, stderrTail: stdoutTail }); + expect(details?.stdoutTail).toBe(stdoutTail); + expect(details?.stderrTail).toBe(stdoutTail); + }); it('bounds a tail the child did not bound', () => { const details = stepFailedFrame({ stderrTail: 'x'.repeat(20_000) }); expect(details?.stderrTail).toHaveLength(8192); diff --git a/packages/sdk/tests/authored-run-failure-evidence.test.ts b/packages/sdk/tests/authored-run-failure-evidence.test.ts index 0160b9a5e..2846efec2 100644 --- a/packages/sdk/tests/authored-run-failure-evidence.test.ts +++ b/packages/sdk/tests/authored-run-failure-evidence.test.ts @@ -6,6 +6,10 @@ import { readCompletedStepOutput, readSuccessfulOutput } from '../src/authored-s import type { RunOutcome } from '../src/protocol.js'; import type { JournalClient } from '../src/journal-client.js'; import { chainFixture } from './flow-chain-fixture.js'; +import { EXCERPT_BYTES } from '../src/cli/step-excerpt.js'; + +/** The one line the report has to name, and the one the old render always cut. */ +const MARKER = 'not ok 111 - pty-exit: child process exit is detected'; const cleanup: Array<() => Promise> = []; afterEach(async () => { for (const close of cleanup.splice(0)) await close(); }); @@ -59,6 +63,68 @@ describe('a failing f.run through the live kernel', () => { expect(message).toContain('Inspect: flows replay'); }); + it('names the failing case from the middle of a real test run', async () => { + // The reported bug, end to end: kernel capture -> journal -> + // `preserve_failure_output` -> SDK render. A runner that streams results + // and prints its totals last puts `ok` lines and a summary in the final + // kilobyte by construction, so the one `not ok` was exactly the part the + // old last-1,024-bytes render cut. + const passing = (index: number) => `ok ${index} - pty: a passing case with a realistically long name`; + const expected = [ + ...Array.from({ length: 110 }, (_, index) => passing(index + 1)), + MARKER, + ...Array.from({ length: 110 }, (_, index) => passing(index + 112)), + '1..221', '# tests 221', '# pass 220', '# fail 1', + ].join('\n') + '\n'; + const stream = Buffer.from(expected, 'utf8'); + const at = Buffer.byteLength(expected.slice(0, expected.indexOf(MARKER)), 'utf8'); + // The fixture is only evidence if the failure sits where the old render + // could not reach and where head-and-tail context alone would not either: + // past the first 4 KiB, before the last 4 KiB, and inside the 64 KiB the + // kernel captures (`OUTPUT_TAIL_BYTES`, relayflowd/src/exec_det.rs). + expect(at).toBeGreaterThan(4_096); + expect(stream.length - at).toBeGreaterThan(4_096); + expect(stream.length).toBeGreaterThan(12 * 1_024); + expect(stream.length).toBeLessThan(20 * 1_024); + expect(stream.subarray(-1_024).toString('utf8')).not.toContain(MARKER); + + const fixture = chainFixture(); + cleanup.push(() => fixture.close()); + const journal = await fixture.connect(); + + const handle = flow('streamed-test-run', async (f) => { + await f.run(`i=1; while [ $i -le 110 ]; do printf 'ok %s - pty: a passing case with a realistically long name\\n' "$i"; i=$((i+1)); done +printf '${MARKER}\\n' +i=112; while [ $i -le 221 ]; do printf 'ok %s - pty: a passing case with a realistically long name\\n' "$i"; i=$((i+1)); done +printf '1..221\\n# tests 221\\n# pass 220\\n# fail 1\\n' +exit 1`); + f.done('success'); + }); + + const failure = await executeAuthoredFlow(handle, journal, undefined, { dataDir: fixture.data }) + .then(() => undefined, (error) => error as { message: string; details?: Record }); + + // The journal is the record: check the failing line is in the completion + // the kernel wrote before asking what the renderer did with it. + const childRunId = /flows replay (\S+)/u.exec(String(failure?.details?.['hint']))?.[1]; + expect(childRunId).toMatch(/^[0-9A-HJKMNP-TV-Z]{26}$/u); + const entries = (await journal.journalRead(childRunId!, 1)).entries as Array<{ + entry_type: string; payload?: { output?: { stdout_tail?: string } }; + }>; + const journaled = entries.find(entry => entry.entry_type === 'step.completed')?.payload?.output?.stdout_tail; + expect(journaled).toBe(expected); + + // And the render names it, inside its own byte bound, with the head and + // the summary still beside it. + const excerpt = String(failure?.details?.['stdoutTail']); + expect(excerpt).toContain(MARKER); + expect(excerpt).toContain('ok 1 - pty: a passing case with a realistically long name'); + expect(excerpt).toContain('# fail 1'); + expect(Buffer.byteLength(excerpt, 'utf8')).toBeLessThanOrEqual(EXCERPT_BYTES); + expect(failure?.message).toContain('Stdout (captured excerpt):'); + expect(failure?.message).toContain(MARKER); + }, 30_000); + it('carries the same facts structurally, not only rendered into the message', async () => { const fixture = chainFixture(); cleanup.push(() => fixture.close()); diff --git a/packages/sdk/tests/direct-run-failure.test.ts b/packages/sdk/tests/direct-run-failure.test.ts index 4a3b390c9..51765f0eb 100644 --- a/packages/sdk/tests/direct-run-failure.test.ts +++ b/packages/sdk/tests/direct-run-failure.test.ts @@ -40,7 +40,7 @@ it('reports an authored step failure as step_failed with a known status, not pro vi.mocked(executeDurableAuthoredFlow).mockRejectedValueOnce(new AuthoredFlowExecutionError( 'step_failed', 'Run "child-run" failed with completionReason: step_failed. Step "agent-2" (agent) ' - + 'completionReason: worker_error exit=1.\nStderr (last 1,024 bytes):\nno such model', + + 'completionReason: worker_error exit=1.\nStderr (captured excerpt):\nno such model', undefined, 'child-run', )); diff --git a/packages/sdk/tests/resume-failure.test.ts b/packages/sdk/tests/resume-failure.test.ts index 401732f2e..4750a4afa 100644 --- a/packages/sdk/tests/resume-failure.test.ts +++ b/packages/sdk/tests/resume-failure.test.ts @@ -12,7 +12,7 @@ import { PROTOCOL_VERSION } from '../src/protocol.js'; const RUN_ID = '01M2NDS2RYK3MH6YBSB1CHA9SE'; const EVIDENCE = `Run "${RUN_ID}" failed with completionReason: step_failed.` + ' Step "agent-2" (agent) completionReason: worker_error exit=1.' - + '\nStderr (last 1,024 bytes):\nclaude: permission denied: /work/out' + + '\nStderr (captured excerpt):\nclaude: permission denied: /work/out' + `\nInspect: flows replay ${RUN_ID} --at agent-2`; const directories: string[] = []; diff --git a/packages/sdk/tests/step-failure-diagnostic.test.ts b/packages/sdk/tests/step-failure-diagnostic.test.ts index 7172944e5..5241b9a15 100644 --- a/packages/sdk/tests/step-failure-diagnostic.test.ts +++ b/packages/sdk/tests/step-failure-diagnostic.test.ts @@ -5,6 +5,7 @@ import { join } from 'node:path'; import { afterEach, describe, expect, it, vi } from 'vitest'; import { runCli } from '../src/cli.js'; import { classifyOutcome, emptyReport, type RunDiagnostic, type RunReport } from '../src/cli/run.js'; +import { EXCERPT_BYTES } from '../src/cli/step-excerpt.js'; import { socketPathFor } from '../src/daemon-connection.js'; import * as daemonLifecycle from '../src/daemon-lifecycle.js'; import { JournalClient } from '../src/journal-client.js'; @@ -41,6 +42,18 @@ async function classify(client: JournalClient, outcome = failure) { return classifyOutcome(client, 'run', outcome, emptyReport('run'), '/tmp/diagnostic.sock', {}); } +/** A TAP run whose failing case is at `failing` and whose totals come last. */ +function tapRun(cases: number, failing: number): string { + const lines = ['TAP version 13']; + for (let index = 1; index <= cases; index++) { + lines.push(index === failing + ? `not ok ${index} - pty-exit: child reaped twice` + : `ok ${index} - pty: a passing case with a realistically long name`); + } + lines.push(`1..${cases}`, `# tests ${cases}`, `# pass ${cases - 1}`, '# fail 1'); + return lines.join('\n') + '\n'; +} + async function diagnosticFor(stderr: string) { const { client } = stub([[completion(1, stderr)]]); return (await classify(client)).report.diagnostics.at(-1) as RunDiagnostic; @@ -98,17 +111,78 @@ describe('step failure diagnostic', () => { } }); - it('keeps the last 1,024 bytes, not the prefix', async () => { - const diagnostic = await diagnosticFor('discarded-prefix' + 'x'.repeat(2_000) + 'last error'); - expect(diagnostic.stderrTail).toBe('x'.repeat(1_014) + 'last error'); - expect(Buffer.byteLength(diagnostic.stderrTail!)).toBe(1_024); - expect(diagnostic.message).not.toContain('discarded-prefix'); + it.each([false, true])('exposes the middle failure through the CLI itself (json=%s)', async json => { + // The unit above proves the renderer; this proves the whole CLI path, + // human and machine-readable, carries the failing case to the operator. + const dir = mkdtempSync(join(tmpdir(), 'flows-failure-')); + directories.push(dir); + writeFileSync(join(dir, 'flows.json'), '{}'); + const path = join(dir, 'tap-run.yaml'); + writeFileSync(path, 'version: "0.1.0"\nname: tap-run\nsteps:\n - id: fail-command\n type: deterministic\n command: \'node --test\'\n'); + const stream = tapRun(400, 200); + vi.spyOn(daemonLifecycle, 'ensureDaemon').mockResolvedValue({ + kind: 'attached', socketPath: socketPathFor(dir), connection: null, + }); + vi.spyOn(JournalClient.prototype, 'connect').mockResolvedValue(undefined); + vi.spyOn(JournalClient.prototype, 'hello').mockResolvedValue({ protocol: PROTOCOL_VERSION, server: 'relayflowd-test' }); + vi.spyOn(JournalClient.prototype, 'runStart').mockResolvedValue(failure); + vi.spyOn(JournalClient.prototype, 'runGet').mockResolvedValue({ + run_id: failure.run_id, status: 'failed', budget: { tokens_in: 0, tokens_out: 0, dollars: '0' }, + steps: { 'fail-command': { type: 'deterministic', state: 'done' } }, + }); + vi.spyOn(JournalClient.prototype, 'journalRead').mockImplementation(async (_runId, fromSeq) => ({ + entries: fromSeq === 1 ? [completion(1, stream, 1)] : [], + })); + const stdout: string[] = []; + const stderr: string[] = []; + const code = await runCli(['run', '--no-spawn', '--data-dir', dir, ...(json ? ['--json'] : []), path], { + stdout: line => stdout.push(line), stderr: line => stderr.push(line), + }); + expect(code).toBe(1); + const output = json ? stdout.join('\n') : stderr.join('\n'); + expect(output).toContain('not ok 200 - pty-exit: child reaped twice'); + if (json) { + const report = JSON.parse(output) as RunReport; + const diagnostic = report.diagnostics.at(-1) as RunDiagnostic; + expect(diagnostic.stderrTail).toContain('not ok 200 - pty-exit: child reaped twice'); + expect(Buffer.byteLength(diagnostic.stderrTail!)).toBeLessThanOrEqual(EXCERPT_BYTES); + } + }); + + it('keeps the head the last-1,024-bytes render discarded outright', async () => { + // This assertion is the inverse of the one it replaces, and the inversion + // is the bug: `discarded-prefix` is the head of the stream, and a render + // that could only ever show its last kilobyte threw it away. + const diagnostic = await diagnosticFor('discarded-prefix\n' + 'x\n'.repeat(4_000) + 'last error\n'); + expect(diagnostic.stderrTail).toContain('discarded-prefix'); + expect(diagnostic.stderrTail).toContain('last error'); + expect(diagnostic.stderrTail).toMatch(/… [\d,]+ bytes elided …/u); + expect(diagnostic.message).toContain('discarded-prefix'); + expect(Buffer.byteLength(diagnostic.stderrTail!)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('names the failing case from the middle of a streamed test run', async () => { + // The reported case. A runner that streams results and prints its totals + // last puts `ok` lines and a summary in the final kilobyte by + // construction, so the one `not ok` was exactly the part that got cut. + const diagnostic = await diagnosticFor(tapRun(400, 200)); + expect(diagnostic.message).toContain('Stderr (captured excerpt):'); + expect(diagnostic.message).toContain('not ok 200 - pty-exit: child reaped twice'); + expect(diagnostic.message).toContain('# fail 1'); + expect(diagnostic.message).toContain('TAP version 13'); + }); + + it('returns a stream that fits whole, so no marker means no elision', async () => { + const stream = tapRun(14, 5); + expect(Buffer.byteLength(stream)).toBeLessThan(EXCERPT_BYTES); + const diagnostic = await diagnosticFor(stream); + expect(diagnostic.stderrTail).toBe(stream); + expect(diagnostic.stderrTail).not.toContain('elided'); }); it('truncates at UTF-8 boundaries without splitting multibyte characters', async () => { - const diagnostic = await diagnosticFor('🙂'.repeat(400) + 'é'); - expect(diagnostic.stderrTail).toBe('🙂'.repeat(255) + 'é'); - expect(Buffer.byteLength(diagnostic.stderrTail!)).toBeLessThanOrEqual(1_024); + const diagnostic = await diagnosticFor('🙂'.repeat(2_000) + 'é'); + expect(Buffer.byteLength(diagnostic.stderrTail!)).toBeLessThanOrEqual(EXCERPT_BYTES); expect(diagnostic.stderrTail).not.toContain('\ufffd'); }); @@ -117,7 +191,7 @@ describe('step failure diagnostic', () => { const diagnostic = await diagnosticFor(binary.repeat(1_000) + '\u009b31m\u202eEND\n\t'); expect(diagnostic.stderrTail).toMatch(/END\n\t$/); expect(diagnostic.stderrTail).not.toMatch(/[\x00-\x08\x0b-\x1f\x7f-\x9f\p{Cf}]/u); - expect(Buffer.byteLength(diagnostic.stderrTail!)).toBeLessThanOrEqual(1_024); + expect(Buffer.byteLength(diagnostic.stderrTail!)).toBeLessThanOrEqual(EXCERPT_BYTES); }); it('includes an empty stderr field for a silent nonzero exit', async () => { diff --git a/packages/sdk/tests/step-failure-excerpt.test.ts b/packages/sdk/tests/step-failure-excerpt.test.ts new file mode 100644 index 000000000..29a020178 --- /dev/null +++ b/packages/sdk/tests/step-failure-excerpt.test.ts @@ -0,0 +1,302 @@ +import { describe, expect, it } from 'vitest'; +import { EXCERPT_BYTES, MIN_EXCERPT_BYTES, formatStepExcerpt } from '../src/cli/step-excerpt.js'; + +/** Every marker this module prints is a line of its own, fenced by `…`. */ +const MARKER = /^… .* …$/u; + +function bytes(value: string): number { + return Buffer.byteLength(value, 'utf8'); +} + +/** + * The bytes of the source that the excerpt actually shows. + * + * Only valid for a fixture of non-empty, newline-terminated, control-free + * lines: then every content line of the output is a whole source line, worth + * its own bytes plus the `\n` the split removed. + */ +function shownBytes(output: string): number { + return output.split('\n') + .filter((line, index, all) => !MARKER.test(line) && !(line === '' && index === all.length - 1)) + .reduce((sum, line) => sum + bytes(line) + 1, 0); +} + +function elidedBytes(output: string): number { + const stated = /… ([\d,]+) bytes elided/u.exec(output); + expect(stated).not.toBeNull(); + return Number(stated![1]!.replaceAll(',', '')); +} + +/** The reported case: a `not ok` early in a stream whose summary is last. */ +function tapStream(cases: number, failing: readonly number[]): string { + const lines = ['TAP version 13']; + for (let index = 1; index <= cases; index++) { + lines.push(failing.includes(index) + ? `not ok ${index} - pty-exit: child reaped twice` + : `ok ${index} - pty: a passing case with a realistically long name`); + } + lines.push(`1..${cases}`, `# tests ${cases}`, `# pass ${cases - failing.length}`, `# fail ${failing.length}`); + return lines.join('\n') + '\n'; +} + +describe('formatStepExcerpt: what it keeps', () => { + it('returns a stream that fits whole, and says nothing about elision', () => { + const stream = tapStream(14, [5]); + expect(bytes(stream)).toBeLessThan(EXCERPT_BYTES); + const excerpt = formatStepExcerpt(stream); + expect(excerpt).toBe(stream); + expect(excerpt).not.toMatch(/elided/u); + }); + + it.each([ + ['an empty stream', ''], + ['a single line with no newline', 'boom on stderr'], + ['a stream of exactly the budget', 'x'.repeat(EXCERPT_BYTES - 1) + '\n'], + ])('returns %s unchanged', (_label, stream) => { + expect(formatStepExcerpt(stream)).toBe(stream); + }); + + it('elides one byte over the budget, and stays within it', () => { + const excerpt = formatStepExcerpt('x'.repeat(EXCERPT_BYTES) + '\n'); + expect(excerpt).toMatch(/… [\d,]+ bytes elided …/u); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('shows the failing case that the old last-1,024-bytes tail always cut', () => { + // The reported case, scaled until it no longer fits and with the failing + // case where a streaming runner leaves it — past the head, well before + // the summary. Every byte of the last kilobyte of this stream is `ok` or + // a total. + const stream = tapStream(400, [200]); + expect(bytes(stream)).toBeGreaterThan(EXCERPT_BYTES); + expect(Buffer.from(stream, 'utf8').subarray(-1_024).toString('utf8')) + .not.toContain('not ok 200'); + + const excerpt = formatStepExcerpt(stream); + expect(excerpt).toContain('not ok 200 - pty-exit: child reaped twice'); + // Head, marker and tail are all still there: the failing line arrives with + // the run's opening and its summary, not instead of them. + expect(excerpt).toContain('TAP version 13'); + expect(excerpt).toContain('# fail 1'); + expect(excerpt).toMatch(/… [\d,]+ bytes elided; 1 line matched a failure marker …/u); + expect(excerpt).toContain('… end of elided region …'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('keeps the head, which the tail-only render discarded outright', () => { + const excerpt = formatStepExcerpt('discarded-prefix\n' + 'x\n'.repeat(4_000) + 'last error\n'); + expect(excerpt.startsWith('discarded-prefix\n')).toBe(true); + expect(excerpt.endsWith('last error\n')).toBe(true); + }); + + it('accounts for every source byte: shown plus elided is the input', () => { + const stream = tapStream(400, [200, 210]); + const excerpt = formatStepExcerpt(stream); + expect(shownBytes(excerpt) + elidedBytes(excerpt)).toBe(bytes(stream)); + }); +}); + +describe('formatStepExcerpt: which lines it highlights', () => { + it.each([ + ['TAP', 'not ok 13 - pty-exit: child process exit is detected'], + ['indented TAP subtests', ' not ok 2 - nested subtest'], + ['pytest', 'FAILED tests/test_pty.py::test_exit - assert 1 == 0'], + ['vitest file headers', ' FAIL tests/pty-exit.test.ts > exit is detected'], + ['vitest failure glyphs', ' × pty-exit: child process exit is detected'], + ['cargo case results', 'test pty::exit::child_is_reaped ... FAILED'], + ['cargo failure headings', '---- pty::exit::child_is_reaped stdout ----'], + ['rust panics', "thread 'main' panicked at kernel/src/lib.rs:41:9:"], + ['ANSI-coloured headers', '\u001b[31m FAIL \u001b[39m tests/pty-exit.test.ts'], + ])('recognises a %s failure line from anywhere in the stream', (_runner, line) => { + const filler = 'ok - a passing case with a realistically long name\n'; + const excerpt = formatStepExcerpt(filler.repeat(40) + line + '\n' + filler.repeat(120)); + // The ANSI case is matched on an escape-stripped view but rendered through + // the display sanitiser, so compare on what survives sanitising. + expect(excerpt).toContain(line.replaceAll(/[\p{Cc}\p{Cf}]/gu, '?')); + expect(excerpt).toMatch(/1 line matched a failure marker/u); + }); + + it('gives an unrecognised format head and tail context without claiming a match', () => { + const excerpt = formatStepExcerpt('first line\n' + 'noise\n'.repeat(2_000) + 'last line\n'); + expect(excerpt).toContain('first line'); + expect(excerpt).toContain('last line'); + expect(excerpt).toMatch(/^… [\d,]+ bytes elided …$/mu); + expect(excerpt).not.toContain('failure marker'); + expect(excerpt).not.toContain('… end of elided region …'); + }); + + it('does not repeat a failure that is already visible in the head or the tail', () => { + const filler = 'ok - a passing case with a realistically long name\n'; + const stream = 'not ok 1 - in the head\n' + filler.repeat(200) + 'not ok 999 - in the tail\n'; + const excerpt = formatStepExcerpt(stream); + expect(excerpt.split('not ok 1 - in the head')).toHaveLength(2); + expect(excerpt.split('not ok 999 - in the tail')).toHaveLength(2); + // Both are shown at their own position, so neither is reported as omitted. + expect(excerpt).not.toContain('more matching lines'); + }); + + it('treats two identical failing lines at two positions as two observations', () => { + const filler = 'ok - a passing case with a realistically long name\n'; + const repeated = 'not ok 7 - the same name twice\n'; + const excerpt = formatStepExcerpt( + filler.repeat(40) + repeated + filler.repeat(40) + repeated + filler.repeat(120)); + expect(excerpt.split(repeated.trimEnd())).toHaveLength(3); + expect(excerpt).toMatch(/2 lines matched a failure marker/u); + }); + + it('caps the highlights at twenty lines and counts the rest', () => { + const filler = 'ok - a passing case with a realistically long name\n'; + const failures = Array.from({ length: 50 }, (_, index) => `not ok ${index + 1} - middle failure\n`).join(''); + const excerpt = formatStepExcerpt(filler.repeat(40) + failures + filler.repeat(200)); + expect(excerpt.match(/^not ok /gmu)).toHaveLength(20); + expect(excerpt).toMatch(/20 lines matched a failure marker/u); + expect(excerpt).toContain('… +30 more matching lines …'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('shows part of a failing line too long to fit, and says it was cut', () => { + const filler = 'ok - a passing case with a realistically long name\n'; + const excerpt = formatStepExcerpt( + filler.repeat(40) + 'not ok 5 - ' + 'D'.repeat(8_000) + '\n' + filler.repeat(120)); + expect(excerpt).toContain('not ok 5 - DDDD'); + expect(excerpt).toContain('… line truncated …'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('names a failing case that the tail cut lands in the middle of', () => { + // The tail is cut at a byte offset, not at a line boundary. A failing + // line longer than the tail's share therefore keeps its uninformative + // rest on screen while its marker and its name sit ahead of the cut — + // the reported bug, one layout further in. + const failure = 'not ok 5 - pty-exit: child reaped twice'; + const stream = 'ok - passing\n'.repeat(400) + failure + ' D'.repeat(2_000) + '\n# fail 1\n'; + const excerpt = formatStepExcerpt(stream); + expect(excerpt).toContain(failure); + expect(excerpt).toMatch(/… [\d,]+ bytes elided; 1 line matched a failure marker …/u); + expect(excerpt).toContain('# fail 1'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('keeps naming it wherever the cut lands, including exactly on its first byte', () => { + // One byte of padding at a time slides the failing line across the tail + // boundary, so the sweep covers every alignment there is: wholly in the + // middle, cut anywhere inside, starting exactly at the tail, and wholly + // inside the tail. It is named once in all of them — once, because a + // line reported twice is two failures to the reader. + const failure = 'not ok 5 - pty-exit: child reaped twice'; + for (const rest of [' D'.repeat(1_000), ' D'.repeat(2_000)]) { + for (let pad = 0; pad < 200; pad++) { + const stream = 'ok - passing\n'.repeat(400) + + failure + rest + '\n' + 'x'.repeat(pad) + '\n# fail 1\n'; + const excerpt = formatStepExcerpt(stream); + expect(excerpt.split(failure)).toHaveLength(2); + expect(excerpt).toContain('# fail 1'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + } + } + }); + + it('does not claim a truncation when the tail resumes the line at the cut', () => { + // A kept prefix the tail picks up at the very byte it ended is one + // unbroken run of source: the tail starts at the line instead, and the + // excerpt shows the whole of it with no marker in the middle. + const failing = 'not ok 5 - pty-exit: child reaped twice' + ' D'.repeat(1_000) + '\n'; + const excerpt = formatStepExcerpt('ok - passing\n'.repeat(400) + failing + '# fail 1\n'); + expect(excerpt).toContain(failing); + expect(excerpt).not.toContain('… line truncated …'); + expect(excerpt.endsWith('# fail 1\n')).toBe(true); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('counts a failing line the cut hides and the share could not fit', () => { + // Thirty short matches spend the highlight share, so the long line the + // tail cuts into gets no prefix of its own. What the tail shows of it + // names nothing, so it is reported as omitted rather than as seen. + const filler = 'ok - a passing case with a realistically long name\n'; + const middle = Array.from({ length: 30 }, + (_, index) => `not ok ${index + 1} - a middle failure with a realistically long name\n`).join(''); + const excerpt = formatStepExcerpt(filler.repeat(40) + middle + filler.repeat(20) + + 'not ok 99 - crosses the tail cut' + ' D'.repeat(2_000) + '\n# fail 31\n'); + expect(excerpt).not.toContain('not ok 99 - crosses the tail cut'); + const shown = Number(/([\d,]+) lines matched a failure marker/u.exec(excerpt)![1]!.replaceAll(',', '')); + const more = Number(/\+([\d,]+) more matching lines/u.exec(excerpt)![1]!.replaceAll(',', '')); + expect(shown + more).toBe(31); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('reports matches it had no room to show at all', () => { + // One very long matching line consumes the highlight share; the rest of + // the middle matches are counted rather than silently dropped. + const long = 'not ok 1 - ' + 'D'.repeat(4_000) + '\n'; + const filler = 'ok - a passing case with a realistically long name\n'; + const excerpt = formatStepExcerpt( + filler.repeat(40) + long + 'not ok 2 - short\nnot ok 3 - short\n' + filler.repeat(120)); + expect(excerpt).toContain('… +2 more matching lines …'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); +}); + +describe('formatStepExcerpt: what it is safe to print', () => { + it('never splits a multibyte character and never invents a replacement', () => { + const excerpt = formatStepExcerpt('🙂'.repeat(2_000) + 'é'); + expect(excerpt).not.toContain('�'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('keeps a replacement character the capture itself produced', () => { + // The Rust capture decodes lossily and may hand over a U+FFFD of its own + // at its 64 KiB boundary. That is data, not damage this module did. + const excerpt = formatStepExcerpt('� head\n' + 'x\n'.repeat(4_000) + '� tail\n'); + expect(excerpt).toContain('� head'); + expect(excerpt).toContain('� tail'); + }); + + it('replaces controls and bidi overrides on a short stream too, without growing it', () => { + const stream = '\u001b[31mred\u009b0m‮overridden\u0000\r\n\tkept\n'; + const excerpt = formatStepExcerpt(stream); + expect(excerpt).not.toMatch(/(?![\n\t])[\p{Cc}\p{Cf}]/u); + expect(excerpt).toContain('\n\tkept\n'); + expect(bytes(excerpt)).toBeLessThanOrEqual(bytes(stream)); + }); + + it('replaces controls in an elided stream and stays inside the budget', () => { + const binary = Buffer.from([0, 0xff, 0x1b, 13, 8]).toString('utf8'); + const excerpt = formatStepExcerpt(binary.repeat(1_000) + '\u009b31m‮END\n\t'); + expect(excerpt).toMatch(/END\n\t$/u); + expect(excerpt).not.toMatch(/[\x00-\x08\x0b-\x1f\x7f-\x9f\p{Cf}]/u); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('handles CRLF, tabs and a final line with no newline', () => { + const stream = 'first\r\n' + '\tindented\r\n'.repeat(1_000) + 'not ok 4 - crlf case\r\nno trailing newline'; + const excerpt = formatStepExcerpt(stream); + expect(excerpt).toContain('first'); + expect(excerpt).toContain('no trailing newline'); + expect(excerpt).toContain('\tindented'); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + }); + + it('bounds a single enormous line with no newline at all', () => { + const excerpt = formatStepExcerpt('A'.repeat(70_000)); + expect(bytes(excerpt)).toBeLessThanOrEqual(EXCERPT_BYTES); + expect(excerpt).toMatch(/… [\d,]+ bytes elided …/u); + expect(excerpt.startsWith('A')).toBe(true); + expect(excerpt.endsWith('A')).toBe(true); + }); + + it.each([1_024, MIN_EXCERPT_BYTES, EXCERPT_BYTES, 8_192])('stays inside a %s byte budget', budget => { + for (const stream of [ + tapStream(400, [200]), + '🙂'.repeat(20_000), + 'A'.repeat(70_000), + Array.from({ length: 300 }, (_, index) => `not ok ${index} - failure`).join('\n'), + ]) { + expect(bytes(formatStepExcerpt(stream, budget))).toBeLessThanOrEqual(budget); + } + }); + + it.each([0, -1, 255, 1.5, Number.NaN])('refuses the unusable budget %s rather than eliding in silence', budget => { + expect(() => formatStepExcerpt('x'.repeat(10_000), budget)) + .toThrow('step excerpt budget must be an integer of at least 256 bytes'); + }); +});