From 02303852363b539b444a0f2b7b08ad3bd818fc8c Mon Sep 17 00:00:00 2001 From: "Sebastian \"Sebbie\" Silbermann" Date: Fri, 25 Oct 2024 22:58:23 +0200 Subject: [PATCH] Reland "Sourcemap errors in terminal by default" (#71877) --- .../react-dev-overlay/server/shared.ts | 2 +- .../error-inspect.tsx | 3 + packages/next/src/server/node-environment.ts | 3 + .../next/src/server/patch-error-inspect.ts | 232 ++++++++++++++++++ .../app-action-size-limit-invalid.test.ts | 5 +- ...mic-io-errors.prospective-fallback.test.ts | 1 + .../prospective-fallback/next.config.js | 1 + .../fixtures/default/app/layout.js | 7 + .../default/app/rsc-error-log-cause/page.js | 10 + .../app/rsc-error-log-custom-name/page.js | 10 + .../default/app/rsc-error-log/page.js | 9 + .../fixtures/default/next.config.js | 11 + .../server-source-maps.test.ts | 34 +++ 13 files changed, 325 insertions(+), 3 deletions(-) create mode 100644 packages/next/src/server/node-environment-extensions/error-inspect.tsx create mode 100644 packages/next/src/server/patch-error-inspect.ts create mode 100644 test/e2e/app-dir/server-source-maps/fixtures/default/app/layout.js create mode 100644 test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-cause/page.js create mode 100644 test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-custom-name/page.js create mode 100644 test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log/page.js create mode 100644 test/e2e/app-dir/server-source-maps/fixtures/default/next.config.js create mode 100644 test/e2e/app-dir/server-source-maps/server-source-maps.test.ts diff --git a/packages/next/src/client/components/react-dev-overlay/server/shared.ts b/packages/next/src/client/components/react-dev-overlay/server/shared.ts index 2c6e4f175fae7..6ebfd3d43518f 100644 --- a/packages/next/src/client/components/react-dev-overlay/server/shared.ts +++ b/packages/next/src/client/components/react-dev-overlay/server/shared.ts @@ -50,7 +50,7 @@ export function findSourcePackage({ export function getOriginalCodeFrame( frame: StackFrame, source: string | null -): string | null | undefined { +): string | null { if (!source || isInternal(frame.file)) { return null } diff --git a/packages/next/src/server/node-environment-extensions/error-inspect.tsx b/packages/next/src/server/node-environment-extensions/error-inspect.tsx new file mode 100644 index 0000000000000..e086cbd003bd6 --- /dev/null +++ b/packages/next/src/server/node-environment-extensions/error-inspect.tsx @@ -0,0 +1,3 @@ +import { patchErrorInspect } from '../patch-error-inspect' + +patchErrorInspect() diff --git a/packages/next/src/server/node-environment.ts b/packages/next/src/server/node-environment.ts index 83d97ac3a1571..bed9e44fe0d0f 100644 --- a/packages/next/src/server/node-environment.ts +++ b/packages/next/src/server/node-environment.ts @@ -2,6 +2,9 @@ // for later imports to work properly. import './node-environment-baseline' +// Import as early as possible so that unexpected errors in other extensions are properly formatted. +// Has to come after baseline since error-inspect requires AsyncLocalStorage that baseline provides. +import './node-environment-extensions/error-inspect' import './node-environment-extensions/random' import './node-environment-extensions/date' import './node-environment-extensions/web-crypto' diff --git a/packages/next/src/server/patch-error-inspect.ts b/packages/next/src/server/patch-error-inspect.ts new file mode 100644 index 0000000000000..17e74797453ea --- /dev/null +++ b/packages/next/src/server/patch-error-inspect.ts @@ -0,0 +1,232 @@ +import { findSourceMap } from 'module' +import type * as util from 'util' +import { SourceMapConsumer as SyncSourceMapConsumer } from 'next/dist/compiled/source-map' +import type { StackFrame } from 'next/dist/compiled/stacktrace-parser' +import { parseStack } from '../client/components/react-dev-overlay/server/middleware' +import { getOriginalCodeFrame } from '../client/components/react-dev-overlay/server/shared' +import { workUnitAsyncStorage } from './app-render/work-unit-async-storage.external' + +// TODO: Implement for Edge runtime +const inspectSymbol = Symbol.for('nodejs.util.inspect.custom') + +function frameToString(frame: StackFrame): string { + let sourceLocation = frame.lineNumber !== null ? `:${frame.lineNumber}` : '' + if (frame.column !== null && sourceLocation !== '') { + sourceLocation += `:${frame.column}` + } + return frame.methodName + ? ` at ${frame.methodName} (${frame.file}${sourceLocation})` + : ` at ${frame.file}${frame.lineNumber}:${frame.column}` +} + +function computeErrorName(error: Error): string { + // TODO: Node.js seems to use a different algorithm + // class ReadonlyRequestCookiesError extends Error {}` would read `ReadonlyRequestCookiesError: [...]` + // in the stack i.e. seems like under certain conditions it favors the constructor name. + return error.name || 'Error' +} + +function prepareUnsourcemappedStackTrace( + error: Error, + structuredStackTrace: any[] +): string { + const name = computeErrorName(error) + const message = error.message || '' + let stack = name + ': ' + message + for (let i = 0; i < structuredStackTrace.length; i++) { + stack += '\n at ' + structuredStackTrace[i].toString() + } + return stack +} + +function shouldIgnoreListByDefault(file: string): boolean { + return ( + // TODO: Solve via `ignoreList` instead. Tricky because node internals are not part of the sourcemap. + file.startsWith('node:') + // C&P from setup-dev-bundler + // TODO: Taken from setup-dev-bundler but these seem too broad + // file.includes('web/adapter') || + // file.includes('web/globals') || + // file.includes('sandbox/context') || + // TODO: Seems too aggressive? + // file.includes('') || + // file.startsWith('eval') + ) +} + +function getSourcemappedFrameIfPossible( + frame: StackFrame, + sourcemapConsumers: Map +): { + stack: StackFrame + // DEV only + code: string | null +} | null { + if (frame.file === null) { + return null + } + + let sourcemap = sourcemapConsumers.get(frame.file) + if (sourcemap === undefined) { + const moduleSourcemap = findSourceMap(frame.file) + if (moduleSourcemap === undefined) { + return null + } + sourcemap = new SyncSourceMapConsumer( + // @ts-expect-error -- Module.SourceMap['version'] is number but SyncSourceMapConsumer wants a string + moduleSourcemap.payload + ) + sourcemapConsumers.set(frame.file, sourcemap) + } + + const sourcePosition = sourcemap.originalPositionFor({ + column: frame.column ?? 0, + line: frame.lineNumber ?? 1, + }) + + if (sourcePosition.source === null) { + return null + } + + const sourceContent: string | null = + sourcemap.sourceContentFor( + sourcePosition.source, + /* returnNullOnMissing */ true + ) ?? null + + const originalFrame: StackFrame = { + methodName: + sourcePosition.name || + // default is not a valid identifier in JS so webpack uses a custom variable when it's an unnamed default export + // Resolve it back to `default` for the method name if the source position didn't have the method. + frame.methodName + ?.replace('__WEBPACK_DEFAULT_EXPORT__', 'default') + ?.replace('__webpack_exports__.', ''), + column: sourcePosition.column, + file: sourcePosition.source, + lineNumber: sourcePosition.line, + // TODO: c&p from async createOriginalStackFrame but why not frame.arguments? + arguments: [], + } + + const codeFrame = + process.env.NODE_ENV !== 'production' + ? getOriginalCodeFrame(originalFrame, sourceContent) + : null + + return { + stack: originalFrame, + code: codeFrame, + } +} + +function parseAndSourceMap(error: Error): string { + // We overwrote Error.prepareStackTrace earlier so error.stack is not sourcemapped. + let unparsedStack = String(error.stack) + // We could just read it from `error.stack`. + // This works around cases where a 3rd party `Error.prepareStackTrace` implementation + // doesn't implement the name computation correctly. + const errorName = computeErrorName(error) + + let idx = unparsedStack.indexOf('react-stack-bottom-frame') + if (idx !== -1) { + idx = unparsedStack.lastIndexOf('\n', idx) + } + if (idx !== -1) { + // Cut off everything after the bottom frame since it'll be React internals. + unparsedStack = unparsedStack.slice(0, idx) + } + + const unsourcemappedStack = parseStack(unparsedStack) + const sourcemapConsumers = new Map() + + let sourceMappedStack = '' + let sourceFrameDEV: null | string = null + for (const frame of unsourcemappedStack) { + if (frame.file === null) { + sourceMappedStack += '\n' + frameToString(frame) + } else if (!shouldIgnoreListByDefault(frame.file)) { + const sourcemappedFrame = getSourcemappedFrameIfPossible( + frame, + sourcemapConsumers + ) + + if (sourcemappedFrame === null) { + sourceMappedStack += '\n' + frameToString(frame) + } else { + // TODO: Use the first frame that's not ignore-listed + if ( + process.env.NODE_ENV !== 'production' && + sourcemappedFrame.code !== null && + sourceFrameDEV === null + ) { + sourceFrameDEV = sourcemappedFrame.code + } + // TODO: Hide if ignore-listed but consider what happens if every frame is ignore listed. + sourceMappedStack += '\n' + frameToString(sourcemappedFrame.stack) + } + } + } + + return ( + errorName + + ': ' + + error.message + + sourceMappedStack + + (sourceFrameDEV !== null ? '\n' + sourceFrameDEV : '') + ) +} + +export function patchErrorInspect() { + Error.prepareStackTrace = prepareUnsourcemappedStackTrace + + // @ts-expect-error -- TODO upstream types + // eslint-disable-next-line no-extend-native -- We're not extending but overriding. + Error.prototype[inspectSymbol] = function ( + depth: number, + inspectOptions: util.InspectOptions, + inspect: typeof util.inspect + ): string { + // avoid false-positive dynamic i/o warnings e.g. due to usage of `Math.random` in `source-map`. + return workUnitAsyncStorage.exit(() => { + // Create a new Error object with the source mapping applied and then use native + // Node.js formatting on the result. + const newError = + this.cause !== undefined + ? // Setting an undefined `cause` would print `[cause]: undefined` + new Error(this.message, { cause: this.cause }) + : new Error(this.message) + + // TODO: Ensure `class MyError extends Error {}` prints `MyError` as the name + newError.stack = parseAndSourceMap(this) + + for (const key in this) { + if (!Object.prototype.hasOwnProperty.call(newError, key)) { + // @ts-expect-error -- We're copying all enumerable properties. + // So they definitely exist on `this` and obviously have no type on `newError` (yet) + newError[key] = this[key] + } + } + + const originalCustomInspect = (newError as any)[inspectSymbol] + // Prevent infinite recursion. + // { customInspect: false } would result in `error.cause` not using our inspect. + Object.defineProperty(newError, inspectSymbol, { + value: undefined, + enumerable: false, + writable: true, + }) + try { + return inspect(newError, { + ...inspectOptions, + depth: + (inspectOptions.depth ?? + // Default in Node.js + 2) - depth, + }) + } finally { + ;(newError as any)[inspectSymbol] = originalCustomInspect + } + }) + } +} diff --git a/test/e2e/app-dir/actions/app-action-size-limit-invalid.test.ts b/test/e2e/app-dir/actions/app-action-size-limit-invalid.test.ts index bf0699962bf25..f3cfb6c442080 100644 --- a/test/e2e/app-dir/actions/app-action-size-limit-invalid.test.ts +++ b/test/e2e/app-dir/actions/app-action-size-limit-invalid.test.ts @@ -1,5 +1,6 @@ import { nextTestSetup } from 'e2e-utils' import { retry } from 'next-test-utils' +import stripAnsi from 'strip-ansi' import { accountForOverhead } from './account-for-overhead' const CONFIG_ERROR = @@ -26,7 +27,7 @@ describe('app-dir action size limit invalid config', () => { beforeAll(() => { const onLog = (log: string) => { - logs.push(log.trim()) + logs.push(stripAnsi(log.trim())) } next.on('stdout', onLog) @@ -115,7 +116,7 @@ describe('app-dir action size limit invalid config', () => { await retry(() => { expect(logs).toContainEqual( - expect.stringContaining('[Error]: Body exceeded 1.5mb limit') + expect.stringContaining('Error: Body exceeded 1.5mb limit') ) expect(logs).toContainEqual( expect.stringContaining( diff --git a/test/e2e/app-dir/dynamic-io-errors/dynamic-io-errors.prospective-fallback.test.ts b/test/e2e/app-dir/dynamic-io-errors/dynamic-io-errors.prospective-fallback.test.ts index ab021df70a7fb..d9c59ec790450 100644 --- a/test/e2e/app-dir/dynamic-io-errors/dynamic-io-errors.prospective-fallback.test.ts +++ b/test/e2e/app-dir/dynamic-io-errors/dynamic-io-errors.prospective-fallback.test.ts @@ -27,6 +27,7 @@ describe(`Dynamic IO Prospective Fallback`, () => { // we expect the build to fail } + // TODO: Assert on component stack expect(next.cliOutput).toContain( 'Route "/blog/[slug]": A component accessed data, headers, params, searchParams, or a short-lived cache without a Suspense boundary nor a "use cache" above it.' ) diff --git a/test/e2e/app-dir/dynamic-io-errors/fixtures/prospective-fallback/next.config.js b/test/e2e/app-dir/dynamic-io-errors/fixtures/prospective-fallback/next.config.js index bb76fc99dc6b6..195ad29be3c54 100644 --- a/test/e2e/app-dir/dynamic-io-errors/fixtures/prospective-fallback/next.config.js +++ b/test/e2e/app-dir/dynamic-io-errors/fixtures/prospective-fallback/next.config.js @@ -1,5 +1,6 @@ module.exports = { experimental: { dynamicIO: true, + serverSourceMaps: true, }, } diff --git a/test/e2e/app-dir/server-source-maps/fixtures/default/app/layout.js b/test/e2e/app-dir/server-source-maps/fixtures/default/app/layout.js new file mode 100644 index 0000000000000..a3a86a5ca1e12 --- /dev/null +++ b/test/e2e/app-dir/server-source-maps/fixtures/default/app/layout.js @@ -0,0 +1,7 @@ +export default function Root({ children }) { + return ( + + {children} + + ) +} diff --git a/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-cause/page.js b/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-cause/page.js new file mode 100644 index 0000000000000..cbeade4a077fb --- /dev/null +++ b/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-cause/page.js @@ -0,0 +1,10 @@ +function logError(cause) { + const error = new Error('Boom', { cause }) + console.error(error) +} + +export default function Page() { + const error = new Error('Boom') + logError(error) + return null +} diff --git a/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-custom-name/page.js b/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-custom-name/page.js new file mode 100644 index 0000000000000..cd973b42ae401 --- /dev/null +++ b/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log-custom-name/page.js @@ -0,0 +1,10 @@ +class UnnamedError extends Error {} +class NamedError extends Error { + name = 'MyError' +} + +export default function Page() { + console.error(new UnnamedError('Foo')) + console.error(new NamedError('Bar')) + return null +} diff --git a/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log/page.js b/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log/page.js new file mode 100644 index 0000000000000..383f4689b600c --- /dev/null +++ b/test/e2e/app-dir/server-source-maps/fixtures/default/app/rsc-error-log/page.js @@ -0,0 +1,9 @@ +function logError() { + const error = new Error('Boom') + console.error(error) +} + +export default function Page() { + logError() + return null +} diff --git a/test/e2e/app-dir/server-source-maps/fixtures/default/next.config.js b/test/e2e/app-dir/server-source-maps/fixtures/default/next.config.js new file mode 100644 index 0000000000000..2e3b04951d3b6 --- /dev/null +++ b/test/e2e/app-dir/server-source-maps/fixtures/default/next.config.js @@ -0,0 +1,11 @@ +/** + * @type {import('next').NextConfig} + */ +const nextConfig = { + experimental: { + dynamicIO: true, + serverSourceMaps: true, + }, +} + +module.exports = nextConfig diff --git a/test/e2e/app-dir/server-source-maps/server-source-maps.test.ts b/test/e2e/app-dir/server-source-maps/server-source-maps.test.ts new file mode 100644 index 0000000000000..4174e83860b43 --- /dev/null +++ b/test/e2e/app-dir/server-source-maps/server-source-maps.test.ts @@ -0,0 +1,34 @@ +import * as path from 'path' +import { nextTestSetup } from 'e2e-utils' + +describe('app-dir - server source maps', () => { + const { skipped, next, isNextDev } = nextTestSetup({ + files: path.join(__dirname, 'fixtures/default'), + // Deploy tests don't have access to runtime logs. + // Manually verify that the runtime logs match. + skipDeployment: true, + }) + + if (skipped) return + + it('logged errors have a sourcemapped stack with a codeframe', async () => { + // TODO: Write test once we run with `--enable-source-maps` when `experimental.serverSourceMaps` is set + }) + + it('logged errors have a sourcemapped `cause`', async () => { + // TODO: Write test once we run with `--enable-source-maps` when `experimental.serverSourceMaps` is set + }) + + it('logged errors preserve their name', async () => { + await next.render('/rsc-error-log-custom-name') + + expect(next.cliOutput).toContain( + // TODO: isNextDev ? 'UnnamedError: Foo' : '[Error]: Foo' + isNextDev ? 'Error: Foo' : 'Error: Foo' + ) + expect(next.cliOutput).toContain( + // TODO: isNextDev ? 'NamedError [MyError]: Bar' : '[MyError]: Bar' + isNextDev ? 'Error [MyError]: Bar' : 'Error [MyError]: Bar' + ) + }) +})