From db2aec7d53621a333d7009e8c2e00d348c248b73 Mon Sep 17 00:00:00 2001 From: Hugo Richard Date: Thu, 11 Jun 2026 22:42:25 +0100 Subject: [PATCH 1/2] fix: dedupe Next captureOutput logs and map dev stacks to source --- .changeset/fix-capture-output-duplicates.md | 5 + .../3.integrate/frameworks/02.nextjs.md | 2 +- packages/evlog/src/logger.ts | 24 ++- packages/evlog/src/next/enrich-error-stack.ts | 13 ++ packages/evlog/src/next/handler.ts | 5 +- .../evlog/src/next/instrumentation-create.ts | 18 +- .../shared/enrich-error-stack-next.node.ts | 189 ++++++++++++++++++ .../src/shared/enrich-error-stack.node.ts | 51 +++-- packages/evlog/src/shared/pretty-error.ts | 75 ++++--- .../test/core/enrich-error-stack-next.test.ts | 41 ++++ packages/evlog/test/core/pretty-error.test.ts | 56 ++++++ .../evlog/test/next/instrumentation.test.ts | 70 +++++++ 12 files changed, 502 insertions(+), 47 deletions(-) create mode 100644 .changeset/fix-capture-output-duplicates.md create mode 100644 packages/evlog/src/next/enrich-error-stack.ts create mode 100644 packages/evlog/src/shared/enrich-error-stack-next.node.ts create mode 100644 packages/evlog/test/core/enrich-error-stack-next.test.ts diff --git a/.changeset/fix-capture-output-duplicates.md b/.changeset/fix-capture-output-duplicates.md new file mode 100644 index 00000000..ea36eb5a --- /dev/null +++ b/.changeset/fix-capture-output-duplicates.md @@ -0,0 +1,5 @@ +--- +"evlog": patch +--- + +Fix duplicate terminal output when Next.js `captureOutput` is enabled: pretty-print writes use the native stdout handle registered at patch time, passthrough is skipped unless `silent: true`, and evlog-formatted terminal lines are ignored by capture. Next.js dev stacks are source-mapped to original TypeScript (like Nitro) via a Next-only enricher that does not bundle nitropack/youch; stored stacks are compacted and useless `.next`/`node:` snippet previews are skipped. The primary `at` line now points at your route/handler file instead of Next `route-modules` internals. diff --git a/apps/docs/content/3.integrate/frameworks/02.nextjs.md b/apps/docs/content/3.integrate/frameworks/02.nextjs.md index 5f1243b3..bd55e5cc 100644 --- a/apps/docs/content/3.integrate/frameworks/02.nextjs.md +++ b/apps/docs/content/3.integrate/frameworks/02.nextjs.md @@ -154,7 +154,7 @@ Next.js automatically calls these exports: - `onRequestError()`: Called on every unhandled request error. Emits a structured error log with the error message, digest, stack trace, request path/method, and routing context (`routerKind`, `routePath`, `routeType`, `renderSource`). ::callout{icon="i-lucide-info" color="info"} -`captureOutput` only activates in the Node.js runtime (`NEXT_RUNTIME === 'nodejs'`). It patches `process.stdout.write` and `process.stderr.write` to emit structured `log.info` / `log.error` events alongside the original output. Known Next.js Edge bundler warnings are filtered by default so they are not re-emitted as evlog errors. +`captureOutput` only activates in the Node.js runtime (`NEXT_RUNTIME === 'nodejs'`). It patches `process.stdout.write` and `process.stderr.write` to emit structured `log.info` / `log.error` events. When `silent` is `false` (the default), captured output is shown once as structured terminal output — the raw write is not duplicated. Set `silent: true` to keep the original passthrough alongside drain delivery. Known Next.js Edge bundler warnings are filtered by default so they are not re-emitted as evlog errors. :: ### Configuration diff --git a/packages/evlog/src/logger.ts b/packages/evlog/src/logger.ts index 4c86569d..b40925e5 100644 --- a/packages/evlog/src/logger.ts +++ b/packages/evlog/src/logger.ts @@ -4,12 +4,27 @@ import { buildAuditFields, consumeAuditForceKeep, finalizeAudit } from './audit' import { markGloballyRedacted, redactEvent, resolveRedactConfig } from './redact' import type { PluginRunner } from './shared/plugin' import { createPluginRunner, getEmptyPluginRunner } from './shared/plugin' -import { buildErrorEntries, PRETTY_ERROR_TREE_SPACER, registerPrettyErrorSnippetReader } from './shared/pretty-error' +import { buildErrorEntries, compactStackForStorage, PRETTY_ERROR_TREE_SPACER, registerPrettyErrorSnippetReader } from './shared/pretty-error' import type { ResolvedPrettyError } from './shared/dev-terminal' import { resolveDevTerminal } from './shared/dev-terminal' import { EvlogError } from './error' import { colors, cssColors, detectEnvironment, escapeFormatString, formatDuration, getConsoleMethod, getCssLevelColor, getLevelColor, isBrowser, isDev, isLevelEnabled, matchesPattern } from './utils' +const nativeStdoutWrite = + typeof process !== 'undefined' && typeof process.stdout?.write === 'function' + ? process.stdout.write.bind(process.stdout) + : undefined + +interface EvlogProcessOutputGlobal { + __evlogNativeStdoutWrite?: typeof process.stdout.write +} + +function writePrettyStdout(text: string): void { + const global = globalThis as EvlogProcessOutputGlobal + const write = global.__evlogNativeStdoutWrite ?? nativeStdoutWrite + write?.(text) +} + function isPlainObject(val: unknown): val is Record { return val !== null && typeof val === 'object' && !Array.isArray(val) } @@ -563,12 +578,11 @@ function flushPrettyLines(lines: string[]): void { if (lines.length === 0) return const text = `${lines.join('\n')}\n` if ( - typeof process !== 'undefined' - && typeof process.stdout?.write === 'function' + nativeStdoutWrite && !isBrowser() && process.env.VITEST !== 'true' ) { - process.stdout.write(text) + writePrettyStdout(text) return } console.log(lines.join('\n')) @@ -875,7 +889,7 @@ export function createLogger>(initial const errorObj: Record = { name: err.name, message: err.message, - stack: err.stack, + stack: compactStackForStorage(err.stack), } const errRecord = err as unknown as Record for (const k of ['code', 'status', 'statusText', 'statusCode', 'statusMessage', 'data', 'cause', 'internal'] as const) { diff --git a/packages/evlog/src/next/enrich-error-stack.ts b/packages/evlog/src/next/enrich-error-stack.ts new file mode 100644 index 00000000..6c3efa50 --- /dev/null +++ b/packages/evlog/src/next/enrich-error-stack.ts @@ -0,0 +1,13 @@ +/** + * Source-map stack enrichment for Next.js dev — isolated from Nitro to avoid bundling nitropack/youch. + */ +export async function enrichNextErrorStackForDev( + error: Error, + options: { pretty?: boolean } = {}, +): Promise { + if (process.env.NODE_ENV === 'production') return + if (options.pretty === false) return + + const { enrichErrorStackFromNextDev } = await import('../shared/enrich-error-stack-next.node') + enrichErrorStackFromNextDev(error) +} diff --git a/packages/evlog/src/next/handler.ts b/packages/evlog/src/next/handler.ts index 33134d16..f260501c 100644 --- a/packages/evlog/src/next/handler.ts +++ b/packages/evlog/src/next/handler.ts @@ -6,6 +6,7 @@ import { shouldLog, getServiceForPath } from '../shared/routes' import { bindStreamingResponseLifecycle, shouldDeferEmitForResponse } from '../shared/streamResponse' import { filterSafeHeaders } from '../utils' import { EvlogError } from '../error' +import { enrichNextErrorStackForDev } from './enrich-error-stack' import type { NextEvlogOptions } from './types' import { evlogStorage } from './storage' @@ -252,7 +253,9 @@ export function createWithEvlog(options: NextEvlogOptions) { return result as Awaited } catch (error) { - logger.error(error instanceof Error ? error : new Error(String(error))) + const err = error instanceof Error ? error : new Error(String(error)) + await enrichNextErrorStackForDev(err, { pretty: state.options.pretty }) + logger.error(err) const errorStatus = (error as { status?: number }).status ?? (error as { statusCode?: number }).statusCode diff --git a/packages/evlog/src/next/instrumentation-create.ts b/packages/evlog/src/next/instrumentation-create.ts index 6fc016bd..58a8b15f 100644 --- a/packages/evlog/src/next/instrumentation-create.ts +++ b/packages/evlog/src/next/instrumentation-create.ts @@ -31,8 +31,13 @@ export const DEFAULT_CAPTURE_OUTPUT_IGNORE: Array = [ 'not supported in the Edge Runtime', 'not supported inthe Edge Runtime', 'Import trace:', + /^(?:\u001b\[[0-9;]*m)?(?:ERROR|INFO|WARN|DEBUG) \[/, ] +interface EvlogProcessOutputGlobal { + __evlogNativeStdoutWrite?: typeof process.stdout.write +} + /** * Configuration for {@link createInstrumentation} and {@link defineNodeInstrumentation}. * Controls global logger options and optional stdout/stderr capture (Node.js only). @@ -79,6 +84,7 @@ let activeCaptureOutput: ignore: Array stdout: boolean stderr: boolean + silent: boolean } | undefined @@ -108,18 +114,20 @@ function shouldIgnoreCapturedOutput(message: string, ignore: Array { diff --git a/packages/evlog/src/shared/enrich-error-stack-next.node.ts b/packages/evlog/src/shared/enrich-error-stack-next.node.ts new file mode 100644 index 00000000..46c8c23a --- /dev/null +++ b/packages/evlog/src/shared/enrich-error-stack-next.node.ts @@ -0,0 +1,189 @@ +import { existsSync, readFileSync } from 'node:fs' +import { createRequire } from 'node:module' +import { isAbsolute, relative } from 'node:path' +import { pathToFileURL, fileURLToPath } from 'node:url' + +/** Parsed stack frame from Next.js `parseStack`. */ +interface NextParsedFrame { + file: string | null + line1: number | null + column1: number | null + methodName: string | null + arguments: string[] +} + +type SourceMapConsumerInstance = { + originalPositionFor: (pos: { line: number, column: number }) => { + source: string | null + line: number | null + column: number | null + name: string | null + } +} + +const require = createRequire(import.meta.url) + +function computeErrorName(error: Error): string { + return error.name || 'Error' +} + +function formatMappedFrame( + methodName: string | null, + sourceURL: string | null, + line1: number | null, + column1: number | null, +): string { + let sourceLocation = line1 !== null ? `:${line1}` : '' + if (column1 !== null && sourceLocation !== '') { + sourceLocation += `:${column1}` + } + + let fileLocation: string + if (sourceURL !== null && sourceURL.startsWith('file://') && URL.canParse(sourceURL)) { + fileLocation = relative(process.cwd(), fileURLToPath(sourceURL)) + } else if (sourceURL !== null && sourceURL.startsWith('/')) { + fileLocation = relative(process.cwd(), sourceURL) + } else { + fileLocation = sourceURL ?? 'unknown' + } + + return methodName + ? ` at ${methodName} (${fileLocation}${sourceLocation})` + : ` at ${fileLocation}${sourceLocation}` +} + +function isFrameworkRuntimePath(path: string): boolean { + const normalized = path.replace(/\\/g, '/') + return normalized.includes('route-modules/') + || normalized.includes('webpack://next/') + || normalized.includes('/next/dist/') + || normalized.includes('/compiled/next-server/') +} + +function shouldSkipMappedSource(source: string): boolean { + const normalized = source.replace(/\\/g, '/') + return normalized.includes('node_modules') + || normalized.includes('/packages/evlog/') + || normalized.includes('/node_modules/') + || isFrameworkRuntimePath(normalized) +} + +function resolveFrameFile(frame: NextParsedFrame): string | null { + if (!frame.file) return null + if (frame.file.startsWith('file://')) { + try { + return fileURLToPath(frame.file) + } catch { + return frame.file + } + } + if (isAbsolute(frame.file)) return frame.file + return null +} + +function getSourceMapConsumer( + frameFile: string, + cache: Map, +): SourceMapConsumerInstance | null { + const cached = cache.get(frameFile) + if (cached !== undefined) return cached + + const mapPath = `${frameFile}.map` + if (!existsSync(mapPath)) { + cache.set(frameFile, null) + return null + } + + try { + const sourceMapModule = require('next/dist/compiled/source-map') as { + SourceMapConsumer: new(payload: unknown, sourceMapURL: string) => SourceMapConsumerInstance + } + const payload = JSON.parse(readFileSync(mapPath, 'utf8')) as unknown + const chunkUrl = pathToFileURL(frameFile).href + const consumer = new sourceMapModule.SourceMapConsumer(payload, `${chunkUrl}.map`) + cache.set(frameFile, consumer) + return consumer + } catch { + cache.set(frameFile, null) + return null + } +} + +function mapFrame( + frame: NextParsedFrame, + cache: Map, +): { frame: NextParsedFrame, skipped: boolean } { + if (frame.file?.startsWith('node:')) { + return { frame, skipped: true } + } + + const frameFile = resolveFrameFile(frame) + if (!frameFile || frame.line1 === null) { + return { frame, skipped: false } + } + + const consumer = getSourceMapConsumer(frameFile, cache) + if (!consumer) { + if (frameFile.includes('.next/')) { + return { frame, skipped: true } + } + return { frame, skipped: false } + } + + const sourcePosition = consumer.originalPositionFor({ + line: frame.line1, + column: (frame.column1 ?? 1) - 1, + }) + + if (!sourcePosition.source || sourcePosition.line === null) { + return { frame, skipped: frameFile.includes('.next/') } + } + + if (shouldSkipMappedSource(sourcePosition.source)) { + return { frame, skipped: true } + } + + return { + frame: { + ...frame, + file: sourcePosition.source, + line1: sourcePosition.line, + column1: sourcePosition.column === null ? null : sourcePosition.column + 1, + methodName: sourcePosition.name ?? frame.methodName, + }, + skipped: false, + } +} + +/** + * Rewrite `error.stack` with Turbopack/Webpack source-mapped frames in Next.js dev. + * Reads sibling `.map` files for `.next` chunks (same resolution as the dev overlay). + */ +export function enrichErrorStackFromNextDev(error: Error): void { + if (process.env.NODE_ENV === 'production') return + if (!error.stack) return + + try { + const { parseStack } = require('next/dist/server/lib/parse-stack') as { + parseStack: (stack: string, distDir?: string) => NextParsedFrame[] + } + + const frames = parseStack(error.stack) + if (frames.length === 0) return + + const cache = new Map() + const mappedLines: string[] = [] + + for (const frame of frames) { + const { frame: mapped, skipped } = mapFrame(frame, cache) + if (skipped) continue + mappedLines.push(formatMappedFrame(mapped.methodName, mapped.file, mapped.line1, mapped.column1)) + } + + if (mappedLines.length === 0) return + + error.stack = `${computeErrorName(error)}: ${error.message}\n${mappedLines.join('\n')}` + } catch { + // Next internals unavailable — keep the original stack + } +} diff --git a/packages/evlog/src/shared/enrich-error-stack.node.ts b/packages/evlog/src/shared/enrich-error-stack.node.ts index e52fb09f..52421ddb 100644 --- a/packages/evlog/src/shared/enrich-error-stack.node.ts +++ b/packages/evlog/src/shared/enrich-error-stack.node.ts @@ -17,31 +17,54 @@ function shouldEnrichStackFromConfig(): boolean { return process.env.NODE_ENV !== 'production' } -/** - * Rewrite `error.stack` with source-mapped frames when the Nitro dev runtime is available. - * Matches Nitro's Youch output (e.g. `server/api/foo.ts:100` instead of `.nuxt/dev/index.mjs`). - */ -export async function enrichErrorStackForDev( - error: Error, - options: EnrichErrorStackOptions = {}, -): Promise { - if (process.env.NODE_ENV === 'production') return - const pretty = options.pretty ?? shouldEnrichStackFromConfig() - if (!pretty) return +function isNextDevRuntime(): boolean { + return process.env.NEXT_RUNTIME === 'nodejs' + || process.env.NEXT_RUNTIME === 'edge' + || Boolean(process.env.__NEXT_DIST_DIR) +} + +async function enrichErrorStackFromNitroDev(error: Error): Promise { + if (isNextDevRuntime()) return false + const { createRequire } = await import('node:module') + const require = createRequire(import.meta.url) const specifiers = [ 'nitropack/runtime/internal/error/dev', 'nitro/runtime/internal/error/dev', ] + for (const specifier of specifiers) { try { - const mod = await import(specifier) + const mod = require(specifier) as { loadStackTrace?: (err: Error) => Promise } if (typeof mod.loadStackTrace === 'function') { await mod.loadStackTrace(error).catch(() => {}) - return + return true } } catch { - // try next runtime + // try next Nitro runtime entry } } + + return false +} + +/** + * Rewrite `error.stack` with source-mapped frames when the Nitro or Next.js dev runtime is available. + * Matches Nitro's Youch output (e.g. `server/api/foo.ts:100` instead of `.nuxt/dev/index.mjs`). + */ +export async function enrichErrorStackForDev( + error: Error, + options: EnrichErrorStackOptions = {}, +): Promise { + if (process.env.NODE_ENV === 'production') return + const pretty = options.pretty ?? shouldEnrichStackFromConfig() + if (!pretty) return + + if (isNextDevRuntime()) { + const { enrichErrorStackFromNextDev } = await import('./enrich-error-stack-next.node') + enrichErrorStackFromNextDev(error) + return + } + + await enrichErrorStackFromNitroDev(error) } diff --git a/packages/evlog/src/shared/pretty-error.ts b/packages/evlog/src/shared/pretty-error.ts index 6ebe0d86..570f7e60 100644 --- a/packages/evlog/src/shared/pretty-error.ts +++ b/packages/evlog/src/shared/pretty-error.ts @@ -66,7 +66,7 @@ export interface CodeSnippetLine { isErrorLine: boolean } -const SKIP_PATH_RE = /(?:^|[/\\])(?:node_modules|\.nuxt|\.output)(?:[/\\]|$)/ +const SKIP_PATH_RE = /(?:^|[/\\])(?:node_modules|\.nuxt|\.next|\.output)(?:[/\\]|$)/ const SKIP_FRAME_PATH_RE = /(?:^|[/\\])(?:packages[/\\]evlog|evlog[/\\](?:dist|src))(?:[/\\]|$)/ const SKIP_FRAME_FN_RE = /^(?:createError|EvlogError|new EvlogError)$/ @@ -154,9 +154,11 @@ export function decodeFileUrl(file: string): string { } function isAppPath(file: string): boolean { - const normalized = file.replace(/\\/g, '/') + const normalized = decodeFileUrl(file).replace(/\\/g, '/') + if (normalized.startsWith('node:')) return false if (SKIP_PATH_RE.test(normalized)) return false if (normalized.includes('/node_modules/')) return false + if (isFrameworkRuntimePath(normalized)) return false return true } @@ -174,6 +176,25 @@ function formatDisplayPath(file: string, cwd: string): string { return decoded } +/** + * Compact a stack trace for wide-event storage (drains, NDJSON). + * Drops node_modules, build output, and evlog internals; keeps up to five useful frames. + */ +export function compactStackForStorage(stack: string | undefined, maxFrames = 5): string | undefined { + if (!stack) return undefined + + const lines = stack.split('\n') + const head = lines[0] ?? '' + const frames = parseStackFrames(stack) + const useful = frames.filter(f => f.file && f.line && f.isApp && !isInternalErrorFrame(f)).slice(0, maxFrames) + + if (useful.length === 0) { + return head || undefined + } + + return [head, ...useful.map(f => f.raw)].join('\n') +} + /** * Parse a V8 stack trace string into frames. */ @@ -231,7 +252,21 @@ export function parseStackFrames(stack: string | undefined): StackFrame[] { return frames } +function isFrameworkRuntimePath(path: string): boolean { + const normalized = path.replace(/\\/g, '/') + return normalized.includes('route-modules/') + || normalized.includes('webpack://next/') + || normalized.includes('/next/dist/') + || normalized.includes('/compiled/next-server/') +} + +function isFrameworkRuntimeFrame(frame: StackFrame): boolean { + if (!frame.file) return false + return isFrameworkRuntimePath(decodeFileUrl(frame.file)) +} + function isInternalErrorFrame(frame: StackFrame): boolean { + if (isFrameworkRuntimeFrame(frame)) return true if (frame.fn) { const fn = frame.fn.replace(/^async /, '') if (SKIP_FRAME_FN_RE.test(fn)) return true @@ -240,31 +275,20 @@ function isInternalErrorFrame(frame: StackFrame): boolean { const path = decodeFileUrl(frame.file).replace(/\\/g, '/') if (SKIP_FRAME_PATH_RE.test(path)) return true if (path.includes('.nuxt/')) return true + if (path.includes('.next/')) return true return false } /** - * Pick the most useful frame for code snippets (prefer app source over bundles). + * Pick the most useful frame for code snippets (topmost app throw site). */ export function pickPrimaryFrame(frames: StackFrame[]): StackFrame | undefined { - const appFrames = frames.filter(f => f.isApp && f.file && f.line && !isInternalErrorFrame(f)) - if (appFrames.length === 0) return undefined - - const scored = appFrames.map((frame) => { - const path = decodeFileUrl(frame.file!).replace(/\\/g, '/') - let score = 0 - if (path.includes('/server/')) score += 8 - if (/\.(?:ts|tsx|vue)$/.test(path)) score += 6 - if (path.includes('/src/')) score += 3 - if (path.startsWith('./')) score += 2 - if (/\.(?:js|jsx|mjs)$/.test(path)) score += 1 - if (path.includes('.nuxt/')) score -= 20 - if (path.includes('/packages/evlog/')) score -= 20 - return { frame, score } - }) - - scored.sort((a, b) => b.score - a.score) - return scored[0]?.frame ?? appFrames[0] + for (const frame of frames) { + if (frame.isApp && frame.file && frame.line && !isInternalErrorFrame(frame)) { + return frame + } + } + return undefined } /** @@ -276,6 +300,8 @@ export function readCodeSnippet( contextLines = 2, ): CodeSnippetLine[] | null { if (!isDev() || isBrowser() || !snippetReader) return null + const path = decodeFileUrl(file).replace(/\\/g, '/') + if (path.includes('.next/') || path.includes('.nuxt/') || path.includes('.output/')) return null return snippetReader(file, line, contextLines) } @@ -292,15 +318,16 @@ function formatSnippetLines(snippet: CodeSnippetLine[]): string[] { function formatFrameLocation(frame: StackFrame, cwd: string): string { const file = frame.file ? formatDisplayPath(frame.file, cwd) : 'unknown' const loc = frame.line ? `${file}:${frame.line}` : file - return frame.fn ? `at ${frame.fn} (${loc})` : `at ${loc}` + const fn = frame.fn && frame.fn !== '' ? frame.fn : undefined + return fn ? `at ${fn} (${loc})` : `at ${loc}` } function formatCollapsedFrame(frame: StackFrame, cwd: string): string { const file = frame.file ? formatDisplayPath(frame.file, cwd) : 'unknown' const loc = frame.line ? `${file}:${frame.line}` : file const prefix = frame.fn?.startsWith('async') ? 'at async ' : 'at ' - const fn = frame.fn?.replace(/^async /, '') ?? loc - if (frame.fn && frame.fn !== loc) { + const fn = frame.fn?.replace(/^async /, '') + if (fn && fn !== '' && fn !== loc) { return `${prefix}${fn} (${loc})` } return `${prefix}${loc}` diff --git a/packages/evlog/test/core/enrich-error-stack-next.test.ts b/packages/evlog/test/core/enrich-error-stack-next.test.ts new file mode 100644 index 00000000..dab08e93 --- /dev/null +++ b/packages/evlog/test/core/enrich-error-stack-next.test.ts @@ -0,0 +1,41 @@ +import { existsSync } from 'node:fs' +import { resolve } from 'node:path' +import { afterEach, beforeEach, describe, expect, it } from 'vitest' +import { enrichErrorStackFromNextDev } from '../../src/shared/enrich-error-stack-next.node' + +describe('enrichErrorStackFromNextDev', () => { + const originalEnv = process.env.NODE_ENV + const originalDistDir = process.env.__NEXT_DIST_DIR + + beforeEach(() => { + process.env.NODE_ENV = 'development' + }) + + afterEach(() => { + process.env.NODE_ENV = originalEnv + if (originalDistDir === undefined) { + delete process.env.__NEXT_DIST_DIR + } else { + process.env.__NEXT_DIST_DIR = originalDistDir + } + }) + + it('uses the next-playground turbopack map when present', () => { + const chunk = resolve( + process.cwd(), + '../../apps/next-playground/.next/dev/server/chunks/[root-of-the-server]__0pdvr0y._.js', + ) + if (!existsSync(`${chunk}.map`)) { + return + } + + const error = new Error('Payment method declined') + error.name = 'EvlogError' + error.stack = `EvlogError: Payment method declined + at ${chunk}:5372:176` + + enrichErrorStackFromNextDev(error) + + expect(error.stack).toContain('structured-error/route.ts:7') + }) +}) diff --git a/packages/evlog/test/core/pretty-error.test.ts b/packages/evlog/test/core/pretty-error.test.ts index 4746ce29..ddd30551 100644 --- a/packages/evlog/test/core/pretty-error.test.ts +++ b/packages/evlog/test/core/pretty-error.test.ts @@ -6,6 +6,7 @@ import { createError } from '../../src/error' import { createRequestLogger, initLogger } from '../../src/logger' import { buildErrorEntries, + compactStackForStorage, normalizeErrorContext, parseStackFrames, pickPrimaryFrame, @@ -109,6 +110,57 @@ at async file:///Users/dev/project/node_modules/h3/dist/index.mjs:2017:19` const primary = pickPrimaryFrame(parseStackFrames(stack)) expect(primary).toBeUndefined() }) + + it('skips node internal frames when picking snippet locations', () => { + const stack = `EvlogError: Payment method declined + at AsyncLocalStorage.run (node:internal/async_local_storage/async_context_frame:63:14) + at Object.handler (file:///Users/dev/project/apps/next-playground/app/api/test/structured-error/route.ts:7:9)` + const primary = pickPrimaryFrame(parseStackFrames(stack)) + expect(primary?.file).toContain('structured-error/route.ts') + expect(primary?.line).toBe(7) + }) + + it('prefers app route.ts over Next route-modules after dev stack enrichment', () => { + const stack = `EvlogError: Payment method declined + at (app/api/test/structured-error/route.ts:7:25) + at AppRouteRouteModule.do (webpack://next/src/server/route-modules/app-route/module.ts:631:21) + at (webpack://next/src/server/route-modules/app-route/module.ts:844:24)` + const frames = parseStackFrames(stack) + const primary = pickPrimaryFrame(frames) + expect(primary?.file).toContain('structured-error/route.ts') + expect(primary?.line).toBe(7) + + const entries = buildErrorEntries({ + message: 'Payment method declined', + stack, + why: 'Card declined', + }, { snippet: false, stackDepth: 3, compact: false }) + const children = entries[0]?.children ?? [] + const locationLine = children.find(line => line.includes('structured-error/route.ts')) + expect(locationLine).toBeDefined() + expect(children.find(line => line.includes('route-modules'))).toBeUndefined() + }) +}) + +describe('compactStackForStorage', () => { + it('drops build output and node_modules frames from stored stacks', () => { + const stack = `EvlogError: Payment method declined + at createError (/Users/dev/project/packages/evlog/src/error.ts:699:12) + at Object.handler (/Users/dev/project/apps/next-playground/.next/dev/server/chunks/route.js:5372:176) + at async /Users/dev/project/node_modules/next/dist/server/base-server.js:934:17 + at async /Users/dev/project/node_modules/next/dist/server/lib/start-server.js:225:13` + + expect(compactStackForStorage(stack)).toBe('EvlogError: Payment method declined') + }) + + it('keeps app source frames when present', () => { + const stack = `Error: boom + at Object.handler (file:///Users/dev/project/server/api/test.get.ts:100:0) + at async file:///Users/dev/project/node_modules/h3/dist/index.mjs:2017:19` + + expect(compactStackForStorage(stack)).toBe(`Error: boom +at Object.handler (file:///Users/dev/project/server/api/test.get.ts:100:0)`) + }) }) describe('readCodeSnippet', () => { @@ -137,6 +189,10 @@ describe('readCodeSnippet', () => { { line: 4, content: 'line 4', isErrorLine: false }, ]) }) + + it('skips bundled .next paths even when a reader is registered', () => { + expect(readCodeSnippet('/Users/dev/project/.next/dev/server/chunks/route.js', 42)).toBeNull() + }) }) describe('buildErrorEntries', () => { diff --git a/packages/evlog/test/next/instrumentation.test.ts b/packages/evlog/test/next/instrumentation.test.ts index 33f4773f..9832596b 100644 --- a/packages/evlog/test/next/instrumentation.test.ts +++ b/packages/evlog/test/next/instrumentation.test.ts @@ -336,6 +336,76 @@ describe('createInstrumentation', () => { expect(logInfoSpy).not.toHaveBeenCalled() }) + it('captureOutput without silent suppresses passthrough to avoid terminal duplication', async () => { + const createInstrumentation = await loadModule() + process.env.NEXT_RUNTIME = 'nodejs' + + const passthroughSpy = vi.fn() + process.stdout.write = function(chunk: unknown, ...args: unknown[]) { + passthroughSpy() + return originalStdoutWrite.call(process.stdout, chunk as string, ...args as []) + } as typeof process.stdout.write + + const { register } = createInstrumentation({ + captureOutput: true, + pretty: false, + silent: false, + }) + + await runRegister(register) + + passthroughSpy.mockClear() + process.stdout.write('hello from next\n') + + expect(logInfoSpy).toHaveBeenCalledTimes(1) + expect(logInfoSpy.mock.calls[0]?.[0]).toMatchObject({ + source: 'stdout', + message: 'hello from next', + }) + expect(passthroughSpy).not.toHaveBeenCalled() + }) + + it('captureOutput with silent passthroughs raw output for drain-only setups', async () => { + const createInstrumentation = await loadModule() + process.env.NEXT_RUNTIME = 'nodejs' + + const passthroughSpy = vi.fn() + process.stdout.write = function(chunk: unknown, ...args: unknown[]) { + passthroughSpy() + return originalStdoutWrite.call(process.stdout, chunk as string, ...args as []) + } as typeof process.stdout.write + + const { register } = createInstrumentation({ + captureOutput: true, + pretty: false, + silent: true, + }) + + await runRegister(register) + + passthroughSpy.mockClear() + process.stdout.write('hello from next\n') + + expect(logInfoSpy).toHaveBeenCalledTimes(1) + expect(passthroughSpy).toHaveBeenCalledTimes(1) + }) + + it('captureOutput ignores evlog-formatted terminal lines on stdout', async () => { + const createInstrumentation = await loadModule() + process.env.NEXT_RUNTIME = 'nodejs' + + const { register } = createInstrumentation({ + captureOutput: true, + pretty: false, + silent: true, + }) + + await runRegister(register) + + process.stdout.write('ERROR [next-playground] GET /api/test 402 in 1ms\n') + expect(logInfoSpy).not.toHaveBeenCalled() + }) + it('captureOutput custom ignore replaces the default filter', async () => { const createInstrumentation = await loadModule() process.env.NEXT_RUNTIME = 'nodejs' From 200d532129b8b28da837162b9196d4da24254a3c Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 11 Jun 2026 22:02:21 +0000 Subject: [PATCH 2/2] refactor: simplify PR #381 and keep production stacks intact - Revert shared/enrich-error-stack.node.ts to main: the Next branch and createRequire refactor were dead code (file is only imported by the Nitro plugins, where NEXT_RUNTIME is never set) - Only compact stored stacks in dev: compactStackForStorage filtered out .output/.next/node_modules frames, which would have reduced production stacks to the message line in drains; it now also returns the stack unchanged when no app frame survives - Drop the evlog-format regex from DEFAULT_CAPTURE_OUTPUT_IGNORE: the native stdout bypass already prevents recapture, and the regex silently swallowed app lines starting with INFO [ etc. - Deduplicate isFrameworkRuntimePath and EvlogProcessOutputGlobal, inline computeErrorName - Replace the enricher test that depended on a local playground build artifact with a synthetic chunk + sourcemap fixture that runs in CI https://claude.ai/code/session_01M4hK5tKJCvXKZDBpa93G15 --- .changeset/fix-capture-output-duplicates.md | 2 +- packages/evlog/src/logger.ts | 5 +- .../evlog/src/next/instrumentation-create.ts | 6 +- .../shared/enrich-error-stack-next.node.ts | 16 +--- .../src/shared/enrich-error-stack.node.ts | 51 ++++-------- packages/evlog/src/shared/pretty-error.ts | 11 ++- .../test/core/enrich-error-stack-next.test.ts | 77 ++++++++++++++----- packages/evlog/test/core/pretty-error.test.ts | 4 +- .../evlog/test/next/instrumentation.test.ts | 16 ---- 9 files changed, 86 insertions(+), 102 deletions(-) diff --git a/.changeset/fix-capture-output-duplicates.md b/.changeset/fix-capture-output-duplicates.md index ea36eb5a..0d5ac7b3 100644 --- a/.changeset/fix-capture-output-duplicates.md +++ b/.changeset/fix-capture-output-duplicates.md @@ -2,4 +2,4 @@ "evlog": patch --- -Fix duplicate terminal output when Next.js `captureOutput` is enabled: pretty-print writes use the native stdout handle registered at patch time, passthrough is skipped unless `silent: true`, and evlog-formatted terminal lines are ignored by capture. Next.js dev stacks are source-mapped to original TypeScript (like Nitro) via a Next-only enricher that does not bundle nitropack/youch; stored stacks are compacted and useless `.next`/`node:` snippet previews are skipped. The primary `at` line now points at your route/handler file instead of Next `route-modules` internals. +Fix duplicate terminal output when Next.js `captureOutput` is enabled: pretty-print writes use the native stdout handle registered at patch time and passthrough is skipped unless `silent: true`. Next.js dev stacks are source-mapped to original TypeScript (like Nitro) via a Next-only enricher that does not bundle nitropack/youch; stored stacks are compacted in dev (production stacks are kept intact) and useless `.next`/`node:` snippet previews are skipped. The primary `at` line now points at your route/handler file instead of Next `route-modules` internals. diff --git a/packages/evlog/src/logger.ts b/packages/evlog/src/logger.ts index b40925e5..614a0a59 100644 --- a/packages/evlog/src/logger.ts +++ b/packages/evlog/src/logger.ts @@ -15,7 +15,8 @@ const nativeStdoutWrite = ? process.stdout.write.bind(process.stdout) : undefined -interface EvlogProcessOutputGlobal { +/** Cross-bundle global slot for the native stdout write registered by captureOutput patching. */ +export interface EvlogProcessOutputGlobal { __evlogNativeStdoutWrite?: typeof process.stdout.write } @@ -889,7 +890,7 @@ export function createLogger>(initial const errorObj: Record = { name: err.name, message: err.message, - stack: compactStackForStorage(err.stack), + stack: isDev() ? compactStackForStorage(err.stack) : err.stack, } const errRecord = err as unknown as Record for (const k of ['code', 'status', 'statusText', 'statusCode', 'statusMessage', 'data', 'cause', 'internal'] as const) { diff --git a/packages/evlog/src/next/instrumentation-create.ts b/packages/evlog/src/next/instrumentation-create.ts index 58a8b15f..5ff5b782 100644 --- a/packages/evlog/src/next/instrumentation-create.ts +++ b/packages/evlog/src/next/instrumentation-create.ts @@ -5,6 +5,7 @@ import type { } from './instrumentation-gate' type LoggerModule = typeof import('../logger') +type EvlogProcessOutputGlobal = import('../logger').EvlogProcessOutputGlobal /** Options for capturing process stdout/stderr as structured log events. */ export interface CaptureOutputOptions { @@ -31,13 +32,8 @@ export const DEFAULT_CAPTURE_OUTPUT_IGNORE: Array = [ 'not supported in the Edge Runtime', 'not supported inthe Edge Runtime', 'Import trace:', - /^(?:\u001b\[[0-9;]*m)?(?:ERROR|INFO|WARN|DEBUG) \[/, ] -interface EvlogProcessOutputGlobal { - __evlogNativeStdoutWrite?: typeof process.stdout.write -} - /** * Configuration for {@link createInstrumentation} and {@link defineNodeInstrumentation}. * Controls global logger options and optional stdout/stderr capture (Node.js only). diff --git a/packages/evlog/src/shared/enrich-error-stack-next.node.ts b/packages/evlog/src/shared/enrich-error-stack-next.node.ts index 46c8c23a..30c92dc5 100644 --- a/packages/evlog/src/shared/enrich-error-stack-next.node.ts +++ b/packages/evlog/src/shared/enrich-error-stack-next.node.ts @@ -2,6 +2,7 @@ import { existsSync, readFileSync } from 'node:fs' import { createRequire } from 'node:module' import { isAbsolute, relative } from 'node:path' import { pathToFileURL, fileURLToPath } from 'node:url' +import { isFrameworkRuntimePath } from './pretty-error' /** Parsed stack frame from Next.js `parseStack`. */ interface NextParsedFrame { @@ -23,10 +24,6 @@ type SourceMapConsumerInstance = { const require = createRequire(import.meta.url) -function computeErrorName(error: Error): string { - return error.name || 'Error' -} - function formatMappedFrame( methodName: string | null, sourceURL: string | null, @@ -52,19 +49,10 @@ function formatMappedFrame( : ` at ${fileLocation}${sourceLocation}` } -function isFrameworkRuntimePath(path: string): boolean { - const normalized = path.replace(/\\/g, '/') - return normalized.includes('route-modules/') - || normalized.includes('webpack://next/') - || normalized.includes('/next/dist/') - || normalized.includes('/compiled/next-server/') -} - function shouldSkipMappedSource(source: string): boolean { const normalized = source.replace(/\\/g, '/') return normalized.includes('node_modules') || normalized.includes('/packages/evlog/') - || normalized.includes('/node_modules/') || isFrameworkRuntimePath(normalized) } @@ -182,7 +170,7 @@ export function enrichErrorStackFromNextDev(error: Error): void { if (mappedLines.length === 0) return - error.stack = `${computeErrorName(error)}: ${error.message}\n${mappedLines.join('\n')}` + error.stack = `${error.name || 'Error'}: ${error.message}\n${mappedLines.join('\n')}` } catch { // Next internals unavailable — keep the original stack } diff --git a/packages/evlog/src/shared/enrich-error-stack.node.ts b/packages/evlog/src/shared/enrich-error-stack.node.ts index 52421ddb..e52fb09f 100644 --- a/packages/evlog/src/shared/enrich-error-stack.node.ts +++ b/packages/evlog/src/shared/enrich-error-stack.node.ts @@ -17,54 +17,31 @@ function shouldEnrichStackFromConfig(): boolean { return process.env.NODE_ENV !== 'production' } -function isNextDevRuntime(): boolean { - return process.env.NEXT_RUNTIME === 'nodejs' - || process.env.NEXT_RUNTIME === 'edge' - || Boolean(process.env.__NEXT_DIST_DIR) -} - -async function enrichErrorStackFromNitroDev(error: Error): Promise { - if (isNextDevRuntime()) return false +/** + * Rewrite `error.stack` with source-mapped frames when the Nitro dev runtime is available. + * Matches Nitro's Youch output (e.g. `server/api/foo.ts:100` instead of `.nuxt/dev/index.mjs`). + */ +export async function enrichErrorStackForDev( + error: Error, + options: EnrichErrorStackOptions = {}, +): Promise { + if (process.env.NODE_ENV === 'production') return + const pretty = options.pretty ?? shouldEnrichStackFromConfig() + if (!pretty) return - const { createRequire } = await import('node:module') - const require = createRequire(import.meta.url) const specifiers = [ 'nitropack/runtime/internal/error/dev', 'nitro/runtime/internal/error/dev', ] - for (const specifier of specifiers) { try { - const mod = require(specifier) as { loadStackTrace?: (err: Error) => Promise } + const mod = await import(specifier) if (typeof mod.loadStackTrace === 'function') { await mod.loadStackTrace(error).catch(() => {}) - return true + return } } catch { - // try next Nitro runtime entry + // try next runtime } } - - return false -} - -/** - * Rewrite `error.stack` with source-mapped frames when the Nitro or Next.js dev runtime is available. - * Matches Nitro's Youch output (e.g. `server/api/foo.ts:100` instead of `.nuxt/dev/index.mjs`). - */ -export async function enrichErrorStackForDev( - error: Error, - options: EnrichErrorStackOptions = {}, -): Promise { - if (process.env.NODE_ENV === 'production') return - const pretty = options.pretty ?? shouldEnrichStackFromConfig() - if (!pretty) return - - if (isNextDevRuntime()) { - const { enrichErrorStackFromNextDev } = await import('./enrich-error-stack-next.node') - enrichErrorStackFromNextDev(error) - return - } - - await enrichErrorStackFromNitroDev(error) } diff --git a/packages/evlog/src/shared/pretty-error.ts b/packages/evlog/src/shared/pretty-error.ts index 570f7e60..c84785ed 100644 --- a/packages/evlog/src/shared/pretty-error.ts +++ b/packages/evlog/src/shared/pretty-error.ts @@ -179,18 +179,16 @@ function formatDisplayPath(file: string, cwd: string): string { /** * Compact a stack trace for wide-event storage (drains, NDJSON). * Drops node_modules, build output, and evlog internals; keeps up to five useful frames. + * Returns the stack unchanged when no app frame survives the filter. */ export function compactStackForStorage(stack: string | undefined, maxFrames = 5): string | undefined { if (!stack) return undefined - const lines = stack.split('\n') - const head = lines[0] ?? '' + const head = stack.split('\n')[0] ?? '' const frames = parseStackFrames(stack) const useful = frames.filter(f => f.file && f.line && f.isApp && !isInternalErrorFrame(f)).slice(0, maxFrames) - if (useful.length === 0) { - return head || undefined - } + if (useful.length === 0) return stack return [head, ...useful.map(f => f.raw)].join('\n') } @@ -252,7 +250,8 @@ export function parseStackFrames(stack: string | undefined): StackFrame[] { return frames } -function isFrameworkRuntimePath(path: string): boolean { +/** True for Next.js runtime internals (route-modules, next/dist, bundled next-server). */ +export function isFrameworkRuntimePath(path: string): boolean { const normalized = path.replace(/\\/g, '/') return normalized.includes('route-modules/') || normalized.includes('webpack://next/') diff --git a/packages/evlog/test/core/enrich-error-stack-next.test.ts b/packages/evlog/test/core/enrich-error-stack-next.test.ts index dab08e93..f366a685 100644 --- a/packages/evlog/test/core/enrich-error-stack-next.test.ts +++ b/packages/evlog/test/core/enrich-error-stack-next.test.ts @@ -1,41 +1,80 @@ -import { existsSync } from 'node:fs' -import { resolve } from 'node:path' +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { createRequire } from 'node:module' +import { tmpdir } from 'node:os' +import { join } from 'node:path' import { afterEach, beforeEach, describe, expect, it } from 'vitest' import { enrichErrorStackFromNextDev } from '../../src/shared/enrich-error-stack-next.node' -describe('enrichErrorStackFromNextDev', () => { +const require = createRequire(import.meta.url) +const hasNextInternals = (() => { + try { + require.resolve('next/dist/server/lib/parse-stack') + return true + } catch { + return false + } +})() + +describe.skipIf(!hasNextInternals)('enrichErrorStackFromNextDev', () => { const originalEnv = process.env.NODE_ENV - const originalDistDir = process.env.__NEXT_DIST_DIR + let dir: string beforeEach(() => { process.env.NODE_ENV = 'development' + dir = mkdtempSync(join(tmpdir(), 'evlog-next-enrich-')) }) afterEach(() => { process.env.NODE_ENV = originalEnv - if (originalDistDir === undefined) { - delete process.env.__NEXT_DIST_DIR - } else { - process.env.__NEXT_DIST_DIR = originalDistDir - } + rmSync(dir, { recursive: true, force: true }) }) - it('uses the next-playground turbopack map when present', () => { - const chunk = resolve( - process.cwd(), - '../../apps/next-playground/.next/dev/server/chunks/[root-of-the-server]__0pdvr0y._.js', - ) - if (!existsSync(`${chunk}.map`)) { - return - } + /** Chunk whose sibling map sends generated 5:10 to route.ts 7:3 (`SAME` = [9, 0, 6, 2]). */ + function writeChunkFixture(): string { + const chunk = join(dir, 'chunk.js') + writeFileSync(chunk, 'l1\nl2\nl3\nl4\nthrow_here\n') + writeFileSync(`${chunk}.map`, JSON.stringify({ + version: 3, + sources: ['app/api/test/structured-error/route.ts'], + names: [], + mappings: ';;;;SAME', + })) + return chunk + } + it('rewrites chunk frames to original sources via sibling maps', () => { + const chunk = writeChunkFixture() const error = new Error('Payment method declined') error.name = 'EvlogError' - error.stack = `EvlogError: Payment method declined - at ${chunk}:5372:176` + error.stack = `EvlogError: Payment method declined\n at ${chunk}:5:10` enrichErrorStackFromNextDev(error) + expect(error.stack).toContain('EvlogError: Payment method declined') expect(error.stack).toContain('structured-error/route.ts:7') + expect(error.stack).not.toContain('chunk.js') + }) + + it('keeps unmapped frames when no sibling map exists', () => { + const chunk = join(dir, 'plain.js') + writeFileSync(chunk, 'throw_here\n') + const error = new Error('boom') + error.stack = `Error: boom\n at ${chunk}:1:1` + + enrichErrorStackFromNextDev(error) + + expect(error.stack).toContain('plain.js:1') + }) + + it('does nothing in production', () => { + process.env.NODE_ENV = 'production' + const chunk = writeChunkFixture() + const error = new Error('boom') + const stack = `Error: boom\n at ${chunk}:5:10` + error.stack = stack + + enrichErrorStackFromNextDev(error) + + expect(error.stack).toBe(stack) }) }) diff --git a/packages/evlog/test/core/pretty-error.test.ts b/packages/evlog/test/core/pretty-error.test.ts index ddd30551..b6b27e6d 100644 --- a/packages/evlog/test/core/pretty-error.test.ts +++ b/packages/evlog/test/core/pretty-error.test.ts @@ -143,14 +143,14 @@ at async file:///Users/dev/project/node_modules/h3/dist/index.mjs:2017:19` }) describe('compactStackForStorage', () => { - it('drops build output and node_modules frames from stored stacks', () => { + it('returns the stack unchanged when only build output and node_modules frames remain', () => { const stack = `EvlogError: Payment method declined at createError (/Users/dev/project/packages/evlog/src/error.ts:699:12) at Object.handler (/Users/dev/project/apps/next-playground/.next/dev/server/chunks/route.js:5372:176) at async /Users/dev/project/node_modules/next/dist/server/base-server.js:934:17 at async /Users/dev/project/node_modules/next/dist/server/lib/start-server.js:225:13` - expect(compactStackForStorage(stack)).toBe('EvlogError: Payment method declined') + expect(compactStackForStorage(stack)).toBe(stack) }) it('keeps app source frames when present', () => { diff --git a/packages/evlog/test/next/instrumentation.test.ts b/packages/evlog/test/next/instrumentation.test.ts index 9832596b..ec30cf9c 100644 --- a/packages/evlog/test/next/instrumentation.test.ts +++ b/packages/evlog/test/next/instrumentation.test.ts @@ -390,22 +390,6 @@ describe('createInstrumentation', () => { expect(passthroughSpy).toHaveBeenCalledTimes(1) }) - it('captureOutput ignores evlog-formatted terminal lines on stdout', async () => { - const createInstrumentation = await loadModule() - process.env.NEXT_RUNTIME = 'nodejs' - - const { register } = createInstrumentation({ - captureOutput: true, - pretty: false, - silent: true, - }) - - await runRegister(register) - - process.stdout.write('ERROR [next-playground] GET /api/test 402 in 1ms\n') - expect(logInfoSpy).not.toHaveBeenCalled() - }) - it('captureOutput custom ignore replaces the default filter', async () => { const createInstrumentation = await loadModule() process.env.NEXT_RUNTIME = 'nodejs'