diff --git a/docs/reference/cli/project.md b/docs/reference/cli/project.md index a9b525fb7..3ef927187 100644 --- a/docs/reference/cli/project.md +++ b/docs/reference/cli/project.md @@ -138,7 +138,7 @@ void project logs --level error --range 12h void project logs --level error --filter websocket ``` -Logs include top-level `console.*` calls and uncaught errors captured by Cloudflare Tail. If you catch an error and save it only to your database, it won't appear here. Also log it with `console.error()` or `logger.error()` from `void/log`. +Logs include top-level `console.*` calls and uncaught errors captured by Cloudflare Tail. If you catch an error and save it only to your database, it won't appear here. Also log it with `console.error()` or `logger.error()` from `void/log`. On hosted Void targets, pass the `Error` object itself to `console.error()`, as in `console.error('Save failed:', error)`, to see its stack trace under the log line. Logging only `error.message` shows no stack. For errors that never reach your Worker, such as edge routing errors or static site requests, use `void project requests --status 5xx`. diff --git a/packages/deploy-core/src/index.ts b/packages/deploy-core/src/index.ts index e7df7a761..1893d7caa 100644 --- a/packages/deploy-core/src/index.ts +++ b/packages/deploy-core/src/index.ts @@ -36,7 +36,10 @@ export type RedirectRule = { export type AssetConfig = { not_found_handling?: 'none' | 'single-page-application' | '404-page'; html_handling?: 'auto-trailing-slash' | 'force-trailing-slash' | 'drop-trailing-slash' | 'none'; - /** Native Cloudflare Workers Assets routing; ignored by managed dispatch. */ + /** + * Native Cloudflare Workers Assets routing. Managed dispatch does not route + * by it; it reads it only to tell whether the app's worker answered a request. + */ run_worker_first?: boolean | Array; }; diff --git a/packages/void/src/cli/client.ts b/packages/void/src/cli/client.ts index 5ff1ec133..f09651eae 100644 --- a/packages/void/src/cli/client.ts +++ b/packages/void/src/cli/client.ts @@ -353,8 +353,13 @@ export type SecretResponse = { export type LogEntry = { timestamp: number; outcome: string; - logs: Array<{ level: string; message: Array; timestamp: number }>; - exceptions: Array<{ name: string; message: string; timestamp: number }>; + logs: Array<{ + level: string; + message: Array; + timestamp: number; + errorInfo?: Array<{ name: string; message: string; stack?: string } | null>; + }>; + exceptions: Array<{ name: string; message: string; timestamp: number; stack?: string }>; url: string; method: string; status: string; diff --git a/packages/void/src/cli/logs.ts b/packages/void/src/cli/logs.ts index 0dc9f0379..5c1fe186d 100644 --- a/packages/void/src/cli/logs.ts +++ b/packages/void/src/cli/logs.ts @@ -1,7 +1,7 @@ import { outro, log, wrapTextWithPrefix } from '@voidzero-dev/vite-plus-prompts'; import { getToken } from './auth.ts'; import { PlatformClient, type LogEntry } from './client.ts'; -import { dim, formatCount, pc } from './output.ts'; +import { dim, errorStackFrames, formatCount, pc } from './output.ts'; import { readDeploymentPlatform, readProjectConfig } from './project.ts'; import { sanitizeTerminalLogText } from './terminal-log-text.ts'; @@ -109,7 +109,7 @@ function printEntry(entry: LogEntry): void { ); for (const l of entry.logs) { - const text = sanitizeTerminalLogText(l.message.map(String).join(' ')); + const text = formatLogMessage(l); const level = l.level ?? 'log'; const marker = level === 'error' @@ -126,7 +126,10 @@ function printEntry(entry: LogEntry): void { console.log( wrapTextWithPrefix( process.stdout, - sanitizeTerminalLogText(`${ex.name}: ${ex.message}`), + [ + sanitizeTerminalLogText(`${ex.name}: ${ex.message}`), + ...errorStackFrames(ex).map((frame) => dim(sanitizeTerminalLogText(frame))), + ].join('\n'), ' '.repeat(14), ` ${pc.red('[exception]')} `, ), @@ -134,6 +137,25 @@ function printEntry(entry: LogEntry): void { } } +/** + * Join a console call's arguments; an argument that was an `Error` is followed + * by its dimmed stack frames. Arguments and frames are app data, so each is + * sanitized before the dim style is added. + */ +function formatLogMessage(log: LogEntry['logs'][number]): string { + let text = ''; + let separator = ''; + for (const [index, value] of log.message.entries()) { + text += `${separator}${sanitizeTerminalLogText(String(value))}`; + const frames = errorStackFrames(log.errorInfo?.[index]); + if (frames.length > 0) { + text += `\n${frames.map((frame) => dim(sanitizeTerminalLogText(frame))).join('\n')}`; + } + separator = frames.length > 0 ? '\n' : ' '; + } + return text; +} + function formatTime(ts: number): string { const d = new Date(ts); return d.toLocaleTimeString('en-GB', { hour12: false }); diff --git a/packages/void/src/cli/output.ts b/packages/void/src/cli/output.ts index a7dc1b76b..7741921ac 100644 --- a/packages/void/src/cli/output.ts +++ b/packages/void/src/cli/output.ts @@ -152,3 +152,26 @@ export function ensureUtc(s: string): string { } return s + 'Z'; } + +/** + * Stack frames of an error a Worker reported, one line per frame. The log or + * exception line already shows `Name: message`, so a leading copy of that + * header is dropped; Workers send stacks both with and without it. + */ +export function errorStackFrames(error: unknown): Array { + if (!error || typeof error !== 'object') { + return []; + } + const { name, message, stack } = error as { name?: unknown; message?: unknown; stack?: unknown }; + if (typeof stack !== 'string') { + return []; + } + const header = message ? `${String(name)}: ${String(message)}` : String(name); + const frames = + stack === header + ? '' + : stack.startsWith(`${header}\n`) + ? stack.slice(header.length + 1) + : stack; + return frames.trimEnd() ? frames.trimEnd().split('\n') : []; +} diff --git a/packages/void/src/router/compile.ts b/packages/void/src/router/compile.ts index c1817734a..3f008dbe5 100644 --- a/packages/void/src/router/compile.ts +++ b/packages/void/src/router/compile.ts @@ -1,4 +1,5 @@ import { fileURLToPath } from 'node:url'; +import { relative } from 'pathslash'; import type { VoidAuthProvider } from '../auth/providers.ts'; import type { DevRedirectRule, HeaderRule } from '../cli/types.ts'; import type { NotFoundHandling } from '../config.ts'; @@ -478,25 +479,38 @@ export function compileRouteTable( lines.push(`const job${i}Crons = ${JSON.stringify(job.crons)};`); } lines.push(''); + // Workers log capture keeps only an error's own name, message and stack (not + // AggregateError.errors or cause), so each job logs its own error, with the job file + // and cron, as soon as it fails. lines.push('export async function scheduled(controller, env, ctx) {'); + lines.push(' const run = async (job, loadJob) => {'); + lines.push(' try {'); + lines.push(' const mod = await loadJob();'); + lines.push( + " if (typeof mod.default === 'function') await mod.default(controller, env, ctx);", + ); + lines.push(' } catch (error) {'); + lines.push( + ' console.error(`[void] Scheduled job ${job} failed for cron "${controller.cron}":`, error);', + ); + lines.push(' return { job, error };'); + lines.push(' }'); + lines.push(' };'); lines.push(' const tasks = [];'); for (let i = 0; i < scan.jobs.length; i++) { const job = scan.jobs[i]; const filePath = JSON.stringify(`${jobsDir}/${job.filePath}`); - lines.push(` if (job${i}Crons.includes(controller.cron)) {`); - lines.push(' tasks.push((async () => {'); - lines.push(` const mod = await import(${filePath});`); + const label = JSON.stringify(relative(options.projectRoot, `${jobsDir}/${job.filePath}`)); lines.push( - " if (typeof mod.default === 'function') await mod.default(controller, env, ctx);", + ` if (job${i}Crons.includes(controller.cron)) tasks.push(run(${label}, () => import(${filePath})));`, ); - lines.push(' })());'); - lines.push(' }'); } - lines.push(' const results = await Promise.allSettled(tasks);'); + lines.push(' const failures = (await Promise.all(tasks)).filter(Boolean);'); + lines.push(' if (failures.length) {'); lines.push( - ' const errors = results.filter(result => result.status === "rejected").map(result => result.reason);', + ' throw new AggregateError(failures.map((failure) => failure.error), `Scheduled jobs failed: ${failures.map((failure) => failure.job).join(", ")}`);', ); - lines.push(' if (errors.length) throw new AggregateError(errors, "Scheduled jobs failed");'); + lines.push(' }'); lines.push('}'); lines.push(''); } else { diff --git a/packages/void/test/unit/logs-rendering.test.ts b/packages/void/test/unit/logs-rendering.test.ts index 01c066a0d..629474ccf 100644 --- a/packages/void/test/unit/logs-rendering.test.ts +++ b/packages/void/test/unit/logs-rendering.test.ts @@ -197,3 +197,145 @@ it('keeps color codes, newlines and tabs, and removes other escape sequences who expect(sanitizeTerminalLogText('\u009b2J\u0085\u007f\u0000\u0008end')).toBe('2Jend'); expect(sanitizeTerminalLogText('plain text, ünïcode ✓')).toBe('plain text, ünïcode ✓'); }); + +it('prints stack frames under the error that logged them', async () => { + logsFixture.entries = [ + { + timestamp: 0, + method: 'GET', + url: '/sponsors.svg', + status: '500', + outcome: 'ok', + logs: [ + { + level: 'error', + message: ["TypeError: Cannot read properties of undefined (reading 'href')"], + errorInfo: [ + { + name: 'TypeError', + message: "Cannot read properties of undefined (reading 'href')", + stack: ' at assets/resvg.js:14881:64\n at assets/resvg.js:15409:3', + }, + ], + }, + { + level: 'error', + message: ['Render failed:', 'Error: font missing', 'retrying'], + errorInfo: [ + null, + { + name: 'Error', + message: 'font missing', + stack: 'Error: font missing\n at render (index.js:10:5)', + }, + null, + ], + }, + { + level: 'error', + message: ['Error'], + errorInfo: [{ name: 'Error', message: '', stack: 'Error\n at g (y.js:2:2)' }], + }, + { + level: 'warn', + message: ['Error: retry later'], + errorInfo: [{ name: 'Error', message: 'retry later' }], + }, + ], + exceptions: [ + { + name: 'Error', + message: 'Worker threw', + stack: 'Error: Worker threw\n at fetch (index.js:1:1)', + }, + { name: 'Error', message: 'boom', stack: 'Error: boom' }, + { name: 'Error', message: 'Worker exceeded CPU time limit.' }, + ], + }, + ]; + const output = Object.assign( + new Writable({ + write(_chunk, _encoding, callback) { + callback(); + }, + }), + { columns: 120 }, + ); + vi.spyOn(process, 'stdout', 'get').mockReturnValue(output as typeof process.stdout); + const print = vi.spyOn(console, 'log').mockImplementation(() => {}); + await runLogsCommand('/fixture', '', '1h'); + const messages = print.mock.calls.map((args) => String(args[0] ?? '')); + const header = messages.findIndex((line) => line.includes('/sponsors.svg')); + expect(header).toBeGreaterThanOrEqual(0); + expect( + messages.slice(header + 1).flatMap((message) => stripVTControlCharacters(message).split('\n')), + ).toEqual([ + " [error] TypeError: Cannot read properties of undefined (reading 'href')", + ' at assets/resvg.js:14881:64', + ' at assets/resvg.js:15409:3', + ' [error] Render failed: Error: font missing', + ' at render (index.js:10:5)', + ' retrying', + ' [error] Error', + ' at g (y.js:2:2)', + ' [warn] Error: retry later', + ' [exception] Error: Worker threw', + ' at fetch (index.js:1:1)', + ' [exception] Error: boom', + ' [exception] Error: Worker exceeded CPU time limit.', + ]); + expect(messages.join('\n')).toContain('\x1b[2m at assets/resvg.js:14881:64'); +}); + +it('drops terminal control sequences from stack frames', async () => { + logsFixture.entries = [ + { + timestamp: 0, + method: 'GET', + url: '/sponsors.svg', + status: '500', + outcome: 'exception', + logs: [ + { + level: 'error', + message: ['Error: boom'], + errorInfo: [ + { + name: 'Error', + message: 'boom', + stack: 'Error: boom\n at \x1b]52;c;ZXZpbA==\x07f (a.js:1:1)\x1b[2J\r', + }, + ], + }, + ], + exceptions: [ + { + name: 'Error', + message: 'x', + stack: + 'Error: x\n at \x1b]8;;https://evil.example\x07g\x1b]8;;\x07 (b.js:2:2)\u009b2J', + }, + ], + }, + ]; + const output = Object.assign( + new Writable({ + write(_chunk, _encoding, callback) { + callback(); + }, + }), + { columns: 120 }, + ); + vi.spyOn(process, 'stdout', 'get').mockReturnValue(output as typeof process.stdout); + const print = vi.spyOn(console, 'log').mockImplementation(() => {}); + await runLogsCommand('/fixture', '', '1h'); + + const printed = print.mock.calls.map((args) => String(args[0] ?? '')).join('\n'); + for (const unsafe of ['\x1b]', '\x1b[2J', '\r', '\x07', '\u009b']) { + expect(printed).not.toContain(unsafe); + } + expect(printed).not.toContain('evil.example'); + const plain = stripVTControlCharacters(printed); + expect(plain).toContain(' at f (a.js:1:1)'); + expect(plain).toContain(' at g (b.js:2:2)2J'); +}); diff --git a/packages/void/test/unit/scheduled-dispatch.test.ts b/packages/void/test/unit/scheduled-dispatch.test.ts index bc9d84e5f..7f42c58e2 100644 --- a/packages/void/test/unit/scheduled-dispatch.test.ts +++ b/packages/void/test/unit/scheduled-dispatch.test.ts @@ -2,7 +2,7 @@ import { mkdirSync, mkdtempSync, rmSync, writeFileSync } from 'node:fs'; import { tmpdir } from 'node:os'; import { join } from 'node:path'; import { pathToFileURL } from 'node:url'; -import { afterEach, expect, it } from 'vite-plus/test'; +import { afterEach, expect, it, vi } from 'vite-plus/test'; import { generateWrapper } from '../../src/cli/wrapper.ts'; import { compileRouteTable } from '../../src/router/compile.ts'; @@ -11,6 +11,7 @@ afterEach(() => { for (const root of roots.splice(0)) { rmSync(root, { recursive: true, force: true }); } + vi.restoreAllMocks(); }); const jobs = [ { name: 'first', filePath: 'first.mjs', crons: ['* * * * *', '* * * * *'] }, @@ -18,6 +19,44 @@ const jobs = [ { name: 'other', filePath: 'other.mjs', crons: ['0 1 * * *'] }, ]; type JobEnv = { calls: Array; fail: boolean }; +type Scheduled = (controller: { cron: string }, env: JobEnv, ctx: object) => Promise; +type LoadJob = ( + path: string, +) => Promise<{ default: (controller: unknown, env: JobEnv) => Promise }>; + +function compileNativeScheduled(jobsDir: string, load: LoadJob): Scheduled { + const code = compileRouteTable( + { + routes: [], + middleware: [], + jobs, + queues: [], + pages: { pages: [], layouts: [], namedLayouts: [] }, + }, + '/routes', + '/middleware', + jobsDir, + '/queues', + null, + { + honoPath: '/hono', + runtimeEnvPath: '/env', + projectRoot: '/project', + homeDir: '/home', + reactRefresh: false, + auth: null, + }, + ); + const source = code.slice( + code.indexOf('const job0Crons'), + code.indexOf('const __scheduledHandler'), + ); + return new Function( + 'load', + source.replace('export async function', 'async function').replaceAll('import(', 'load(') + + '\nreturn scheduled;', + )(load); +} it('authenticates framework cron HTTP requests while leaving native events usable', async () => { const root = mkdtempSync(join(tmpdir(), 'void-cron-auth-')); @@ -71,40 +110,9 @@ it('authenticates framework cron HTTP requests while leaving native events usabl it.each(['native', 'framework'])( '%s executes every matching job once and waits for siblings after failure', async (kind) => { - let scheduled: (controller: { cron: string }, env: JobEnv, ctx: object) => Promise; + let scheduled: Scheduled; if (kind === 'native') { - const code = compileRouteTable( - { - routes: [], - middleware: [], - jobs, - queues: [], - pages: { pages: [], layouts: [], namedLayouts: [] }, - }, - '/routes', - '/middleware', - '/crons', - '/queues', - null, - { - honoPath: '/hono', - - runtimeEnvPath: '/env', - projectRoot: '/project', - homeDir: '/home', - reactRefresh: false, - auth: null, - }, - ); - const source = code.slice( - code.indexOf('const job0Crons'), - code.indexOf('const __scheduledHandler'), - ); - scheduled = new Function( - 'load', - source.replace('export async function', 'async function').replaceAll('import(', 'load(') + - '\nreturn scheduled;', - )(async (path: string) => ({ + scheduled = compileNativeScheduled('/project/crons', async (path) => ({ default: async (_controller: unknown, env: JobEnv) => { const name = path.split('/').pop()!.replace('.mjs', ''); if (name === 'second') { @@ -149,3 +157,80 @@ it.each(['native', 'framework'])( expect(env.calls).toEqual([]); }, ); + +it.each([ + ['crons', '/project/crons'], + ['src/crons', '/project/src/crons'], +])('logs each failed job under %s with its cron and original error', async (dir, jobsDir) => { + const errorLog = vi.spyOn(console, 'error').mockImplementation(() => {}); + const failure = new TypeError('first failed'); + const scheduled = compileNativeScheduled(jobsDir, async (path) => ({ + default: async (_controller: unknown, env: JobEnv) => { + if (!env.fail) { + return; + } + if (path.endsWith('/first.mjs')) { + await new Promise((resolve) => setTimeout(resolve, 2)); + throw failure; + } + if (path.endsWith('/second.mjs')) { + throw 'second failed'; + } + }, + })); + const env: JobEnv = { calls: [], fail: false }; + await scheduled({ cron: '* * * * *' }, env, {}); + expect(errorLog).not.toHaveBeenCalled(); + + env.fail = true; + const rejection = await scheduled({ cron: '* * * * *' }, env, {}).catch( + (error: unknown) => error, + ); + expect(rejection).toBeInstanceOf(AggregateError); + const { errors, message } = rejection as AggregateError; + expect(message).toBe(`Scheduled jobs failed: ${dir}/first.mjs, ${dir}/second.mjs`); + expect(errors).toHaveLength(2); + expect(errors[0]).toBe(failure); + expect(errors[1]).toBe('second failed'); + expect(errorLog.mock.calls).toHaveLength(2); + expect(errorLog.mock.calls[0][0]).toBe( + `[void] Scheduled job ${dir}/second.mjs failed for cron "* * * * *":`, + ); + expect(errorLog.mock.calls[0][1]).toBe('second failed'); + expect(errorLog.mock.calls[1][0]).toBe( + `[void] Scheduled job ${dir}/first.mjs failed for cron "* * * * *":`, + ); + expect(errorLog.mock.calls[1][1]).toBe(failure); +}); + +it('names a job whose module fails to load and waits for the other jobs', async () => { + const errorLog = vi.spyOn(console, 'error').mockImplementation(() => {}); + const failure = new SyntaxError('module failed to load'); + const scheduled = compileNativeScheduled('/project/crons', async (path) => { + if (path.endsWith('/first.mjs')) { + throw failure; + } + return { + default: async (_controller: unknown, env: JobEnv) => { + await new Promise((resolve) => setTimeout(resolve, 2)); + env.calls.push(path.split('/').pop()!.replace('.mjs', '')); + }, + }; + }); + const env: JobEnv = { calls: [], fail: false }; + + const rejection = await scheduled({ cron: '* * * * *' }, env, {}).catch( + (error: unknown) => error, + ); + expect(env.calls).toEqual(['second']); + expect(rejection).toBeInstanceOf(AggregateError); + const { errors, message } = rejection as AggregateError; + expect(message).toBe('Scheduled jobs failed: crons/first.mjs'); + expect(errors).toHaveLength(1); + expect(errors[0]).toBe(failure); + expect(errorLog.mock.calls).toHaveLength(1); + expect(errorLog.mock.calls[0][0]).toBe( + '[void] Scheduled job crons/first.mjs failed for cron "* * * * *":', + ); + expect(errorLog.mock.calls[0][1]).toBe(failure); +}); diff --git a/platform/packages/dispatch/src/index.ts b/platform/packages/dispatch/src/index.ts index 69f4a7778..584d89c23 100644 --- a/platform/packages/dispatch/src/index.ts +++ b/platform/packages/dispatch/src/index.ts @@ -1136,8 +1136,8 @@ export default { // Pages protocol (X-VoidPages) uses a separate JSON edge cache; HTML uses KV+edge. // ISR applies to SSR page paths only. An API route or an asset-extension // path that happens to match a catch-all page pattern must render live and - // never enter the ISR cache — mirrors the write-back guard (requestType === - // 'ssr') below and how meta-frameworks resolve API routes to non-ISR outputs. + // never enter the ISR cache — mirrors the write-back path check below and + // how meta-frameworks resolve API routes to non-ISR outputs. const isSsrPath = routing.ssr === true && (routing.type !== 'framework' || isFrameworkDocumentRequest(request)) && @@ -1488,9 +1488,12 @@ export default { // shared representation. For SSR deployments, a dotted path is only a // candidate when the emitted asset manifest positively identifies it. const staticCachePathname = pathname; - const isStaticCandidate = - isStaticCacheRequestEligible(request, staticCachePathname, routing) && - (await isKnownStaticAssetPath(env, staticCachePathname, routing, timeoutMs)); + // `false` only when this SSR deploy's asset manifest was read and no asset + // answers the path. Metering reuses it to label app routes. + const knownStaticAsset = isStaticCacheRequestEligible(request, staticCachePathname, routing) + ? await isKnownStaticAssetPath(env, staticCachePathname, routing, timeoutMs) + : undefined; + const isStaticCandidate = knownStaticAsset === true; let staticCacheKey: Request | undefined; if (isStaticCandidate) { @@ -1816,8 +1819,17 @@ export default { return meter(clientRevalidateResponse(finalRes), responseFailureKind); } - // Classify for metering - const dynamicType = classifyDynamicRequestType(pathname, routing.ssr); + // Classify for metering. A path with a file extension is the app's only when + // the worker, not Cloudflare's asset layer, answered it, and either the + // manifest answer for this exact path says it is not a deployed file or the + // response is a server error. Platform asset failures carry a failure kind + // and keep the default. + const listedAsset = pathname === staticCachePathname ? knownStaticAsset : undefined; + const handledByApp = + !responseFailureKind && + workerAnsweredPath(routing, listedAsset) && + (listedAsset === false || response.status >= 500); + const dynamicType = classifyDynamicRequestType(pathname, routing.ssr, handledByApp); if (dynamicType) { requestType = dynamicType; } @@ -1845,12 +1857,14 @@ export default { // Config TTL is the gatekeeper — worker x-revalidate can reduce but not enable ISR const isrTtl = configTtl > 0 ? resolveRevalidateTtl(response, configTtl) : 0; // Only a full 200 is cacheable — `.ok` (200–299) would let a 206 poison the entry. - // `requestType` was reclassified above from the POST-fallback pathname, so - // `=== 'ssr'` already skips a fallback that rewrote to `/api` — the same - // `/api` exclusion the miss-write and background-revalidation sites spell out - // with `!isApiPath(effective…)`. (This SSR-path gate is stricter than those two: + // `pathname` is the POST-fallback pathname, so the SSR path check below + // already skips a fallback that rewrote to `/api` — the same `/api` exclusion + // the miss-write and background-revalidation sites spell out with + // `!isApiPath(effective…)`. (This SSR-path gate is stricter than those two: // it also skips extension targets, but requests reaching this branch are not // the ssr+revalidate ISR-ladder path where SPA `/index.html` fallbacks cache.) + // A path with a file extension never enters the ISR cache here, even when + // metering labels it `ssr` because the app's own route answered. // // Fallback positive-ID gate — the same one the miss-write and background sites // enforce: when a FALLBACK rewrote this request, the render may enter the shared @@ -1866,7 +1880,9 @@ export default { if ( isrTtl > 0 && response.status === 200 && - requestType === 'ssr' && + routing.ssr && + !isApiPath(pathname) && + !hasExtension(pathname) && (routing.type !== 'framework' || isHtmlResponse(response)) && !hasSharedCacheOptOut(response) && (!writebackFallbackApplied || @@ -1912,7 +1928,16 @@ export default { if (err.label === 'static-asset') { return meterStaticAssetFailure(PLATFORM_STATIC_ASSET_TIMEOUT); } - const dynamicType = classifyDynamicRequestType(pathname, routing.ssr); + // The dispatched request was still running when the budget ran out. It + // counts as the app's when the worker, not the asset layer, owns the path. + const dynamicType = classifyDynamicRequestType( + pathname, + routing.ssr, + workerAnsweredPath( + routing, + pathname === staticCachePathname ? knownStaticAsset : undefined, + ), + ); if (dynamicType) { requestType = dynamicType; } @@ -2525,12 +2550,24 @@ function isStaticCacheRequestEligible( ); } +/** + * Whether `pathname` may use the deploy-versioned static cache. + * + * - `true`: a static deploy, a non-SSR deploy, or a path the SSR deploy's asset + * manifest lists. + * - `false`: the SSR deploy's asset manifest was read, does not list the path, + * and lists no HTML file Cloudflare's `html_handling` would answer it from. + * - `undefined`: there is no manifest to consult, it could not be read, or + * `html_handling` would answer the path from a listed HTML file. + * + * Only `true` makes a request a static-cache candidate. + */ async function isKnownStaticAssetPath( env: Env, pathname: string, routing: RoutingEntry, timeoutMs: number, -): Promise { +): Promise { if (routing.staticDeploymentId) { return true; } @@ -2538,7 +2575,7 @@ async function isKnownStaticAssetPath( return true; } if (!routing.assetManifestId) { - return false; + return undefined; } try { const manifest = await fetchAssetManifest( @@ -2548,18 +2585,78 @@ async function isKnownStaticAssetPath( Math.min(timeoutMs, STATIC_ASSET_HEDGE_DELAY_MS), ); if (!manifest) { - return false; + return undefined; } if (Object.hasOwn(manifest, pathname)) { return true; } const decoded = safeDecodePathname(pathname); - return decoded !== pathname && Object.hasOwn(manifest, decoded); + if (decoded !== pathname && Object.hasOwn(manifest, decoded)) { + return true; + } + // Not a listed file, but Cloudflare's asset layer may still serve or + // redirect it from an HTML file, so it is not known to be the worker's. + const htmlHandling = routing.assetConfig?.html_handling ?? 'auto-trailing-slash'; + if ( + htmlHandling !== 'none' && + (hasHtmlHandlingSource(manifest, pathname) || hasHtmlHandlingSource(manifest, decoded)) + ) { + return undefined; + } + return false; } catch { // Asset identity is an optimization gate. If the manifest is unavailable, // dispatch the request live instead of guessing from the URL or response. - return false; + return undefined; + } +} + +/** + * Whether the manifest lists an HTML file that Cloudflare's `html_handling` + * serves or redirects to for `pathname`: `/x` from `/x.html` or + * `/x/index.html`, `/x.html` from `/x/index.html`, and `/x/index.html` from + * `/x.html`. Every mode except `none` reads these same files. + */ +function hasHtmlHandlingSource(manifest: Record, pathname: string): boolean { + const sources = [`${pathname}.html`, `${pathname}/index.html`]; + if (pathname.endsWith('.html')) { + const base = pathname.slice(0, -'.html'.length); + sources.push(`${base}/index.html`); + if (base.endsWith('/index')) { + sources.push(`${base.slice(0, -'/index'.length)}.html`); + } + } + return sources.some((source) => Object.hasOwn(manifest, source)); +} + +/** + * Whether the user worker, not Cloudflare's asset layer, answers `pathname`. + * `listed` is the asset manifest's answer for the path (see + * `isKnownStaticAssetPath`). + * + * A worker deploy published since asset manifests were introduced has no + * manifest only when it uploaded no files, so the worker answers everything. + * So does a deploy whose `run_worker_first` covers every path. Older live + * deploys may still have an asset layer without a manifest, so callers use a + * `true` here for a successful response only when the manifest also marks the + * path unlisted. Otherwise the asset layer serves listed files itself, and an + * unlisted path reaches the worker only with `not_found_handling: 'none'` + * (Cloudflare's default); the SPA shell and the 404 page come from the asset + * layer. When `listed` is `undefined` (no readable manifest, or an HTML file the + * asset layer answers the path from), the path is not known to be the worker's. + */ +function workerAnsweredPath(routing: RoutingEntry, listed: boolean | undefined): boolean { + if (!routing.assetManifestId) { + return true; + } + const runWorkerFirst = routing.assetConfig?.run_worker_first; + if ( + runWorkerFirst === true || + (Array.isArray(runWorkerFirst) && runWorkerFirst.includes('/**')) + ) { + return true; } + return listed === false && (routing.assetConfig?.not_found_handling ?? 'none') === 'none'; } /** Apply the same origin/cached response policy to static reads and writes. */ diff --git a/platform/packages/dispatch/src/request-type.ts b/platform/packages/dispatch/src/request-type.ts index d64c90565..683d786cd 100644 --- a/platform/packages/dispatch/src/request-type.ts +++ b/platform/packages/dispatch/src/request-type.ts @@ -22,15 +22,24 @@ export function isApiPath(pathname: string): boolean { * default ('static'/'websocket'). Used on BOTH the success path and the dispatch * TIMEOUT path so timed-out /api and SSR requests are metered with the right type * instead of collapsing into the 'static' bucket. + * + * An SSR worker also serves the deploy's static files, so a path with a file + * extension keeps the default unless `handledByApp` is true, meaning the caller + * knows the app's own code answered. That needs the worker, not Cloudflare's + * asset layer, to have answered the path, and then either the asset manifest + * was read and does not list it (a route such as `routes/og.png.ts`), or the + * worker returned a server error or ran past the dispatch budget. A successful + * response with no manifest answer keeps the default. */ export function classifyDynamicRequestType( pathname: string, ssr: boolean | undefined, + handledByApp = false, ): RequestType | null { if (isApiPath(pathname)) { return 'api'; } - if (ssr && !hasExtension(pathname)) { + if (ssr && (!hasExtension(pathname) || handledByApp)) { return 'ssr'; } return null; diff --git a/platform/packages/dispatch/test/request-type.test.ts b/platform/packages/dispatch/test/request-type.test.ts index a5f3f9e51..09df7ceb5 100644 --- a/platform/packages/dispatch/test/request-type.test.ts +++ b/platform/packages/dispatch/test/request-type.test.ts @@ -44,6 +44,22 @@ describe('classifyDynamicRequestType', () => { expect(classifyDynamicRequestType('/logo.png', true)).toBe(null); }); + it("classifies an ssr path with a file extension as 'ssr' when the app answered", () => { + expect(classifyDynamicRequestType('/sponsors.svg', true, true)).toBe('ssr'); + }); + + it('returns null for an ssr path with a file extension the app did not answer', () => { + expect(classifyDynamicRequestType('/logo.png', true, false)).toBe(null); + }); + + it('returns null for a non-ssr path the app answered (keep default)', () => { + expect(classifyDynamicRequestType('/sponsors.svg', false, true)).toBe(null); + }); + + it("classifies an '/api' path with a file extension as 'api' when the app answered", () => { + expect(classifyDynamicRequestType('/api/data.json', true, true)).toBe('api'); + }); + it('returns null for a non-ssr dynamic path (keep default)', () => { expect(classifyDynamicRequestType('/dashboard', false)).toBe(null); }); diff --git a/platform/packages/dispatch/test/unit/index.test.ts b/platform/packages/dispatch/test/unit/index.test.ts index c64b9991b..d0f6b9ed0 100644 --- a/platform/packages/dispatch/test/unit/index.test.ts +++ b/platform/packages/dispatch/test/unit/index.test.ts @@ -49,6 +49,11 @@ type RoutingEntry = { hashedAssetsPrefix?: string; staticDeploymentId?: string; assetManifestId?: string; + assetConfig?: { + not_found_handling?: 'none' | 'single-page-application' | '404-page'; + html_handling?: 'auto-trailing-slash' | 'force-trailing-slash' | 'drop-trailing-slash' | 'none'; + run_worker_first?: boolean | Array; + }; headerRules?: Array<{ pattern: string; headers: Array<[string, string]> }>; redirectRules?: Array<{ source: string; destination: string; status: number; host?: string }>; fallbackRules?: Array<{ source: string; destination: string; status: number; host?: string }>; @@ -6641,3 +6646,476 @@ it.each(['requests', 'execution'] as const)( expect(workerFetch).toHaveBeenCalledTimes(resource === 'requests' ? 0 : 1); }, ); + +function meteredRequestType(analyticsWrites: Array): string | undefined { + expect(analyticsWrites).toHaveLength(1); + return (analyticsWrites[0] as { blobs: Array }).blobs[1]; +} + +describe('request type metering for SSR routes with a file extension', () => { + // An SSR worker answers both the app's routes and the deploy's static files. + // A route such as `routes/sponsors.svg.ts` has a file extension, so its label + // comes from the asset manifest or from how the worker answered, never from + // the path alone. Void SSR deploys run the worker first for every path. + const routing: RoutingEntry = { + workerName: 'user-app-dpl_1', + projectId: 'proj_1', + type: 'void', + ssr: true, + version: 'deploy-1', + assetManifestId: 'deploy-1', + assetConfig: { not_found_handling: 'none', run_worker_first: ['/**'] }, + }; + const routingWithoutManifest: RoutingEntry = { + workerName: 'user-app-dpl_1', + projectId: 'proj_1', + type: 'void', + ssr: true, + version: 'deploy-1', + }; + const assetManifest = { '/robots.txt': 'robots-hash' }; + + function svgResponse(): Response { + return new Response('', { headers: { 'Content-Type': 'image/svg+xml' } }); + } + + it.each(['/sponsors.svg', '/support-matrix.png?theme=dark'])( + 'labels the route at %s as ssr when the asset manifest does not list it', + async (path) => { + const { env, workerFetch, analyticsWrites } = createEnv({ + routing, + assetManifest, + workerResponse: svgResponse(), + }); + + const response = await app.fetch( + new Request(`https://my-app.void.app${path}`), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(workerFetch).toHaveBeenCalledOnce(); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }, + ); + + // A plain GET goes through the static cache. The other requests skip it, so + // the worker's answer is labeled without the manifest's. + it.each<[string, RequestInit]>([ + ['a plain GET', {}], + ['a GET with a cookie', { headers: { Cookie: 'a=1' } }], + ['a HEAD request', { method: 'HEAD' }], + ['a Range request', { headers: { Range: 'bytes=0-3' } }], + ])('keeps a file listed in the asset manifest as static for %s', async (_, init) => { + const { env, workerFetch, analyticsWrites } = createEnv({ + routing, + assetManifest, + workerResponse: new Response('User-agent: *', { headers: { 'Content-Type': 'text/plain' } }), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/robots.txt', init), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(workerFetch).toHaveBeenCalledOnce(); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }); + + it.each([ + ['is missing', async () => null], + [ + 'cannot be read', + async () => { + throw new Error('KV unavailable'); + }, + ], + ])('keeps a successful response static when the asset manifest %s', async (_, readManifest) => { + const created = createEnv({ + routing, + assetManifest, + workerResponse: new Response('User-agent: *', { headers: { 'Content-Type': 'text/plain' } }), + }); + const readRouting = created.env.ROUTING.get.bind(created.env.ROUTING); + const env = { + ...created.env, + ROUTING: { + get: (key: string) => (key.startsWith('manifest:') ? readManifest() : readRouting(key)), + }, + } as unknown as Env; + const error = vi.spyOn(console, 'error').mockImplementation(() => {}); + + try { + const response = await app.fetch( + new Request('https://my-app.void.app/robots.txt'), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(created.workerFetch).toHaveBeenCalledOnce(); + expect(meteredRequestType(created.analyticsWrites)).toBe('static'); + } finally { + error.mockRestore(); + } + }); + + it('keeps a successful response static when the deploy has no asset manifest', async () => { + const { env, analyticsWrites } = createEnv({ + routing: routingWithoutManifest, + workerResponse: svgResponse(), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/sponsors.svg'), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }); + + // A deploy that uploaded no static files has no asset layer, so the worker + // answered the path. + it('labels a route server error as ssr when the deploy has no asset manifest', async () => { + const { env, analyticsWrites } = createEnv({ + routing: routingWithoutManifest, + workerResponse: new Response('boom', { status: 500 }), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/sponsors.svg'), + env, + createCtx(), + ); + + expect(response.status).toBe(500); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + it('labels a route that runs past the dispatch budget as ssr when the deploy has no asset manifest', async () => { + const { env, analyticsWrites } = createEnv({ + routing: routingWithoutManifest, + // Never settles, so the dispatch budget runs out first. + workerFetchImpl: () => new Promise(() => {}), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/sponsors.svg'), + { ...env, DISPATCH_TIMEOUT_MS: '20' } as Env, + createCtx(), + ); + + expect(response.status).toBe(503); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + it.each<[string, RequestInit]>([ + ['a HEAD request', { method: 'HEAD' }], + ['a GET with a cookie', { headers: { Cookie: 'a=1' } }], + ])('labels a route server error from %s as ssr without reading the manifest', async (_, init) => { + const { env, analyticsWrites } = createEnv({ + routing, + assetManifest, + workerResponse: new Response('boom', { status: 500 }), + }); + const routingGet = vi.spyOn(env.ROUTING, 'get'); + + const response = await app.fetch( + new Request('https://my-app.void.app/sponsors.svg', init), + env, + createCtx(), + ); + + expect(response.status).toBe(500); + expect(routingGet.mock.calls.some(([key]) => String(key).startsWith('manifest:'))).toBe(false); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + it.each([ + ['an asset manifest that does not list the path', routing], + ['no asset manifest', routingWithoutManifest], + ])('keeps a platform asset failure static on a deploy with %s', async (_, deployRouting) => { + const stubBody = 'Assets have not yet been deployed to this script.\n'; + const { env, analyticsWrites } = createEnv({ + routing: deployRouting, + assetManifest, + workerResponse: new Response(stubBody, { + status: 200, + headers: { + 'Content-Type': 'text/plain;charset=UTF-8', + 'Content-Length': String(stubBody.length), + }, + }), + }); + const error = vi.spyOn(console, 'error').mockImplementation(() => {}); + + try { + const response = await app.fetch( + new Request('https://my-app.void.app/sponsors.svg'), + env, + createCtx(), + ); + + expect(response.status).toBe(503); + expect(response.headers.get('X-Void-Storage-Error')).toBe('static-asset-missing'); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + expect((analyticsWrites[0] as { blobs: Array }).blobs[5]).toBe( + 'platform-static-asset-missing', + ); + } finally { + error.mockRestore(); + } + }); + + it('labels a route that runs past the dispatch budget as ssr', async () => { + const { env, analyticsWrites } = createEnv({ + routing, + assetManifest, + // Never settles, so the dispatch budget runs out first. + workerFetchImpl: () => new Promise(() => {}), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/sponsors.svg', { headers: { Cookie: 'a=1' } }), + { ...env, DISPATCH_TIMEOUT_MS: '20' } as Env, + createCtx(), + ); + + expect(response.status).toBe(503); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + it('keeps a route with a file extension out of the ISR cache', async () => { + const { env, kvStore, analyticsWrites } = createEnv({ + routing: { ...routing, revalidate: 60 }, + assetManifest, + workerResponse: svgResponse(), + }); + const ctx = createCtx(); + + const response = await app.fetch(new Request('https://my-app.void.app/sponsors.svg'), env, ctx); + await Promise.all((ctx.waitUntil as ReturnType).mock.calls.map((c) => c[0])); + + expect(response.status).toBe(200); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + expect([...kvStore.keys()].some((key) => key.includes('/sponsors.svg'))).toBe(false); + expect(edgeCacheStore.size).toBe(0); + }); +}); + +describe('request type metering when Cloudflare serves assets before the worker', () => { + // Unless `run_worker_first` covers every path, Cloudflare's asset layer + // serves listed files without running the worker. An unlisted path reaches + // the worker only with `not_found_handling: 'none'`; a SPA deploy gets the + // shell from the asset layer instead. + const assetFirstRouting: RoutingEntry = { + workerName: 'user-app-dpl_1', + projectId: 'proj_1', + type: 'framework', + ssr: true, + version: 'deploy-1', + assetManifestId: 'deploy-1', + assetConfig: { not_found_handling: 'none' }, + }; + const spaWithApiRouting: RoutingEntry = { + workerName: 'user-app-dpl_1', + projectId: 'proj_1', + type: 'void', + ssr: true, + version: 'deploy-1', + assetManifestId: 'deploy-1', + assetConfig: { + not_found_handling: 'single-page-application', + run_worker_first: ['/api', '/api/*', '/__void', '/__void/*'], + }, + }; + const assetManifest = { '/index.html': 'shell-hash', '/robots.txt': 'robots-hash' }; + const deploys = [ + ['an asset-first deploy', assetFirstRouting], + ['a SPA deploy with API routes', spaWithApiRouting], + ] as const; + + it('labels an unlisted path as ssr when the worker answers it', async () => { + const { env, analyticsWrites } = createEnv({ + routing: assetFirstRouting, + assetManifest, + workerResponse: new Response('png', { headers: { 'Content-Type': 'image/png' } }), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/og.png'), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + it('labels an unlisted path that runs past the dispatch budget as ssr', async () => { + const { env, analyticsWrites } = createEnv({ + routing: assetFirstRouting, + assetManifest, + // Never settles, so the dispatch budget runs out first. + workerFetchImpl: () => new Promise(() => {}), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/og.png'), + { ...env, DISPATCH_TIMEOUT_MS: '20' } as Env, + createCtx(), + ); + + expect(response.status).toBe(503); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + // Cloudflare's default `html_handling` also serves or redirects a path from + // an HTML file the manifest lists under another name. + it.each([ + ['/docs/v1.2', '/docs/v1.2.html', 200], + ['/docs/v1.2', '/docs/v1.2/index.html', 307], + ['/about.html', '/about/index.html', 307], + ['/about/index.html', '/about.html', 307], + ['/docs/release%20v1.2', '/docs/release v1.2.html', 200], + ])('keeps %s static when the asset layer answers it from %s', async (path, file, status) => { + const { env, analyticsWrites } = createEnv({ + routing: assetFirstRouting, + assetManifest: { ...assetManifest, [file]: 'page-hash' }, + workerResponse: + status === 200 + ? new Response('page', { headers: { 'Content-Type': 'text/html' } }) + : new Response(null, { status, headers: { Location: '/' } }), + }); + + const response = await app.fetch( + new Request(`https://my-app.void.app${path}`), + env, + createCtx(), + ); + + expect(response.status).toBe(status); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }); + + it('labels an unlisted path as ssr when html_handling is none', async () => { + const { env, analyticsWrites } = createEnv({ + routing: { + ...assetFirstRouting, + assetConfig: { not_found_handling: 'none', html_handling: 'none' }, + }, + assetManifest: { ...assetManifest, '/docs/v1.2.html': 'page-hash' }, + workerResponse: new Response('route', { + headers: { 'Content-Type': 'text/html' }, + }), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/docs/v1.2'), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(meteredRequestType(analyticsWrites)).toBe('ssr'); + }); + + it('keeps the SPA shell served for an unlisted path static', async () => { + const { env, analyticsWrites } = createEnv({ + routing: spaWithApiRouting, + assetManifest, + workerResponse: new Response('shell', { + headers: { 'Content-Type': 'text/html' }, + }), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/old-page.html'), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }); + + it.each(deploys)('keeps a server error for a listed file static on %s', async (_, routing) => { + const { env, analyticsWrites } = createEnv({ + routing, + assetManifest, + workerResponse: new Response('unavailable', { status: 503 }), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/robots.txt'), + env, + createCtx(), + ); + + expect(response.status).toBe(503); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }); + + it.each(deploys)( + 'keeps a listed file that runs past the dispatch budget static on %s', + async (_, routing) => { + const { env, analyticsWrites } = createEnv({ + routing, + assetManifest, + // Never settles, so the dispatch budget runs out first. + workerFetchImpl: () => new Promise(() => {}), + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/robots.txt'), + { ...env, DISPATCH_TIMEOUT_MS: '20' } as Env, + createCtx(), + ); + + expect(response.status).toBe(503); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }, + ); +}); + +describe('request type metering after a fallback rewrite', () => { + // The asset manifest answer belongs to the path that was looked up. After a + // fallback rewrites `/missing.png` to the shell, it says nothing about the + // shell, so the response keeps the default label. + it('does not apply the manifest answer for the original path to the rewrite target', async () => { + let calls = 0; + const { env, workerFetch, analyticsWrites } = createEnv({ + routing: { + workerName: 'user-app-dpl_1', + projectId: 'proj_1', + type: 'framework', + ssr: true, + version: 'deploy-1', + assetManifestId: 'deploy-1', + fallbackRules: [{ source: '/*', destination: '/index.html', status: 200 }], + }, + assetManifest: { '/index.html': 'shell-hash' }, + workerFetchImpl: async () => { + calls++; + return calls === 1 + ? new Response('missing', { status: 404 }) + : new Response('shell', { headers: { 'Content-Type': 'text/html' } }); + }, + }); + + const response = await app.fetch( + new Request('https://my-app.void.app/missing.png'), + env, + createCtx(), + ); + + expect(response.status).toBe(200); + expect(workerFetch).toHaveBeenCalledTimes(2); + expect(meteredRequestType(analyticsWrites)).toBe('static'); + }); +});