From 0d2d246888e04d4b56e544a2f6583965f3b55100 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Artur=20M=C4=99dryga=C5=82?= Date: Thu, 20 Aug 2026 11:02:27 +0200 Subject: [PATCH 1/3] fix(api): describe a failed snapshot build by its cause, not its tail MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A snapshot install/build that failed was described with `execTail` — the last 800/1200 characters of stderr + stdout. A tail cuts at the front, so the first line of the message was whatever the tool printed last: pnpm's progress counter (Sentry DEMOS-1W) or the middle of its self-update box (DEMOS-1Y). Sentry titles an issue from that first line, so neither issue named the failure, and because the message was multi-line the browser SDK fed lines 2..n to its stack-frame regexes and invented the culprit `│ Changelog: (v/11.22)`. DEV-2533 already solved this for the Tier-2 boot log. Rather than a second copy of those regexes, move the rule set to `packages/runtime/src/failure-log.ts`: `bootFailureDetail` stays as a thin wrapper with the boot defaults (and the same export `container-boot-failure.test.mjs` imports), and a new `execFailureDetail` handles the builder's two streams. Its tiers run across the streams rather than within a concatenation of them — an announced cause on either stream outranks a merely mentioned one on either — because pnpm keeps counting on stdout after diagnosing on stderr, while vite/ng/next report real errors on stdout and leave deprecation noise on stderr. The window, the empty-output wording, and the byte cap on the kept log become options. `runBuild` now throws `BuildFailure`: a one-line message, with the output kept apart in `log` and the machine code in `code`, mirroring `ContainerBootFailure`. The route catch-all reports it under `context: snapshot-build`, fingerprinted by phase and code so one defect stays one issue, with the log as an `extra`. Rollout: the message changes, so grouping changes. DEMOS-1W and DEMOS-1Y stop receiving events and correctly titled issues appear in their place. DEV-2570 Co-Authored-By: Claude Opus 5 --- runner/packages/runtime/package.json | 4 + runner/packages/runtime/src/container.ts | 89 ++------- runner/packages/runtime/src/failure-log.ts | 204 +++++++++++++++++++++ runner/pipeline/failure-log.test.mjs | 200 ++++++++++++++++++++ runner/workers/api/src/index.ts | 17 +- runner/workers/api/src/share.ts | 60 +++++- 6 files changed, 492 insertions(+), 82 deletions(-) create mode 100644 runner/packages/runtime/src/failure-log.ts create mode 100644 runner/pipeline/failure-log.test.mjs diff --git a/runner/packages/runtime/package.json b/runner/packages/runtime/package.json index 8c6021fe0..306dc6cab 100644 --- a/runner/packages/runtime/package.json +++ b/runner/packages/runtime/package.json @@ -18,6 +18,10 @@ "types": "./dist/container.d.ts", "default": "./dist/container.js" }, + "./failure-log": { + "types": "./dist/failure-log.d.ts", + "default": "./dist/failure-log.js" + }, "./monitor": { "types": "./dist/monitor.d.ts", "default": "./dist/monitor.js" diff --git a/runner/packages/runtime/src/container.ts b/runner/packages/runtime/src/container.ts index c2624382d..798b1281f 100644 --- a/runner/packages/runtime/src/container.ts +++ b/runner/packages/runtime/src/container.ts @@ -17,89 +17,28 @@ import type { } from "./types.js"; import { mintSessionId } from "./session.js"; import { applyHandsontableCss, applyHandsontableVersion } from "./version.js"; -import { MONITOR_EVENT_CEILING, redactPreviewHosts, truncateMessage } from "./monitor.js"; - -/** Dev-server output worth relaying (DEV-2527). Broad on purpose — the point is to - * learn what running dev servers complain about — but narrow enough that ordinary - * request logging and HMR chatter do not qualify. */ -const STDERR_MARKERS = - /\b(error|failed|failure|exception|unhandled|cannot find|not found|econnrefused|eaddrinuse)\b/i; - -/** A line that ANNOUNCES a cause, as opposed to merely mentioning one. Anchored at the - * start of the line on purpose: pnpm prints its prose hints ("This error happened - * while installing the dependencies of …") AFTER the code line, so an unanchored scan - * from the end of the log picks the hint over ERR_PNPM_NO_MATCHING_VERSION. - * - * Deliberately separate from STDERR_MARKERS rather than a widening of it: that set is - * load-bearing for `relayStderr`, where it controls how much dev-server noise is - * shipped as demo events. Two patterns, two jobs. */ -const BOOT_CAUSE_LINE = /^(?:err_[a-z0-9_]+|npm ERR!|ELIFECYCLE|::error::|[a-z]*error\b)/i; - -/** ANSI codes meaning "what follows replaces this line": erase-whole-line (`\x1b[2K`) - * and cursor-to-column (`\x1b[nG`). pnpm redraws its progress counter with these - * rather than with a bare `\r`, so stripping them as ordinary CSI would glue every - * redraw frame into one run-on line. Normalised to `\r` so one last-frame-wins rule - * covers both. - * - * `2K` specifically, NOT `\d*K`: a bare `\x1b[K` is erase-to-end-of-line, the "wipe - * what the previous longer line left behind" idiom, and it usually trails the text it - * is protecting. Treating it as a reset would drop that text — deleting exactly the - * cause line this function exists to find. Those fall through to ANSI_CSI below and - * are stripped like any other code. - * - * (`PreviewPane.tailLines` strips CSI first and therefore keeps redraw fragments. - * Deliberately stricter here: nothing there ends up as a Sentry issue title.) */ -const LINE_RESET = /\x1b\[(?:2K|\d*G)/g; - -/** Full CSI, not just colour (`m`): a boot log is mostly cursor movement. */ -const ANSI_CSI = /\x1b\[[0-9;?]*[ -/]*[@-~]/g; - -/** The last entry satisfying `pred` — the newest occurrence, since logs run forwards. */ -function findLastLine(lines: readonly string[], pred: (line: string) => boolean): string | null { - for (let i = lines.length - 1; i >= 0; i -= 1) { - if (pred(lines[i]!)) return lines[i]!; - } - return null; -} +import { MONITOR_EVENT_CEILING, truncateMessage } from "./monitor.js"; +import { failureDetail, STDERR_MARKERS } from "./failure-log.js"; /** * Split a failed boot log into the one line worth titling an issue with (`cause`) and * the recent context worth keeping beside it (`tail`). * - * The whole log used to become the `Error.message` (DEV-2533). A message that is a log - * takes the issue title from whatever the tail happened to start with, and — because - * V8 puts the message inside `error.stack` and stack parsers skip only the first - * line — feeds lines 2..n of it to the frame regexes, inventing both a stack and a - * culprit. The actual cause, meanwhile, sat unread on the last line. + * The rule set moved to `failure-log.ts` in DEV-2570, when the snapshot builder turned + * out to have the same defect this function was written for (DEV-2533) and reproduced + * it with a second copy of these regexes. This wrapper keeps the boot-log defaults — + * the log arrives pre-bounded by the status route's `tail -c 2500`, so 40 lines is the + * readability window and the byte cap never bites — and keeps the name and the export + * `pipeline/container-boot-failure.test.mjs` imports. * - * The cause is chosen in three tiers, each scanning backwards: a line that announces a - * failure, else a line that mentions one, else the last line there is. + * `code` is dropped: it exists for the Worker's Sentry fingerprint, and the boot path + * fingerprints on `["tier2-container-boot"]` instead (App.tsx). */ export function bootFailureDetail(log: string): { cause: string; tail: string } { - const lines = log - .replace(LINE_RESET, "\r") - .replace(ANSI_CSI, "") - .split("\n") - .map((l) => l.slice(l.lastIndexOf("\r") + 1).trimEnd()) - .filter(Boolean) - // Already bounded upstream by the status route's `tail -c 2500`; this is the - // readability bound, and it is what `tail` promises callers. - .slice(-40); - - const candidate = - findLastLine(lines, (l) => BOOT_CAUSE_LINE.test(l.trimStart())) ?? - findLastLine(lines, (l) => STDERR_MARKERS.test(l)) ?? - lines[lines.length - 1] ?? - ""; - - // Redact, then truncate — the order is the security property (e0da4598): truncating - // first can cut a preview hostname in half and leave the session token behind in a - // form the redactor no longer recognises. - const cause = truncateMessage(redactPreviewHosts(candidate.trim())); - return { - cause: cause || "Container failed to install dependencies or start.", - tail: redactPreviewHosts(lines.join("\n")), - }; + const { cause, tail } = failureDetail(log, { + fallback: "Container failed to install dependencies or start.", + }); + return { cause, tail }; } /** The container reached the server and booted, but the boot script itself diff --git a/runner/packages/runtime/src/failure-log.ts b/runner/packages/runtime/src/failure-log.ts new file mode 100644 index 000000000..4fa2830c5 --- /dev/null +++ b/runner/packages/runtime/src/failure-log.ts @@ -0,0 +1,204 @@ +// What a failed install/build log says went wrong (DEV-2533, DEV-2570). +// +// Two callers, one rule set: the Tier-2 container boot log (`container.ts`, one +// stream, pre-bounded by the status route's `tail -c 2500`) and the snapshot +// builder's `sbx.exec` results (`workers/api/src/share.ts`, two unbounded +// streams). Both used to turn a log into an `Error.message` and both produced the +// same defect — see `failureDetail` below for what that costs. +// +// Import-light on purpose: only `./monitor.js`, which is itself DOM-free, so the +// API Worker can import this subpath the way it already imports `./scheme`. + +import { redactPreviewHosts, truncateMessage } from "./monitor.js"; + +/** Dev-server output worth relaying (DEV-2527). Broad on purpose — the point is to + * learn what running dev servers complain about — but narrow enough that ordinary + * request logging and HMR chatter do not qualify. + * + * Lives here rather than in `container.ts` because it is also the second tier of + * the cause picker below; `container.ts` imports it back for `relayStderr`. */ +export const STDERR_MARKERS = + /\b(error|failed|failure|exception|unhandled|cannot find|not found|econnrefused|eaddrinuse)\b/i; + +/** A line that ANNOUNCES a cause, as opposed to merely mentioning one. Anchored at the + * start of the line on purpose: pnpm prints its prose hints ("This error happened + * while installing the dependencies of …") AFTER the code line, so an unanchored scan + * from the end of the log picks the hint over ERR_PNPM_NO_MATCHING_VERSION. + * + * Deliberately separate from STDERR_MARKERS rather than a widening of it: that set is + * load-bearing for `relayStderr`, where it controls how much dev-server noise is + * shipped as demo events. Two patterns, two jobs. */ +const CAUSE_LINE = /^(?:err_[a-z0-9_]+|npm ERR!|ELIFECYCLE|::error::|[a-z]*error\b)/i; + +/** The stable prefixes of a cause line — the part that is a machine code rather than + * prose, and therefore the only part safe to fingerprint a Sentry issue by. The + * `[a-z]*error\b` arm of `CAUSE_LINE` deliberately has no entry here: it matches + * sentences like "error during build: …", and keying a group by one of those shards + * the group per message, which is the very failure mode the fingerprint exists to + * prevent. */ +const CAUSE_CODE = /^(?:(err_[a-z0-9_]+)|(elifecycle)|(npm ERR!)|(::error::))/i; + +/** ANSI codes meaning "what follows replaces this line": erase-whole-line (`\x1b[2K`) + * and cursor-to-column (`\x1b[nG`). pnpm redraws its progress counter with these + * rather than with a bare `\r`, so stripping them as ordinary CSI would glue every + * redraw frame into one run-on line. Normalised to `\r` so one last-frame-wins rule + * covers both. + * + * `2K` specifically, NOT `\d*K`: a bare `\x1b[K` is erase-to-end-of-line, the "wipe + * what the previous longer line left behind" idiom, and it usually trails the text it + * is protecting. Treating it as a reset would drop that text — deleting exactly the + * cause line this function exists to find. Those fall through to ANSI_CSI below and + * are stripped like any other code. + * + * (`PreviewPane.tailLines` strips CSI first and therefore keeps redraw fragments. + * Deliberately stricter here: nothing there ends up as a Sentry issue title.) */ +const LINE_RESET = /\x1b\[(?:2K|\d*G)/g; + +/** Full CSI, not just colour (`m`): a boot log is mostly cursor movement. And pnpm + * colourises even when its output is a pipe, so the exec path needs this as much as + * the boot path does. */ +const ANSI_CSI = /\x1b\[[0-9;?]*[ -/]*[@-~]/g; + +/** Readability bound on the kept window, and what `tail` promises callers. A boot log + * arrives already tailed to 2500 bytes; an exec result does not, which is why the + * builder raises it. */ +const DEFAULT_KEEP_LINES = 40; + +const DEFAULT_FALLBACK = "The process failed with no output."; + +export interface FailureDetailOptions { + /** How many trailing non-empty lines to keep. Default 40. */ + keepLines?: number; + /** `cause` when the log yields nothing at all. */ + fallback?: string; + /** Byte cap on `tail`, applied after redaction; a cut tail is marked with a leading + * `...`. Uncapped by default, which is what the boot path wants: its log arrives + * already tailed to 2500 bytes by the status route, and capping it again here would + * measure the CLEANED, redacted string — blank lines dropped, hosts replaced by + * `` — whose length is not the byte count that tail promised. The exec path + * has no such upstream bound and passes its own. */ + maxTailChars?: number; +} + +export interface FailureDetail { + /** One line: what to title an issue with, and what to show a user. Never multi-line. */ + cause: string; + /** The recent output the cause was picked out of — context, never part of a message. */ + tail: string; + /** The machine code the cause announced (`ERR_PNPM_NO_MATCHING_VERSION`, `ELIFECYCLE`, + * …), or `"other"`. A stable Sentry fingerprint key; the cause itself is not one. */ + code: string; +} + +/** The last entry satisfying `pred` — the newest occurrence, since logs run forwards. */ +function findLastLine(lines: readonly string[], pred: (line: string) => boolean): string | null { + for (let i = lines.length - 1; i >= 0; i -= 1) { + if (pred(lines[i]!)) return lines[i]!; + } + return null; +} + +/** Strip the redraw frames and escape codes, drop blanks, keep the tail window. */ +function cleanLines(log: string, keepLines: number): string[] { + return log + .replace(LINE_RESET, "\r") + .replace(ANSI_CSI, "") + .split("\n") + .map((l) => l.slice(l.lastIndexOf("\r") + 1).trimEnd()) + .filter(Boolean) + .slice(-keepLines); +} + +const announcesCause = (line: string): boolean => CAUSE_LINE.test(line.trimStart()); +const mentionsCause = (line: string): boolean => STDERR_MARKERS.test(line); + +/** The machine code a cause line announces, or `"other"`. Normalised to an + * uppercase identifier — `npm ERR!` becomes `NPM_ERR`, `::error::` becomes `ERROR` — + * because this is a Sentry fingerprint key, and a key with spaces and punctuation in + * it reads as a stray message rather than a code. */ +export function causeCode(cause: string): string { + const m = CAUSE_CODE.exec(cause.trimStart()); + if (!m) return "other"; + return m[0].toUpperCase().replace(/[^A-Z0-9]+/g, "_").replace(/^_+|_+$/g, ""); +} + +/** Redact, then truncate — the order is the security property (e0da4598): truncating + * first can cut a preview hostname in half and leave the session token behind in a + * form the redactor no longer recognises. Keeps the END of the log, since that is + * what a tail is for. */ +function boundedTail(lines: readonly string[], maxTailChars: number | undefined): string { + const redacted = redactPreviewHosts(lines.join("\n")); + if (maxTailChars === undefined || redacted.length <= maxTailChars) return redacted; + return `...${redacted.slice(-maxTailChars)}`; +} + +function describe( + candidate: string | null, + lines: readonly string[], + options: FailureDetailOptions, +): FailureDetail { + const picked = (candidate ?? "").trim(); + const cause = truncateMessage(redactPreviewHosts(picked)); + return { + cause: cause || (options.fallback ?? DEFAULT_FALLBACK), + tail: boundedTail(lines, options.maxTailChars), + code: picked ? causeCode(picked) : "other", + }; +} + +/** + * Split a failed log into the one line worth titling an issue with (`cause`) and the + * recent context worth keeping beside it (`tail`). + * + * The whole log used to become the `Error.message` (DEV-2533, and again for the + * snapshot builder in DEV-2570). A message that is a log takes the issue title from + * whatever the tail happened to start with, and — because V8 puts the message inside + * `error.stack` and stack parsers skip only the first line — feeds lines 2..n of it to + * the frame regexes, inventing both a stack and a culprit. The actual cause, meanwhile, + * sat unread further down. + * + * The cause is chosen in three tiers, each scanning backwards: a line that announces a + * failure, else a line that mentions one, else the last line there is. + */ +export function failureDetail(log: string, options: FailureDetailOptions = {}): FailureDetail { + const lines = cleanLines(log, options.keepLines ?? DEFAULT_KEEP_LINES); + const candidate = + findLastLine(lines, announcesCause) ?? + findLastLine(lines, mentionsCause) ?? + lines[lines.length - 1] ?? + null; + return describe(candidate, lines, options); +} + +/** + * The same split for a failed `exec`, which has two streams rather than one log. + * + * The tiers run ACROSS the streams, not within a concatenation of them, and that is + * the whole point of this entry point. Joining and scanning backwards makes the last + * line of the last stream win, and neither ordering is right on its own: pnpm keeps + * counting progress on stdout long after it has written its diagnosis to stderr, while + * vite/ng/next report genuine build errors on stdout and leave stderr carrying trailing + * deprecation and browserslist noise. Preferring an ANNOUNCED cause on either stream + * over a merely MENTIONED one on either stream settles both cases; stderr breaks the + * tie within a tier. + * + * `tail` keeps stdout first and stderr last, so when the byte cap bites it is the + * diagnosis that survives. + */ +export function execFailureDetail( + result: { stdout?: string; stderr?: string }, + options: FailureDetailOptions = {}, +): FailureDetail { + const keepLines = options.keepLines ?? DEFAULT_KEEP_LINES; + const err = cleanLines(result.stderr ?? "", keepLines); + const out = cleanLines(result.stdout ?? "", keepLines); + const candidate = + findLastLine(err, announcesCause) ?? + findLastLine(out, announcesCause) ?? + findLastLine(err, mentionsCause) ?? + findLastLine(out, mentionsCause) ?? + err[err.length - 1] ?? + out[out.length - 1] ?? + null; + return describe(candidate, [...out, ...err], options); +} diff --git a/runner/pipeline/failure-log.test.mjs b/runner/pipeline/failure-log.test.mjs new file mode 100644 index 000000000..becb654a4 --- /dev/null +++ b/runner/pipeline/failure-log.test.mjs @@ -0,0 +1,200 @@ +// What a failed install/build reports as its cause (DEV-2570). +// +// The defect these assertions exist against: `share.ts` described a failed +// `sbx.exec` with the last N characters of `stderr + stdout`. A tail cuts at the +// FRONT, so the surviving first line was whatever the tool printed last — pnpm's +// progress counter (Sentry DEMOS-1W) or the middle of its self-update box +// (DEMOS-1Y) — and the multi-line message then fed lines 2..n to the browser SDK's +// stack-frame regexes, inventing the culprit `│ Changelog: (v/11.22)`. +// +// The fixtures are the real DEMOS-1W / DEMOS-1Y event bodies, stream-split the way +// pnpm actually writes them. `container-boot-failure.test.mjs` covers the same rule +// set from the Tier-2 boot side and must keep passing unedited — that suite is the +// regression guard for the extraction. + +import test from "node:test"; +import assert from "node:assert/strict"; +import { + causeCode, + execFailureDetail, + failureDetail, +} from "../packages/runtime/dist/failure-log.js"; +import { register } from "node:module"; + +// `share.ts` reaches the rest of the Worker through `./x.js` specifiers that only a +// bundler resolves, so it is imported the way `mcp-routes.test.mjs` imports the +// router: through the shared resolver hooks, dynamically, after register(). +register("./fixtures/worker-hooks.mjs", import.meta.url); +const { BuildFailure, describeBuildFailure } = await import("../workers/api/src/share.ts"); + +/** The builder's options, as `share.ts` passes them. */ +const BUILDER = { keepLines: 120, fallback: "no output" }; + +/** pnpm's diagnosis. Written to stderr, and it is not the last thing pnpm says. */ +const PNPM_STDERR = ` ERR_PNPM_NO_MATCHING_VERSION No matching version found for handsontable@13106 while fetching it from https://registry.npmjs.org/ + +This error happened while installing a direct dependency of /app + +The latest release of handsontable is "18.0.0". + +Other releases are: + * beta: 8.0.0-beta.2 + * next: 0.0.0-next-64139ae-20260219 + * rc: 18.0.0-rc5 + +If you need the full list of all 1737 published versions run "pnpm view handsontable versions".`; + +/** ...while stdout keeps counting. This is DEMOS-1W's title. */ +const PNPM_STDOUT = `Progress: resolved 1, reused 0, downloaded 0, added 0`; + +/** ...and the self-update box lands after the failure. This is DEMOS-1Y's title, + * and the box frame is where its culprit was parsed from. */ +const PNPM_UPDATE_BOX = ` ╭───────────────────────────────────────────────╮ + │ │ + │ Update available! 10.34.5 → 11.22.0. │ + │ Changelog: https://pnpm.io/v/11.22.0 │ + │ To update, run: corepack use pnpm@11.22.0 │ + │ │ + ╰───────────────────────────────────────────────╯`; + +test("the cause is the pnpm error code, not the progress counter that followed it", () => { + const { cause } = execFailureDetail({ stdout: PNPM_STDOUT, stderr: PNPM_STDERR }, BUILDER); + assert.match(cause, /^ERR_PNPM_NO_MATCHING_VERSION/); + assert.match(cause, /handsontable@13106/); +}); + +test("pnpm's self-update box never becomes the cause", () => { + const { cause } = execFailureDetail( + { stdout: `${PNPM_UPDATE_BOX}\n${PNPM_STDOUT}`, stderr: PNPM_STDERR }, + BUILDER, + ); + assert.match(cause, /^ERR_PNPM_NO_MATCHING_VERSION/); + assert.ok(!cause.includes("Update available")); + assert.ok(!cause.includes("│")); +}); + +test("the cause is one line — the property that stops the SDK inventing a stack", () => { + const { cause } = execFailureDetail( + { stdout: `${PNPM_UPDATE_BOX}\n${PNPM_STDOUT}`, stderr: PNPM_STDERR }, + BUILDER, + ); + assert.ok(!cause.includes("\n")); +}); + +test("the prose hint after the code never outranks the code", () => { + // pnpm prints "This error happened while installing…" AFTER the ERR_ line, and a + // backwards scan for anything mentioning a failure would pick the hint. + const { cause } = execFailureDetail({ stderr: PNPM_STDERR }, BUILDER); + assert.ok(!cause.startsWith("This error happened")); +}); + +test("stderr breaks the tie when both streams announce a cause", () => { + const { cause } = execFailureDetail( + { + stdout: "ELIFECYCLE Command failed with exit code 1.", + stderr: " ERR_PNPM_FETCH_404 GET https://registry.npmjs.org/nope: Not Found - 404", + }, + BUILDER, + ); + assert.match(cause, /^ERR_PNPM_FETCH_404/); +}); + +test("an announced cause on stdout outranks trailing noise on stderr", () => { + // vite/ng/next report real build errors on stdout while stderr carries deprecation + // and browserslist chatter. A plain "stderr wins" rule promotes the warning. + const { cause } = execFailureDetail( + { + stdout: "vite v5.4.21 building for production...\nerror during build:\nELIFECYCLE Command failed with exit code 1.", + stderr: "(node:41) [DEP0040] DeprecationWarning: The `punycode` module is deprecated.\nBrowserslist: caniuse-lite is outdated.", + }, + BUILDER, + ); + assert.match(cause, /^ELIFECYCLE/); +}); + +test("a mentioned cause is used only when nothing announces one", () => { + const { cause, code } = execFailureDetail( + { stdout: "building...\n✘ [ERROR] Could not resolve \"./missing\"", stderr: "" }, + BUILDER, + ); + assert.match(cause, /Could not resolve/); + assert.equal(code, "other"); +}); + +test("the code is the machine token, and prose never becomes one", () => { + assert.equal(causeCode(" ERR_PNPM_NO_MATCHING_VERSION No matching version found"), "ERR_PNPM_NO_MATCHING_VERSION"); + assert.equal(causeCode("ELIFECYCLE Command failed with exit code 1."), "ELIFECYCLE"); + assert.equal(causeCode("npm ERR! code E404"), "NPM_ERR"); + assert.equal(causeCode("::error::frozen install failed for generated starter metadata"), "ERROR"); + assert.equal(causeCode("error during build:"), "other"); + assert.equal(causeCode("Error: connect ECONNREFUSED"), "other"); +}); + +test("the builder's window reaches a cause printed well before the end", () => { + // A boot log is pre-tailed to 2500 bytes and 40 lines is plenty; a webpack build + // prints its error and then a hundred lines of asset table. + const noise = Array.from({ length: 80 }, (_, i) => ` asset chunk-${i}.js 12 KiB [emitted]`).join("\n"); + const { cause } = execFailureDetail( + { stdout: `ELIFECYCLE Command failed with exit code 1.\n${noise}`, stderr: "" }, + BUILDER, + ); + assert.match(cause, /^ELIFECYCLE/); + // ...and the boot path's 40-line default genuinely could not. + assert.ok(!failureDetail(`ELIFECYCLE Command failed with exit code 1.\n${noise}`).cause.startsWith("ELIFECYCLE")); +}); + +test("empty output yields the caller's fallback, not the container's wording", () => { + const { cause, code, tail } = execFailureDetail({ stdout: "", stderr: "" }, BUILDER); + assert.equal(cause, "no output"); + assert.equal(code, "other"); + assert.equal(tail, ""); +}); + +test("ANSI survives nothing — pnpm colourises even into a pipe", () => { + const coloured = `\x1b[2K\x1b[1G\x1b[90mProgress: resolved 1\x1b[39m\n\x1b[31m ERR_PNPM_NO_MATCHING_VERSION\x1b[39m No matching version found`; + const { cause } = execFailureDetail({ stderr: coloured }, BUILDER); + assert.match(cause, /^ERR_PNPM_NO_MATCHING_VERSION/); + // eslint-disable-next-line no-control-regex + assert.ok(!/\x1b/.test(cause)); +}); + +test("the tail is uncapped unless a caller asks — the boot log is bounded upstream", () => { + // A cap here would measure the cleaned, redacted string rather than the 2500 bytes + // the status route already tailed, so `bootFailureDetail` would start marking tails + // it never used to cut. App.tsx concatenates that tail into the user's error card. + const long = Array.from({ length: 30 }, (_, i) => `line ${i} ${"x".repeat(200)}`).join("\n"); + const { tail } = failureDetail(long); + assert.ok(tail.length > 2500); + assert.ok(!tail.startsWith("...")); +}); + +test("the log rides in tail, never in the cause, and stderr survives the byte cap", () => { + const { cause, tail } = execFailureDetail( + { stdout: `${PNPM_UPDATE_BOX}\n${PNPM_STDOUT}`, stderr: PNPM_STDERR }, + { ...BUILDER, maxTailChars: 200 }, + ); + assert.ok(!cause.includes("Progress:")); + assert.ok(tail.length <= 204); + assert.match(tail, /published versions/); +}); + +test("the thrown BuildFailure names the phase, stays one line, and carries the log apart", () => { + const err = describeBuildFailure("install", { + stdout: `${PNPM_UPDATE_BOX}\n${PNPM_STDOUT}`, + stderr: PNPM_STDERR, + }); + assert.ok(err instanceof BuildFailure); + assert.match(err.message, /^install failed: ERR_PNPM_NO_MATCHING_VERSION/); + assert.ok(!err.message.includes("\n")); + assert.equal(err.phase, "install"); + assert.equal(err.code, "ERR_PNPM_NO_MATCHING_VERSION"); + // The output is context, not message — this split is the whole fix. + assert.match(err.log, /Progress: resolved 1/); + assert.ok(!err.message.includes("Progress:")); +}); + +test("a build with no output still describes itself", () => { + const err = describeBuildFailure("build", { stdout: "", stderr: "" }); + assert.equal(err.message, "build failed: no output"); + assert.equal(err.code, "other"); +}); diff --git a/runner/workers/api/src/index.ts b/runner/workers/api/src/index.ts index 2282ceab4..6751fff03 100644 --- a/runner/workers/api/src/index.ts +++ b/runner/workers/api/src/index.ts @@ -39,7 +39,7 @@ import { } from "./session-lifecycle.js"; import { refAmbiguousMessage, refUnknownMessage } from "./session-listing.js"; import { ImportError, MAX_PAYLOAD_CHARS, importFromUrl, validatePayloadFiles } from "./import-url.js"; -import { createDemo, getDemo, getDemoSource, invalidateDemo, serveDemoAsset, shortId, updateDemo, type DemoRow } from "./share.js"; +import { BuildFailure, createDemo, getDemo, getDemoSource, invalidateDemo, serveDemoAsset, shortId, updateDemo, type DemoRow } from "./share.js"; import { budgetPausedMessage, countEgress, @@ -1886,6 +1886,21 @@ export default Sentry.withSentry(sentryOptions, { if (err instanceof InvalidFilePathError) return json({ error: err.message }, 400); // This catch turns every unexpected throw into a 500 body, so withSentry() // never sees it. Report here or the error is invisible. + if (err instanceof BuildFailure) { + Sentry.captureException(err, { + tags: { context: "snapshot-build", build_phase: err.phase }, + // Without a fingerprint the cause line groups per package and per version, + // which is the same one-defect-many-issues shape DEV-2570 exists to end, + // only better titled. Keyed by the machine code so the group stays + // diagnosable; the title then tracks the newest event within it, which is + // the accepted trade (`ContainerBootFailure` in App.tsx makes the same one). + fingerprint: ["snapshot-build", err.phase, err.code], + // Bounded and picked apart in share.ts, and never in the message — a log in + // an `Error.message` is what invented DEMOS-1Y's culprit. + ...(err.log ? { extra: { buildLog: err.log } } : {}), + }); + return json({ error: err.message }, 500); + } Sentry.captureException(err); return json({ error: err instanceof Error ? err.message : String(err) }, 500); } diff --git a/runner/workers/api/src/share.ts b/runner/workers/api/src/share.ts index c46e7b29a..6dfc5f8c7 100644 --- a/runner/workers/api/src/share.ts +++ b/runner/workers/api/src/share.ts @@ -8,6 +8,7 @@ import { getSandbox } from "@cloudflare/sandbox"; import { injectSchemeIntoHtml } from "@handsontable/demo-runtime/scheme"; +import { execFailureDetail } from "@handsontable/demo-runtime/failure-log"; import type { Env } from "./env.js"; import { errorPageResponse, wantsHtmlError } from "./error-page.js"; import { recordContainerUsage, SESSION_INSTANCE_TYPE } from "./budget.js"; @@ -102,10 +103,57 @@ export function contentTypeFor(path: string): string { return CONTENT_TYPES[ext] ?? "application/octet-stream"; } -/** Tail of a failed exec's output. pnpm (and some build tools) report errors - * on stdout, so surface both streams, stdout last. */ -function execTail(r: { stdout?: string; stderr?: string }, n: number): string { - return [r.stderr, r.stdout].filter((s) => s?.trim()).join("\n").slice(-n); +/** How much of a failed exec's output rides along as Sentry context. Generous — + * it is an `extra`, not a message — but bounded, because nothing upstream bounds + * an exec result the way the Tier-2 status route tails a boot log. */ +const BUILD_LOG_MAX = 4000; + +/** Lines kept before the cause is picked. Higher than the boot log's 40: a webpack + * or next build prints its error and then a long asset table after it. */ +const BUILD_LOG_LINES = 120; + +/** + * A snapshot install/build that exited nonzero (DEV-2570). + * + * `message` is ONE line — the cause, as picked by `execFailureDetail`. The output it + * came from is `log`, and it is never part of the message: the route catch-all + * relays `err.message` to the browser as the 500 body, the browser turns that into + * an `ApiError`, and a multi-line message there is fed to the SDK's stack-frame + * regexes, which invents both a stack and a culprit out of the log's own lines + * (Sentry DEMOS-1Y). Same reasoning, same shape as `ContainerBootFailure`. + * + * `phase` and `code` exist so the report site can fingerprint without re-parsing the + * message — see the `BuildFailure` branch in index.ts. + */ +export class BuildFailure extends Error { + // Written out rather than declared as constructor parameter properties: the + // pipeline suites import this module through `--experimental-strip-types`, which + // refuses them outright (ERR_UNSUPPORTED_TYPESCRIPT_SYNTAX). Same erasable-syntax + // constraint `apiError.ts` documents on the client side. + readonly phase: "install" | "build"; + readonly code: string; + readonly log: string; + + constructor(message: string, phase: "install" | "build", code: string, log = "") { + super(message); + this.phase = phase; + this.code = code; + this.log = log; + } +} + +/** Describe a failed exec as a one-line cause plus its bounded output. Exported for + * `pipeline/failure-log.test.mjs`, which owns the "a message is never a log" rule. */ +export function describeBuildFailure( + phase: "install" | "build", + r: { stdout?: string; stderr?: string }, +): BuildFailure { + const { cause, tail, code } = execFailureDetail(r, { + keepLines: BUILD_LOG_LINES, + maxTailChars: BUILD_LOG_MAX, + fallback: "no output", + }); + return new BuildFailure(`${phase} failed: ${cause}`, phase, code, tail); } function base64ToBytes(b64: string): Uint8Array { @@ -168,7 +216,7 @@ export async function runBuild( `sh -lc "cd ${CONTAINER_ROOT} && ${entry.installCommand.replace(" --frozen-lockfile", "")} --no-frozen-lockfile"`, ); } - if (install.success === false) throw new Error(`install failed: ${execTail(install, 800)}`); + if (install.success === false) throw describeBuildFailure("install", install); // Snapshots only need the bundle, not type-checking. Strip leading // type-check steps (tsc / vue-tsc) that often fail in ephemeral containers @@ -180,7 +228,7 @@ export async function runBuild( const build = await sbx.exec( `sh -lc "cd ${CONTAINER_ROOT} && export PATH=${CONTAINER_ROOT}/node_modules/.bin:$PATH && ${buildCommand}"`, ); - if (build.success === false) throw new Error(`build failed: ${execTail(build, 1200)}`); + if (build.success === false) throw describeBuildFailure("build", build); // Resolve the output directory (angular nests under dist//browser). let outDir = `${CONTAINER_ROOT}/${entry.outputDir}`; From 820f87c70c507a523e964a59a4e3e808af30be8b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Artur=20M=C4=99dryga=C5=82?= Date: Thu, 20 Aug 2026 11:21:48 +0200 Subject: [PATCH 2/3] fix(api): take the line under a label-only cause, and keep a trailing reset from erasing one MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two defects found reviewing the picker against real build output. `vite build` announces its failure with a section label — `error during build:` — and puts the error on the next line. The announcing tier stopped on the label, so every vite failure described itself as `build failed: error during build:`: no package, no import, nothing. It is the build command for nearly every framework in the catalog, so that was the common path rather than an edge case. A cause line that ends in a colon now takes the line under it, joined rather than replaced — the label says which tool failed, the line under it says what did. `\x1b[nG` at the END of a line resets nothing, since there is no next frame on that line to keep, but `LINE_RESET` treated it as one and the slice then deleted the line whole. A log that was one such line — `ERR_PNPM_OUTDATED_LOCKFILE …\x1b[0G` — came out as "no output", losing the cause and, because the report site only attaches a non-empty log, the `buildLog` extra with it. Trailing resets are dropped before the last-frame-wins slice; a redraw mid-line still collapses as before. The `ELIFECYCLE`-on-stdout fixture went with them: `runBuild` execs the build binary off `node_modules/.bin` rather than an npm script, so pnpm's epilogue never appears on that stream. It is now a real vite log, which is what surfaced the first defect. DEV-2570 Co-Authored-By: Claude Opus 5 --- runner/packages/runtime/src/failure-log.ts | 49 +++++++++++++++++----- runner/pipeline/failure-log.test.mjs | 47 ++++++++++++++++++++- runner/workers/api/src/index.ts | 4 ++ 3 files changed, 87 insertions(+), 13 deletions(-) diff --git a/runner/packages/runtime/src/failure-log.ts b/runner/packages/runtime/src/failure-log.ts index 4fa2830c5..a91889f42 100644 --- a/runner/packages/runtime/src/failure-log.ts +++ b/runner/packages/runtime/src/failure-log.ts @@ -90,20 +90,47 @@ export interface FailureDetail { code: string; } -/** The last entry satisfying `pred` — the newest occurrence, since logs run forwards. */ -function findLastLine(lines: readonly string[], pred: (line: string) => boolean): string | null { +/** A line that is only a heading for the detail beneath it — vite's `error during + * build:`, esbuild's `Build failed with 1 error:`, tsc's `error TS2307:` when the + * detail wraps. Anchoring on such a line and stopping there loses the actual error: + * the announcing tier picks the label, and the message becomes a content-free + * `build failed: error during build:`. `vite build` is the build command for nearly + * every framework in the catalog, so this is the common path, not an edge case. */ +const CAUSE_LABEL = /:\s*$/; + +/** The last entry satisfying `pred` — the newest occurrence, since logs run forwards. + * Returns the index so a caller can look at what followed it. */ +function findLastIndex(lines: readonly string[], pred: (line: string) => boolean): number { for (let i = lines.length - 1; i >= 0; i -= 1) { - if (pred(lines[i]!)) return lines[i]!; + if (pred(lines[i]!)) return i; } - return null; + return -1; } -/** Strip the redraw frames and escape codes, drop blanks, keep the tail window. */ +/** The cause at `index`, plus the line under it when the cause is only a label. Joined + * rather than replaced: the label carries which tool failed ("error during build:"), + * the line under it carries what failed, and a reader wants both in the title. */ +function lineWithDetail(lines: readonly string[], index: number): string | null { + if (index < 0) return null; + const line = lines[index]!; + const next = lines[index + 1]; + return CAUSE_LABEL.test(line) && next ? `${line.trim()} ${next.trim()}` : line; +} + +/** Strip the redraw frames and escape codes, drop blanks, keep the tail window. + * + * A reset at the very END of a line resets nothing — there is no next frame on that + * line to keep — so it is dropped before the last-frame-wins slice. Without that, a + * line ending in `\x1b[0G` is deleted whole, and a log that is one such line + * (`ERR_PNPM_OUTDATED_LOCKFILE …\x1b[0G`) becomes "no output": no cause, and no + * `buildLog` extra either, since the report site only attaches a non-empty one. Same + * reasoning the comment on `LINE_RESET` gives for trailing `\x1b[K`. */ function cleanLines(log: string, keepLines: number): string[] { return log .replace(LINE_RESET, "\r") .replace(ANSI_CSI, "") .split("\n") + .map((l) => l.replace(/\r+$/, "")) .map((l) => l.slice(l.lastIndexOf("\r") + 1).trimEnd()) .filter(Boolean) .slice(-keepLines); @@ -163,8 +190,8 @@ function describe( export function failureDetail(log: string, options: FailureDetailOptions = {}): FailureDetail { const lines = cleanLines(log, options.keepLines ?? DEFAULT_KEEP_LINES); const candidate = - findLastLine(lines, announcesCause) ?? - findLastLine(lines, mentionsCause) ?? + lineWithDetail(lines, findLastIndex(lines, announcesCause)) ?? + lineWithDetail(lines, findLastIndex(lines, mentionsCause)) ?? lines[lines.length - 1] ?? null; return describe(candidate, lines, options); @@ -193,10 +220,10 @@ export function execFailureDetail( const err = cleanLines(result.stderr ?? "", keepLines); const out = cleanLines(result.stdout ?? "", keepLines); const candidate = - findLastLine(err, announcesCause) ?? - findLastLine(out, announcesCause) ?? - findLastLine(err, mentionsCause) ?? - findLastLine(out, mentionsCause) ?? + lineWithDetail(err, findLastIndex(err, announcesCause)) ?? + lineWithDetail(out, findLastIndex(out, announcesCause)) ?? + lineWithDetail(err, findLastIndex(err, mentionsCause)) ?? + lineWithDetail(out, findLastIndex(out, mentionsCause)) ?? err[err.length - 1] ?? out[out.length - 1] ?? null; diff --git a/runner/pipeline/failure-log.test.mjs b/runner/pipeline/failure-log.test.mjs index becb654a4..05ae02096 100644 --- a/runner/pipeline/failure-log.test.mjs +++ b/runner/pipeline/failure-log.test.mjs @@ -99,17 +99,60 @@ test("stderr breaks the tie when both streams announce a cause", () => { assert.match(cause, /^ERR_PNPM_FETCH_404/); }); +/** A real `vite build` failure. `runBuild` execs the binary off `node_modules/.bin` + * rather than an npm script (share.ts), so there is no pnpm `ELIFECYCLE` epilogue — + * the announcing line is vite's own section label, and the error is under it. */ +const VITE_STDOUT = `vite v5.4.21 building for production... +transforming... +error during build: +[vite]: Rollup failed to resolve import "handsontable/styles/x.css" from "/app/src/main.ts".`; + test("an announced cause on stdout outranks trailing noise on stderr", () => { // vite/ng/next report real build errors on stdout while stderr carries deprecation // and browserslist chatter. A plain "stderr wins" rule promotes the warning. const { cause } = execFailureDetail( { - stdout: "vite v5.4.21 building for production...\nerror during build:\nELIFECYCLE Command failed with exit code 1.", + stdout: VITE_STDOUT, stderr: "(node:41) [DEP0040] DeprecationWarning: The `punycode` module is deprecated.\nBrowserslist: caniuse-lite is outdated.", }, BUILDER, ); - assert.match(cause, /^ELIFECYCLE/); + assert.match(cause, /Rollup failed to resolve import/); + assert.ok(!cause.includes("DeprecationWarning")); +}); + +test("a label-only cause takes the line under it — the common vite build failure", () => { + // Stopping at "error during build:" would title every vite failure identically and + // tell the user nothing; `vite build` is the build command for nearly every + // framework in the catalog, so this is the dominant path. + const { cause } = execFailureDetail({ stdout: VITE_STDOUT }, BUILDER); + assert.equal( + cause, + 'error during build: [vite]: Rollup failed to resolve import "handsontable/styles/x.css" from "/app/src/main.ts".', + ); + assert.ok(!cause.includes("\n")); +}); + +test("a reset at the end of a line erases nothing", () => { + // `\x1b[0G` means "the next frame replaces this line". At the end of a line there is + // no next frame, and treating it as one deleted the line — a one-line log then + // described itself as "no output", with no cause AND no buildLog extra. + const { cause, tail } = execFailureDetail( + { stderr: " ERR_PNPM_OUTDATED_LOCKFILE Cannot install with frozen-lockfile\x1b[0G" }, + BUILDER, + ); + assert.match(cause, /^ERR_PNPM_OUTDATED_LOCKFILE/); + assert.notEqual(tail, ""); +}); + +test("a redraw mid-line still keeps only the last frame", () => { + // The counterpart to the test above: the reset rule must keep collapsing pnpm's + // progress redraws, or every frame glues into one run-on line. + const { cause } = execFailureDetail( + { stdout: "\x1b[2K\x1b[1GProgress: resolved 1\x1b[2K\x1b[1GProgress: resolved 2" }, + BUILDER, + ); + assert.equal(cause, "Progress: resolved 2"); }); test("a mentioned cause is used only when nothing announces one", () => { diff --git a/runner/workers/api/src/index.ts b/runner/workers/api/src/index.ts index 6751fff03..89ba9153a 100644 --- a/runner/workers/api/src/index.ts +++ b/runner/workers/api/src/index.ts @@ -1894,6 +1894,10 @@ export default Sentry.withSentry(sentryOptions, { // only better titled. Keyed by the machine code so the group stays // diagnosable; the title then tracks the newest event within it, which is // the accepted trade (`ContainerBootFailure` in App.tsx makes the same one). + // Bundler failures carry no machine code and therefore share the `other` + // group — coarse, but their causes are specific (the picker takes the line + // under a label like vite's "error during build:"), so the title still names + // one, and `buildLog` carries the rest. fingerprint: ["snapshot-build", err.phase, err.code], // Bounded and picked apart in share.ts, and never in the message — a log in // an `Error.message` is what invented DEMOS-1Y's culprit. From d7755c7b1116fab821e4668ce1389cb787832004 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Artur=20M=C4=99dryga=C5=82?= Date: Thu, 20 Aug 2026 11:24:54 +0200 Subject: [PATCH 3/3] fix(api): budget the kept log per stream so one loud stream cannot evict the other MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The tail cap keeps the END of the join, and `execFailureDetail` joined stdout then stderr — so a stream of deprecation warnings long enough to fill the budget on its own dropped stdout whole. Measured at the builder's 4000-character cap: 60 lines of `DeprecationWarning` on stderr, and the vite line the cause had just been picked from was absent from `buildLog`, leaving an extra that explained nothing (Bugbot, PR #239). Each stream is now capped in its own right, and a stream that does not need its half lends the remainder to the other so a quiet stderr does not cost stdout half the budget for nothing. DEV-2570 Co-Authored-By: Claude Opus 5 --- runner/packages/runtime/src/failure-log.ts | 49 ++++++++++++++++------ runner/pipeline/failure-log.test.mjs | 29 ++++++++++++- 2 files changed, 65 insertions(+), 13 deletions(-) diff --git a/runner/packages/runtime/src/failure-log.ts b/runner/packages/runtime/src/failure-log.ts index a91889f42..ba95f7472 100644 --- a/runner/packages/runtime/src/failure-log.ts +++ b/runner/packages/runtime/src/failure-log.ts @@ -154,21 +154,46 @@ export function causeCode(cause: string): string { * form the redactor no longer recognises. Keeps the END of the log, since that is * what a tail is for. */ function boundedTail(lines: readonly string[], maxTailChars: number | undefined): string { - const redacted = redactPreviewHosts(lines.join("\n")); - if (maxTailChars === undefined || redacted.length <= maxTailChars) return redacted; - return `...${redacted.slice(-maxTailChars)}`; + return bound(redactPreviewHosts(lines.join("\n")), maxTailChars); } -function describe( - candidate: string | null, - lines: readonly string[], - options: FailureDetailOptions, -): FailureDetail { +function bound(redacted: string, cap: number | undefined): string { + if (cap === undefined || redacted.length <= cap) return redacted; + return `...${redacted.slice(-cap)}`; +} + +/** + * The two streams under one byte budget, neither able to evict the other. + * + * A single join capped from the front is not enough: the cap keeps the END, so a + * stream of deprecation warnings long enough to fill the budget on its own drops the + * other stream entirely — including, measurably, the vite line the cause was picked + * from, leaving a `buildLog` extra of pure noise. Each stream is therefore capped in + * its own right, and a stream that does not need its half lends the remainder to the + * other rather than wasting it. + */ +function twoStreamTail( + out: readonly string[], + err: readonly string[], + cap: number | undefined, +): string { + const o = redactPreviewHosts(out.join("\n")); + const e = redactPreviewHosts(err.join("\n")); + if (cap === undefined || o.length + e.length + 1 <= cap) { + return [o, e].filter(Boolean).join("\n"); + } + const half = Math.floor((cap - 1) / 2); + const outCap = e.length <= half ? cap - 1 - e.length : half; + const errCap = o.length <= half ? cap - 1 - o.length : cap - 1 - outCap; + return [bound(o, outCap), bound(e, errCap)].filter(Boolean).join("\n"); +} + +function describe(candidate: string | null, tail: string, fallback?: string): FailureDetail { const picked = (candidate ?? "").trim(); const cause = truncateMessage(redactPreviewHosts(picked)); return { - cause: cause || (options.fallback ?? DEFAULT_FALLBACK), - tail: boundedTail(lines, options.maxTailChars), + cause: cause || (fallback ?? DEFAULT_FALLBACK), + tail, code: picked ? causeCode(picked) : "other", }; } @@ -194,7 +219,7 @@ export function failureDetail(log: string, options: FailureDetailOptions = {}): lineWithDetail(lines, findLastIndex(lines, mentionsCause)) ?? lines[lines.length - 1] ?? null; - return describe(candidate, lines, options); + return describe(candidate, boundedTail(lines, options.maxTailChars), options.fallback); } /** @@ -227,5 +252,5 @@ export function execFailureDetail( err[err.length - 1] ?? out[out.length - 1] ?? null; - return describe(candidate, [...out, ...err], options); + return describe(candidate, twoStreamTail(out, err, options.maxTailChars), options.fallback); } diff --git a/runner/pipeline/failure-log.test.mjs b/runner/pipeline/failure-log.test.mjs index 05ae02096..d21bb49e8 100644 --- a/runner/pipeline/failure-log.test.mjs +++ b/runner/pipeline/failure-log.test.mjs @@ -217,8 +217,11 @@ test("the log rides in tail, never in the cause, and stderr survives the byte ca { ...BUILDER, maxTailChars: 200 }, ); assert.ok(!cause.includes("Progress:")); - assert.ok(tail.length <= 204); + // The cap is per stream plus a `...` marker on each part it cut, and a newline + // between them. + assert.ok(tail.length <= 200 + "...".length * 2 + 1, `tail was ${tail.length}`); assert.match(tail, /published versions/); + assert.match(tail, /Progress: resolved 1/); }); test("the thrown BuildFailure names the phase, stays one line, and carries the log apart", () => { @@ -241,3 +244,27 @@ test("a build with no output still describes itself", () => { assert.equal(err.message, "build failed: no output"); assert.equal(err.code, "other"); }); + +test("a loud stream cannot evict the other from the kept log", () => { + // The cap keeps the END of the tail, so a single join lets 4000 characters of + // stderr deprecation noise drop stdout whole — including the very line the cause + // was picked from, leaving a buildLog extra that explains nothing. + const noise = Array.from( + { length: 60 }, + (_, i) => `(node:41) [DEP00${i}] DeprecationWarning: ${"x".repeat(90)}`, + ).join("\n"); + const { cause, tail } = execFailureDetail( + { stdout: VITE_STDOUT, stderr: noise }, + { ...BUILDER, maxTailChars: 4000 }, + ); + assert.match(cause, /Rollup failed to resolve import/); + assert.match(tail, /Rollup failed to resolve import/); + assert.match(tail, /DeprecationWarning/); + assert.ok(tail.length <= 4000 + "...".length * 2); +}); + +test("an empty stream lends its whole share to the other", () => { + const long = Array.from({ length: 60 }, (_, i) => `line ${i} ${"y".repeat(90)}`).join("\n"); + const { tail } = execFailureDetail({ stdout: long, stderr: "" }, { ...BUILDER, maxTailChars: 4000 }); + assert.ok(tail.length > 3900, `half-budget leak: ${tail.length}`); +});