Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sourcemap errors in terminal by default #71444

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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
}
Expand All @@ -65,6 +65,7 @@ export function getOriginalCodeFrame(
column: frame.column ?? 0,
},
},
// TODO: Only in TTY
{ forceColor: true }
)
}
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
import { patchErrorInspect } from '../patch-error-inspect'

patchErrorInspect()
Comment on lines +1 to +3
Copy link
Member Author

@eps1lon eps1lon Oct 22, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seemingly unnecessary indirection but I went back and forth when to patch and if the patch needs arguments. Keeping the indirection for development for now.

3 changes: 3 additions & 0 deletions packages/next/src/server/node-environment.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,9 @@
// This file should be imported before any others. It sets up the environment
// for later imports to work properly.

// Import before anything else so that unexpected errors in other extensions are properly formatted.
import './node-environment-extensions/error-inspect'

import './node-environment-baseline'
import './node-environment-extensions/random'
import './node-environment-extensions/date'
Expand Down
228 changes: 228 additions & 0 deletions packages/next/src/server/patch-error-inspect.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,228 @@
import { findSourceMap } from 'module'
import type * as util from 'util'
import { SourceMapConsumer as SyncSourceMapConsumer } from 'next/dist/compiled/source-map'
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is an older version of source-map that's still sync (mozilla/source-map#331). Consider moving to https://www.npmjs.com/package/@cspotcode/source-map-consumer

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'
Comment on lines +5 to +6
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Move these to a more appropriate place. These modules are not used on the Client.


// TODO: Implement for Edge runtime
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also for me to test how this works in our Edge sandbox.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also test with Bun.

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.
Comment on lines +22 to +24
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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('<anonymous>') ||
// file.startsWith('eval')
)
}

function getSourcemappedFrameIfPossible(
frame: StackFrame,
sourcemapConsumers: Map<string, SyncSourceMapConsumer>
): {
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.
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this just go through ignore listing? Mainly because I think we want an option to disable ignore listing in the terminal in case you encounter Next.js/React bugs.

unparsedStack = unparsedStack.slice(0, idx)
}

const unsourcemappedStack = parseStack(unparsedStack)
const sourcemapConsumers = new Map<string, SyncSourceMapConsumer>()

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 {
// 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,
Comment on lines +219 to +222
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we wouldn't respect the max depth, if we'd just forward all options. Haven't tested though.

})
} finally {
;(newError as any)[inspectSymbol] = originalCustomInspect
}
}
}
Original file line number Diff line number Diff line change
@@ -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 =
Expand All @@ -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)
Expand Down Expand Up @@ -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(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ describe(`Dynamic IO Prospective Fallback`, () => {
// we expect the build to fail
}

// TODO: Assert on component stack
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With this change:

Error: In Route "/blog/[slug]" this component accessed data without a fallback UI available somewhere above it using Suspense.
    at E (webpack:///src/client/components/layout-router.tsx:324:3)
    at c (webpack:///src/client/components/redirect-boundary.tsx:48:5)
    at l (webpack:///src/client/components/redirect-boundary.tsx:78:34)
    at l (webpack:///src/client/components/not-found-boundary.tsx:119:3)
    at O (webpack:///src/client/components/layout-router.tsx:466:3)
    at ErrorBoundary (webpack:///src/client/components/error-boundary.tsx:190:3)
    at P (webpack:///src/client/components/layout-router.tsx:289:3)
    at S (webpack:///src/client/components/layout-router.tsx:299:9)
    at RenderFromTemplateContext (webpack:///src/client/components/render-from-template-context.tsx:8:10)
    at R (webpack:///src/client/components/layout-router.tsx:514:9)
    at E (webpack:///src/client/components/layout-router.tsx:324:3)
    at c (webpack:///src/client/components/redirect-boundary.tsx:48:5)
    at l (webpack:///src/client/components/redirect-boundary.tsx:78:34)
    at l (webpack:///src/client/components/not-found-boundary.tsx:119:3)
    at O (webpack:///src/client/components/layout-router.tsx:466:3)
    at ErrorBoundary (webpack:///src/client/components/error-boundary.tsx:190:3)
    at P (webpack:///src/client/components/layout-router.tsx:289:3)
    at S (webpack:///src/client/components/layout-router.tsx:299:9)
    at RenderFromTemplateContext (webpack:///src/client/components/render-from-template-context.tsx:8:10)
    at R (webpack:///src/client/components/layout-router.tsx:514:9)
    at E (webpack:///src/client/components/layout-router.tsx:324:3)
    at c (webpack:///src/client/components/redirect-boundary.tsx:48:5)
    at l (webpack:///src/client/components/redirect-boundary.tsx:78:34)
    at c (webpack:///src/client/components/not-found-boundary.tsx:33:5)
    at l (webpack:///src/client/components/not-found-boundary.tsx:119:3)
    at O (webpack:///src/client/components/layout-router.tsx:466:3)
    at ErrorBoundary (webpack:///src/client/components/error-boundary.tsx:190:3)
    at P (webpack:///src/client/components/layout-router.tsx:289:3)
    at S (webpack:///src/client/components/layout-router.tsx:299:9)
    at RenderFromTemplateContext (webpack:///src/client/components/render-from-template-context.tsx:8:10)
    at R (webpack:///src/client/components/layout-router.tsx:514:9)
    at body (<anonymous>)
    at html (<anonymous>)
    at constructor (webpack://next/dist/src/client/components/redirect-boundary.tsx?07a0:48:5)
    at splitInterceptingRoute (webpack://next/dist/src/client/components/redirect-boundary.tsx?07a0:79:9)
    at splitInterceptingRoute (webpack://next/dist/src/client/components/app-router.tsx?b068:215:9)
    at constructor (webpack://next/dist/src/client/components/error-boundary.tsx?ce04:69:11)
    at errorComponent (webpack://next/dist/src/client/components/error-boundary.tsx?ce04:190:3)
    at actionQueue (webpack://next/dist/src/client/components/app-router.tsx?b068:632:3)
    at ServerInsertedHTMLProvider (webpack://next/dist/src/server/app-render/server-inserted-html.tsx?7790:14:34)
    at splitInterceptingRoute (webpack://next/dist/src/server/app-render/app-render.tsx?93c3:836:3)

Follow-up:

  • remove webpack:// prefix
  • Find out why names are not sourcemapped and still minified
  • no useful component stack. I would've expected the component that accessed the data to show up here?

expect(next.cliOutput).toContain(
'In Route "/blog/[slug]" this component accessed data without a Suspense boundary above it to provide a fallback UI.'
)
Expand Down
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
module.exports = {
experimental: {
dynamicIO: true,
serverSourceMaps: true,
},
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,7 @@
export default function Root({ children }) {
return (
<html>
<body>{children}</body>
</html>
)
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
export const dynamic = 'force-dynamic'

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
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
export const dynamic = 'force-dynamic'

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
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
export const dynamic = 'force-dynamic'

function logError() {
const error = new Error('Boom')
console.error(error)
}

export default function Page() {
logError()
return null
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,10 @@
/**
* @type {import('next').NextConfig}
*/
const nextConfig = {
experimental: {
serverSourceMaps: true,
},
}

module.exports = nextConfig
34 changes: 34 additions & 0 deletions test/e2e/app-dir/server-source-maps/server-source-maps.test.ts
Original file line number Diff line number Diff line change
@@ -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,
Comment on lines +7 to +9
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

})

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'
)
})
})
Loading