diff --git a/docs/reference/cli.md b/docs/reference/cli.md index 2a65c5880..fa0d23919 100644 --- a/docs/reference/cli.md +++ b/docs/reference/cli.md @@ -271,6 +271,30 @@ For Drizzle projects, deploy performs a read-only schema drift check. If a new m Every deploy writes a structured JSONL trace to `~/.void/logs/deploy-.jsonl` regardless of `--debug`. On failure the path is printed at the end of the error message so you can attach it when reporting platform issues. `VOID_DEPLOY_DEBUG=1` is accepted as an alternate trigger for stderr mirroring. +When a deploy fails after it starts, the CLI also prints a summary of that trace under the error, so the cause is visible where the file is not — a CI runner, for example, is discarded with the job. The summary has two blocks: every `error` record with its flattened cause chain, then the last 20 records as a timeline. + +Pre-flight failures print no summary. A missing project, a rejected flag combination, or an unsupported `--backend cloudflare` feature stops before any trace exists, and each of those prints its own message explaining what to change. A build failure prints no summary either — the build streams its own output straight to the terminal. + +Void masks the credentials it emits itself: signed query parameters, bearer tokens, and any field whose key names a credential. + +Masking your own values is left to your CI platform, which holds the secrets and masks them before the log is written. GitHub Actions does this for everything under `secrets.*`. Void does not guess at credential-shaped variable names, and it does not parse credentials out of values you supplied — a password inside a `DATABASE_URL` in your build command prints as written. Register such values as CI secrets, or keep them out of the build command. + +``` +■ deploy: Deploy failed: deploy in progress +│ Deployment: dpl_7zgitxdrxxz9 +│ Detailed log: ~/.void/logs/deploy-2026-08-21T03-24-19-764Z.jsonl +│ +│ Errors +│ 9.0s deploy_server_error +│ deploymentId=dpl_7zgitxdrxxz9 +│ message=deploy in progress +│ +│ Last 20 of 26 entries +│ 8.4s info finalize_start assets=98 workers=0 +│ 8.6s info stream_deployment_id deploymentId=dpl_7zgitxdrxxz9 +│ 9.0s error deploy_server_error message=deploy in progress +``` + Project resolution precedence: 1. `--project ` diff --git a/packages/void/src/cli/deploy.ts b/packages/void/src/cli/deploy.ts index 81e939c28..e8f085182 100644 --- a/packages/void/src/cli/deploy.ts +++ b/packages/void/src/cli/deploy.ts @@ -111,6 +111,7 @@ import { } from './github-oidc.ts'; import { lintDestinationSplats, lintDuplicateSources, mergeRoutingRules } from './headers.ts'; import { openDeployLog, type CliLogger } from './log-file.ts'; +import { buildDeployLogSummary } from './log-summary.ts'; import { promptForLoginToken } from './login.ts'; import { cliTitle, createSpinner, pc } from './output.ts'; import { @@ -423,6 +424,23 @@ export async function runDeploy(root: string, options?: RunDeployOptions): Promi cliLog.info('deploy_end', { ok: true }); } catch (err) { cliLog.error('deploy_end', err, { ok: false }); + // Flush before reading the file back. The `Detailed log:` path is useless + // on a CI runner that is destroyed with the job, so inline the errors and + // the trailing timeline into the message the caller prints. + await cliLog.close().catch(() => {}); + try { + if (err instanceof Error) { + const summary = buildDeployLogSummary(cliLog.path); + if (summary) { + err.message = `${err.message}\n${summary}`; + } + } + } catch { + // A postmortem aid must never replace the failure it describes. The + // assignment alone can throw: `message` is read-only on a frozen Error + // and getter-only on a DOMException, which an aborted fetch produces. + // Losing the summary is fine; losing the deploy error is not. + } throw err; } finally { await cliLog.close().catch(() => {}); diff --git a/packages/void/src/cli/log-file.ts b/packages/void/src/cli/log-file.ts index 89238b065..b8f48cba9 100644 --- a/packages/void/src/cli/log-file.ts +++ b/packages/void/src/cli/log-file.ts @@ -15,7 +15,7 @@ export type CliLogger = { close(): Promise; }; -type ErrChainNode = { +export type ErrChainNode = { name?: string; message?: string; code?: string | number; @@ -23,6 +23,43 @@ type ErrChainNode = { cause?: ErrChainNode; }; +/** + * Flatten an already-serialized `ErrChainNode` (as read back out of a JSONL + * record) to a single inline string. Mirrors `formatErrorChainInline`, which + * does the same job for a live `Error` before it is written. + */ +export function formatErrorNodeInline( + node: ErrChainNode | string | null | undefined, + depth = 0, +): string { + // `typeof null` is `'object'`, so the null check has to come first. + if (node == null || typeof node !== 'object') { + return String(node); + } + // A JSONL record is data, not a typed value. Coerce every part instead of + // trusting the declared shape: a hand-edited log, or an `Error` subclass that + // assigned a non-string `message`, must not make a postmortem aid throw. + const message = node.message == null ? '' : String(node.message); + if (depth > 5) { + return message; + } + let head = node.name ? `${String(node.name)}: ${message}` : message; + const tags: Array = []; + if (node.code !== undefined) { + tags.push(`code=${node.code}`); + } + if (node.errno !== undefined) { + tags.push(`errno=${node.errno}`); + } + if (tags.length > 0) { + head = `${head} (${tags.join(' ')})`; + } + if (node.cause != null) { + return `${head} -> ${formatErrorNodeInline(node.cause, depth + 1)}`; + } + return head; +} + /** * Walk `err.cause` up to 6 levels and return a plain JSON-friendly chain. * Skips stack traces deliberately — keeps output line-oriented and readable. diff --git a/packages/void/src/cli/log-summary.ts b/packages/void/src/cli/log-summary.ts new file mode 100644 index 000000000..1249c1aa5 --- /dev/null +++ b/packages/void/src/cli/log-summary.ts @@ -0,0 +1,227 @@ +import { readFileSync } from 'node:fs'; +import pc from 'picocolors'; +import { type ErrChainNode, formatErrorNodeInline } from './log-file.ts'; + +/** How many trailing records the tail block shows. */ +export const LOG_TAIL_LIMIT = 20; +/** How many error records the error block shows. */ +export const LOG_ERROR_LIMIT = 5; + +const FIELD_VALUE_MAX = 80; +const LINE_MAX = 160; +const MSG_COLUMN_MAX = 28; +const ELAPSED_WIDTH = 7; +const LEVEL_WIDTH = 5; +/** Width of `' ' + elapsed + ' '`, used to indent the error sub-lines. */ +const DETAIL_INDENT = ' '.repeat(2 + ELAPSED_WIDTH + 2); + +/** + * `runDeploy` writes this record last, and its `err` field is the very message + * printed above the summary. Keeping it out of the error block avoids echoing + * the same text twice; it still shows up as one line in the tail. + */ +const TERMINAL_ERROR_MSG = 'deploy_end'; + +const RESERVED_KEYS = new Set(['ts', 'elapsedMs', 'lvl', 'msg', 'err']); + +/** + * The trace was a file the user opened by hand; the summary publishes it to + * whatever reads stderr, which in CI is a stored, often public, log. + * + * Scrubbing here covers only credentials this code emits itself — a presigned + * URL it built, an auth header it set, a field it named. Scrubbing user data is + * left to the CI platform, which owns the secrets and masks them before the log + * is written. GitHub Actions does this for everything under `secrets.*`. Void + * does not guess at credential-shaped names or at credentials embedded in + * values the user supplied. + */ +/** Query parameters whose value must never reach a CI log. */ +const SIGNED_QUERY_RE = + /([?&](?:X-Amz-[A-Za-z0-9-]+|[Ss]ignature|sig|token|access_token|key)=)[^&\s]+/g; +const BEARER_RE = /\b(Bearer\s+)\S+/g; +/** + * Field keys whose value is masked whole, whatever it looks like. `auth` is + * deliberately absent — it matches metadata keys such as `authMethod` far more + * often than credentials. + */ +const SECRET_KEY_RE = + /token|secret|password|passwd|credential|cookie|signature|api[-_]?key|private[-_]?key/i; + +type LogRecord = { + elapsedMs?: number; + lvl?: string; + msg?: string; + err?: ErrChainNode | string; + [key: string]: unknown; +}; + +function redact(text: string): string { + return text.replace(SIGNED_QUERY_RE, '$1[redacted]').replace(BEARER_RE, '$1[redacted]'); +} + +function truncate(text: string, max: number): string { + return text.length <= max ? text : `${text.slice(0, max)}...`; +} + +/** Collapse every run of whitespace so one record always renders as one line. */ +function oneLine(text: string): string { + return text.replace(/\s+/g, ' ').trim(); +} + +function stringifyValue(value: unknown): string { + if (typeof value === 'string') { + return value; + } + if (value === null || typeof value === 'number' || typeof value === 'boolean') { + return String(value); + } + try { + return JSON.stringify(value) ?? String(value); + } catch { + return String(value); + } +} + +/** Render one `key=value` pair, collapsed, redacted, and length-capped. */ +function formatField(key: string, value: unknown): string { + if (SECRET_KEY_RE.test(key)) { + return `${key}=[redacted]`; + } + return `${key}=${truncate(redact(oneLine(stringifyValue(value))), FIELD_VALUE_MAX)}`; +} + +function fieldPairs(record: LogRecord): Array { + const pairs: Array = []; + for (const [key, value] of Object.entries(record)) { + if (RESERVED_KEYS.has(key) || value === undefined) { + continue; + } + pairs.push(formatField(key, value)); + } + if (record.err !== undefined) { + pairs.push( + `err=${truncate(redact(oneLine(formatErrorNodeInline(record.err))), FIELD_VALUE_MAX)}`, + ); + } + return pairs; +} + +function formatElapsed(elapsedMs: unknown): string { + const ms = typeof elapsedMs === 'number' && Number.isFinite(elapsedMs) ? elapsedMs : 0; + return `${(ms / 1000).toFixed(1)}s`.padStart(ELAPSED_WIDTH); +} + +function colorLevel(level: string, padded: string): string { + if (level === 'error') { + return pc.red(padded); + } + if (level === 'warn') { + return pc.yellow(padded); + } + // `info` and `debug` are context, not signal — dim them so the red and + // yellow rows stand out in a wall of CI output. + return pc.dim(padded); +} + +function parseRecords(lines: Array): Array { + const records: Array = []; + for (const raw of lines) { + const trimmed = raw.trim(); + if (!trimmed) { + continue; + } + try { + const parsed: unknown = JSON.parse(trimmed); + if (parsed && typeof parsed === 'object' && !Array.isArray(parsed)) { + records.push(parsed as LogRecord); + } + } catch { + // A partially flushed or corrupt line must not hide the rest of the log. + } + } + return records; +} + +/** One aligned line: ` 8.9s error deploy_server_error message=...`. */ +function formatTailLine(record: LogRecord, msgWidth: number): string { + const level = typeof record.lvl === 'string' ? record.lvl : 'info'; + const msg = typeof record.msg === 'string' ? record.msg : ''; + const elapsed = formatElapsed(record.elapsedMs); + const paddedLevel = level.padEnd(LEVEL_WIDTH); + const paddedMsg = msg.padEnd(msgWidth); + const head = ` ${elapsed} ${paddedLevel} ${paddedMsg}`; + const fields = fieldPairs(record).join(' '); + if (!fields) { + return ` ${elapsed} ${colorLevel(level, paddedLevel)} ${msg}`; + } + const budget = Math.max(20, LINE_MAX - head.length); + return ` ${elapsed} ${colorLevel(level, paddedLevel)} ${paddedMsg} ${truncate(fields, budget)}`; +} + +/** An error entry: a headline, then one indented line per field. */ +function formatErrorEntry(record: LogRecord): Array { + const msg = typeof record.msg === 'string' ? record.msg : 'error'; + const lines = [` ${formatElapsed(record.elapsedMs)} ${pc.red(msg)}`]; + for (const pair of fieldPairs(record)) { + lines.push(`${DETAIL_INDENT}${pair}`); + } + return lines; +} + +/** + * Turn raw JSONL lines into the block appended to a failed deploy's error + * message. Returns `null` when there is nothing worth printing. + * + * The block has two parts: every `error` record with its flattened cause + * chain, then the last `LOG_TAIL_LIMIT` records for timeline context. + */ +export function formatDeployLogSummary(lines: Array): string | null { + const records = parseRecords(lines); + if (records.length === 0) { + return null; + } + + const blocks: Array = []; + + const errors = records.filter((r) => r.lvl === 'error' && r.msg !== TERMINAL_ERROR_MSG); + if (errors.length > 0) { + const shown = errors.slice(0, LOG_ERROR_LIMIT); + const errorLines = shown.flatMap((record) => formatErrorEntry(record)); + if (errors.length > shown.length) { + errorLines.push(`${DETAIL_INDENT}(+${errors.length - shown.length} more)`); + } + blocks.push([pc.bold('Errors'), ...errorLines].join('\n')); + } + + const tail = records.slice(-LOG_TAIL_LIMIT); + const msgWidth = Math.min( + MSG_COLUMN_MAX, + tail.reduce((max, r) => Math.max(max, typeof r.msg === 'string' ? r.msg.length : 0), 0), + ); + const heading = + records.length > tail.length + ? `Last ${LOG_TAIL_LIMIT} of ${records.length} entries` + : `Log (${records.length} ${records.length === 1 ? 'entry' : 'entries'})`; + blocks.push( + [pc.bold(heading), ...tail.map((record) => formatTailLine(record, msgWidth))].join('\n'), + ); + + return `\n${blocks.join('\n\n')}`; +} + +/** + * Read a deploy JSONL log and format its summary. Returns `null` for a missing + * path or any read failure — a postmortem aid must never mask the real error. + */ +export function buildDeployLogSummary(path: string | null | undefined): string | null { + if (!path) { + return null; + } + let text: string; + try { + text = readFileSync(path, 'utf-8'); + } catch { + return null; + } + return formatDeployLogSummary(text.split('\n')); +} diff --git a/packages/void/test/unit/deploy-log-summary.test.ts b/packages/void/test/unit/deploy-log-summary.test.ts new file mode 100644 index 000000000..c99d7102d --- /dev/null +++ b/packages/void/test/unit/deploy-log-summary.test.ts @@ -0,0 +1,309 @@ +import { rmSync } from 'node:fs'; +import { describe, expect, it } from 'vite-plus/test'; +import { openDeployLog } from '../../src/cli/log-file.ts'; +import { + buildDeployLogSummary, + formatDeployLogSummary, + LOG_ERROR_LIMIT, + LOG_TAIL_LIMIT, +} from '../../src/cli/log-summary.ts'; + +// picocolors enables color whenever `CI` is set or stdout is a TTY, so the +// assertions below compare against the plain text. +const ANSI = new RegExp(`${String.fromCharCode(27)}\\[[0-9;]*m`, 'g'); + +function plain(text: string | null): string { + return (text ?? '').replace(ANSI, ''); +} + +function line(record: Record): string { + return JSON.stringify({ ts: 1_700_000_000_000, ...record }); +} + +describe('formatDeployLogSummary', () => { + it('returns null when there is nothing to summarize', () => { + expect(formatDeployLogSummary([])).toBeNull(); + expect(formatDeployLogSummary(['', ' ', ''])).toBeNull(); + }); + + it('returns null when every line is malformed', () => { + expect(formatDeployLogSummary(['not json', '{"broken":'])).toBeNull(); + }); + + it('skips malformed lines but keeps the valid ones', () => { + const out = plain( + formatDeployLogSummary([ + 'not json', + line({ elapsedMs: 0, lvl: 'info', msg: 'deploy_start' }), + '{"broken":', + ]), + ); + + expect(out).toContain('deploy_start'); + expect(out).toContain('Log (1 entry)'); + }); + + it('formats a tail with elapsed seconds, level, message, and fields', () => { + const out = plain( + formatDeployLogSummary([ + line({ elapsedMs: 0, lvl: 'info', msg: 'deploy_start', dir: 'docs/.vitepress/dist' }), + line({ elapsedMs: 8412, lvl: 'info', msg: 'finalize_start', assets: 98 }), + line({ elapsedMs: 8952, lvl: 'warn', msg: 'stream_no_terminal_event' }), + ]), + ); + + expect(out).toContain('Log (3 entries)'); + expect(out).toContain('0.0s'); + expect(out).toContain('8.4s'); + expect(out).toContain('9.0s'); + expect(out).toContain('deploy_start'); + expect(out).toContain('dir=docs/.vitepress/dist'); + expect(out).toContain('assets=98'); + expect(out).toContain('warn'); + }); + + it('caps the tail and reports how many entries were dropped', () => { + const lines = Array.from({ length: LOG_TAIL_LIMIT + 5 }, (_, i) => + line({ elapsedMs: i * 100, lvl: 'info', msg: `step_${i}` }), + ); + + const out = plain(formatDeployLogSummary(lines)); + + expect(out).toContain(`Last ${LOG_TAIL_LIMIT} of ${LOG_TAIL_LIMIT + 5} entries`); + expect(out).not.toContain('step_0 '); + expect(out).toContain(`step_${LOG_TAIL_LIMIT + 4}`); + }); + + it('lists error records with their flattened cause chain', () => { + const out = plain( + formatDeployLogSummary([ + line({ elapsedMs: 10, lvl: 'info', msg: 'deploy_start' }), + line({ + elapsedMs: 8952, + lvl: 'error', + msg: 'deploy_server_error', + deploymentId: 'dpl_abc', + err: { + name: 'PlatformApiError', + message: 'Deploy failed', + code: 409, + cause: { name: 'TypeError', message: 'fetch failed' }, + }, + }), + ]), + ); + + expect(out).toContain('Errors'); + expect(out).toContain('deploy_server_error'); + expect(out).toContain('deploymentId=dpl_abc'); + expect(out).toContain('PlatformApiError: Deploy failed (code=409) -> TypeError: fetch failed'); + }); + + it('caps the error list and reports how many were dropped', () => { + const lines = Array.from({ length: LOG_ERROR_LIMIT + 2 }, (_, i) => + line({ elapsedMs: i, lvl: 'error', msg: `boom_${i}` }), + ); + + const out = plain(formatDeployLogSummary(lines)); + + expect(out).toContain('(+2 more)'); + }); + + it('omits the terminal deploy_end record from the error list', () => { + const out = plain( + formatDeployLogSummary([ + line({ elapsedMs: 10, lvl: 'error', msg: 'deploy_server_error', reason: 'in progress' }), + line({ + elapsedMs: 11, + lvl: 'error', + msg: 'deploy_end', + ok: false, + err: { name: 'Error', message: 'deploy: Deploy failed' }, + }), + ]), + ); + + const errorBlock = out.slice(out.indexOf('Errors'), out.indexOf('Log (')); + expect(errorBlock).toContain('deploy_server_error'); + expect(errorBlock).not.toContain('deploy_end'); + // Still visible in the tail, where it is a single truncated line. + expect(out).toContain('deploy_end'); + }); + + it('returns only the tail when no record has error level', () => { + const out = plain( + formatDeployLogSummary([line({ elapsedMs: 0, lvl: 'info', msg: 'deploy_start' })]), + ); + + expect(out).not.toContain('Errors'); + expect(out).toContain('Log (1 entry)'); + }); + + it('collapses newlines inside field values onto one line', () => { + const out = plain( + formatDeployLogSummary([ + line({ elapsedMs: 0, lvl: 'info', msg: 'note', detail: 'first\nsecond\n\nthird' }), + ]), + ); + + expect(out).toContain('detail=first second third'); + }); + + // Void masks the credentials it emits itself. Fields it names are its own, + // so a credential-shaped key is masked whatever the value looks like. + it('masks a field whose key names a credential', () => { + const out = plain( + formatDeployLogSummary([ + line({ + elapsedMs: 0, + lvl: 'info', + msg: 'note', + apiToken: 'sk_live_abcdef', + sessionCookie: 'sid=zzz', + privateKey: 'MIIEpAIBAAKCAQ', + slug: 'my-app', + }), + ]), + ); + + expect(out).toContain('apiToken=[redacted]'); + expect(out).toContain('sessionCookie=[redacted]'); + expect(out).toContain('privateKey=[redacted]'); + expect(out).not.toContain('sk_live_abcdef'); + expect(out).not.toContain('MIIEpAIBAAKCAQ'); + // A non-credential key keeps its value, or the tail stops being useful. + expect(out).toContain('slug=my-app'); + }); + + // Scrubbing user-supplied values is left to the CI platform, which owns the + // secrets and masks them before the log is written. Void neither guesses at + // credential-shaped names nor parses credentials out of values it was handed. + it('passes user-supplied values through unchanged', () => { + const out = plain( + formatDeployLogSummary([ + line({ + elapsedMs: 0, + lvl: 'info', + msg: 'build_start', + command: 'DATABASE_URL=postgres://appuser:hunter2@db.host/app npm run build', + }), + line({ + elapsedMs: 1, + lvl: 'info', + msg: 'note', + registry: 'https://deploy:s3cr3t@npm.internal/', + }), + ]), + ); + + expect(out).toContain('DATABASE_URL=postgres://appuser:hunter2@db.host/app npm run build'); + expect(out).toContain('https://deploy:s3cr3t@npm.internal/'); + }); + + it('leaves a credential-free URL untouched', () => { + const out = plain( + formatDeployLogSummary([ + line({ + elapsedMs: 0, + lvl: 'info', + msg: 'deploy_post', + endpoint: 'https://api.void.app/projects/prj_9k1/deploy', + }), + ]), + ); + + expect(out).toContain('https://api.void.app/projects/prj_9k1/deploy'); + expect(out).not.toContain('[redacted]'); + }); + + it('redacts signed-URL query values and bearer tokens', () => { + const out = plain( + formatDeployLogSummary([ + line({ + elapsedMs: 0, + lvl: 'info', + msg: 'r2_put_start', + url: 'https://r2.example.com/a?X-Amz-Signature=deadbeefcafe&x-id=PutObject', + auth: 'Bearer sk_live_0123456789abcdef', + }), + ]), + ); + + expect(out).not.toContain('deadbeefcafe'); + expect(out).not.toContain('sk_live_0123456789abcdef'); + expect(out).toContain('[redacted]'); + }); + + // The file is data, not a typed value. A summary that throws would replace + // the deploy failure it is supposed to explain. + it('does not throw on an ill-typed err node', () => { + const cases: Array = [ + { message: 123 }, + { name: 5, message: 'x' }, + { message: 'x', cause: 7 }, + 123, + true, + [], + {}, + ]; + + for (const err of cases) { + const out = plain( + formatDeployLogSummary([line({ elapsedMs: 0, lvl: 'error', msg: 'boom', err })]), + ); + expect(out).toContain('boom'); + } + }); + + it('renders a numeric err message rather than dropping it', () => { + const out = plain( + formatDeployLogSummary([line({ elapsedMs: 0, lvl: 'error', msg: 'boom', err: 123 })]), + ); + + expect(out).toContain('err=123'); + }); + + it('truncates a long field value', () => { + const out = plain( + formatDeployLogSummary([ + line({ elapsedMs: 0, lvl: 'info', msg: 'note', detail: 'x'.repeat(500) }), + ]), + ); + + expect(out).toContain('...'); + expect(out).not.toContain('x'.repeat(200)); + }); +}); + +describe('buildDeployLogSummary', () => { + it('returns null when there is no log path', () => { + expect(buildDeployLogSummary(null)).toBeNull(); + expect(buildDeployLogSummary(undefined)).toBeNull(); + }); + + it('returns null when the file cannot be read', () => { + expect(buildDeployLogSummary('/definitely/not/a/real/deploy-log.jsonl')).toBeNull(); + }); + + // `runDeploy` closes the logger and then reads the file straight back, so a + // record written moments earlier has to be on disk by the time close resolves. + it('reads back records a real logger wrote once close() resolves', async () => { + const cliLog = openDeployLog(); + expect(cliLog.path).not.toBeNull(); + const path = cliLog.path!; + + try { + cliLog.info('deploy_start', { dir: 'dist' }); + cliLog.error('deploy_server_error', new Error('boom'), { deploymentId: 'dpl_1' }); + await cliLog.close(); + + const out = plain(buildDeployLogSummary(path)); + expect(out).toContain('deploy_start'); + expect(out).toContain('dir=dist'); + expect(out).toContain('Errors'); + expect(out).toContain('err=Error: boom'); + } finally { + rmSync(path, { force: true }); + } + }); +});