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

errors: display original symbol name #36042

Closed
wants to merge 7 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
1 change: 1 addition & 0 deletions doc/api/module.md
Original file line number Diff line number Diff line change
Expand Up @@ -195,6 +195,7 @@ consists of the following keys:
* originalSource: {string}
* originalLine: {number}
* originalColumn: {number}
* name: {string}

[CommonJS]: modules.md
[ES Modules]: esm.md
Expand Down
124 changes: 81 additions & 43 deletions lib/internal/source_map/prepare_stack_trace.js
Original file line number Diff line number Diff line change
Expand Up @@ -47,45 +47,48 @@ const prepareStackTrace = (globalThis, error, trace) => {
}

let errorSource = '';
let firstLine;
let firstColumn;
let lastSourceMap;
let lastFileName;
const preparedTrace = ArrayPrototypeJoin(ArrayPrototypeMap(trace, (t, i) => {
if (i === 0) {
firstLine = t.getLineNumber();
firstColumn = t.getColumnNumber();
}
let str = i !== 0 ? '\n at ' : '';
str = `${str}${t}`;
try {
const sm = findSourceMap(t.getFileName());
// A stack trace will often have several call sites in a row within the
// same file, cache the source map and file content accordingly:
const fileName = t.getFileName();
const sm = fileName === lastFileName ?
lastSourceMap :
findSourceMap(fileName);
lastSourceMap = sm;
lastFileName = fileName;
if (sm) {
// Source Map V3 lines/columns use zero-based offsets whereas, in
// stack traces, they start at 1/1.
// Source Map V3 lines/columns start at 0/0 whereas stack traces
// start at 1/1:
const {
originalLine,
originalColumn,
originalSource
originalSource,
} = sm.findEntry(t.getLineNumber() - 1, t.getColumnNumber() - 1);
if (originalSource && originalLine !== undefined &&
originalColumn !== undefined) {
const name = getOriginalSymbolName(sm, trace, i);
if (i === 0) {
firstLine = originalLine + 1;
firstColumn = originalColumn + 1;

// Show error in original source context to help user pinpoint it:
errorSource = getErrorSource(
sm.payload,
sm,
originalSource,
firstLine,
firstColumn
originalLine,
originalColumn
);
}
// Show both original and transpiled stack trace information:
const prefix = (name && name !== t.getFunctionName()) ?
`\n -> at ${name}` :
'\n ->';
const originalSourceNoScheme =
StringPrototypeStartsWith(originalSource, 'file://') ?
fileURLToPath(originalSource) : originalSource;
str += `\n -> ${originalSourceNoScheme}:${originalLine + 1}:` +
`${originalColumn + 1}`;
str += `${prefix} (${originalSourceNoScheme}:${originalLine + 1}:` +
Copy link
Contributor Author

@bcoe bcoe Nov 8, 2020

Choose a reason for hiding this comment

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

Worth noting that this puts a (, ) around the file paths in supplemental stack traces now. I felt that this looked better when we have an alternate symbol name, and it seemed more consistent to always wrap in parenthesis:

Error: an exception
    at branch (/Users/bencoe/oss/node-1/test/fixtures/source-map/typescript-throw.js:20:15)
        -> (/Users/bencoe/oss/node-1/test/fixtures/source-map/typescript-throw.ts:18:11)

Edit: figured while we're calling the feature experimental, it's the time to make these tweaks.

Copy link
Member

Choose a reason for hiding this comment

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

as a heads up, this might make it incompatible with the tc39 stacks proposal, if it ever lands - it’ll only specify the union of what browsers do.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@ljharb what would you suggest we do to provide appropriate context about the transpiled call site and original call site, in the spirit of the spirit of the tc39 stacks proposal?

I'm hoping to make the case for removing the experimental language from --enable-source-maps soon -- so now would be a good time to make significant changes to output if needed.

Copy link
Member

Choose a reason for hiding this comment

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

The challenge is specifying what browsers all already do, without permitting anything beyond that.

What do browsers do here on source mapped exception stacks? If the answer is “nothing special”, then that’s probably what node should do too :-/

Copy link
Contributor Author

@bcoe bcoe Nov 29, 2020

Choose a reason for hiding this comment

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

What do browsers do here on source mapped exception stacks? If the answer is “nothing special”, then that’s probably what node should do too :-/

TypeScript and other transpiled flavors or JavaScript have exploded in popularity over the past several years, I'd argue that stack traces just haven't caught up with this need:

  • 6.1m projects rely source-map-support, to provide better debugging information in stack traces are used.
  • A healthy number of folks are finding --enable-source-maps (my team is using it ourselves because it speeds up our debugging during test).
  • Threads like this indicate that folks are more concerned about transpiled server code, when it comes to using contextual information about the stack.

I would have originally gone with the approach source-map-support, of simply replacing the transpiled Call Site with the original Call Site. I believe @hashseed had the idea of displaying both the source and original Call Site, and I believe there's value in this, for a variety of reasons: when looking at an error, it can be good to see how the source was transpiled; source maps, despite best efforts, are sometimes off.


It would be nice if the stacks proposal gave us enough flexibility that we could insert this extra contextual information into the stack trace, without breaking upstream parser.

Couldn't we just consider this to be one line of the stack trace:

at o (/Users/bencoe/oss/node-sourcemap-repro/dist/main.js:1:970)
      -> at functionD (webpack:///index.js:14:9)

☝️ the tabbed in line without an at is fairly distinct.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@ljharb let's move this conversation to the TC39 proposal; this PR is just patching a bug, not introducing new behavior to Node.js.

Copy link
Member

Choose a reason for hiding this comment

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

per our offline discussion, it might be simpler for now to leave .stack as having only one of the results (source, or transpiled), and maybe providing a separate API (Error.getOriginalStack(), Error.getUnmappedStack()) to access the other one? That would ensure no conflicts with the stacks proposal.

Copy link
Member

Choose a reason for hiding this comment

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

Did this land as-is, with the parentheticals discussed here?

`${originalColumn + 1})`;
}
}
} catch (err) {
Expand All @@ -96,18 +99,69 @@ const prepareStackTrace = (globalThis, error, trace) => {
return `${errorSource}${errorString}\n at ${preparedTrace}`;
};

// Transpilers may have removed the original symbol name used in the stack
// trace, if possible restore it from the names field of the source map:
function getOriginalSymbolName(sourceMap, trace, curIndex) {
// First check for a symbol name associated with the enclosing function:
const enclosingEntry = sourceMap.findEntry(
trace[curIndex].getEnclosingLineNumber() - 1,
trace[curIndex].getEnclosingColumnNumber() - 1
);
if (enclosingEntry.name) return enclosingEntry.name;
// Fallback to using the symbol name attached to the next stack frame:
const currentFileName = trace[curIndex].getFileName();
const nextCallSite = trace[curIndex + 1];
if (nextCallSite && currentFileName === nextCallSite.getFileName()) {
const { name } = sourceMap.findEntry(
nextCallSite.getLineNumber() - 1,
nextCallSite.getColumnNumber() - 1
);
return name;
}
}

// Places a snippet of code from where the exception was originally thrown
// above the stack trace. This logic is modeled after GetErrorSource in
// node_errors.cc.
function getErrorSource(payload, originalSource, firstLine, firstColumn) {
function getErrorSource(
sourceMap,
originalSourcePath,
originalLine,
originalColumn
) {
let exceptionLine = '';
const originalSourceNoScheme =
StringPrototypeStartsWith(originalSource, 'file://') ?
fileURLToPath(originalSource) : originalSource;
const originalSourcePathNoScheme =
StringPrototypeStartsWith(originalSourcePath, 'file://') ?
fileURLToPath(originalSourcePath) : originalSourcePath;
const source = getOriginalSource(
sourceMap.payload,
originalSourcePathNoScheme
);
const lines = StringPrototypeSplit(source, /\r?\n/, originalLine + 1);
const line = lines[originalLine];
if (!line) return exceptionLine;

// Display ^ in appropriate position, regardless of whether tabs or
// spaces are used:
let prefix = '';
for (const character of StringPrototypeSlice(line, 0, originalColumn + 1)) {
prefix += (character === '\t') ? '\t' :
StringPrototypeRepeat(' ', getStringWidth(character));
}
prefix = StringPrototypeSlice(prefix, 0, -1); // The last character is '^'.

exceptionLine =
`${originalSourcePathNoScheme}:${originalLine + 1}\n${line}\n${prefix}^\n\n`;
return exceptionLine;
}

function getOriginalSource(payload, originalSourcePath) {
let source;
const originalSourcePathNoScheme =
StringPrototypeStartsWith(originalSourcePath, 'file://') ?
fileURLToPath(originalSourcePath) : originalSourcePath;
const sourceContentIndex =
ArrayPrototypeIndexOf(payload.sources, originalSource);
ArrayPrototypeIndexOf(payload.sources, originalSourcePath);
if (payload.sourcesContent?.[sourceContentIndex]) {
// First we check if the original source content was provided in the
// source map itself:
Expand All @@ -116,29 +170,13 @@ function getErrorSource(payload, originalSource, firstLine, firstColumn) {
// If no sourcesContent was found, attempt to load the original source
// from disk:
try {
source = readFileSync(originalSourceNoScheme, 'utf8');
source = readFileSync(originalSourcePathNoScheme, 'utf8');
} catch (err) {
debug(err);
return '';
source = '';
}
}

const lines = StringPrototypeSplit(source, /\r?\n/, firstLine);
const line = lines[firstLine - 1];
if (!line) return exceptionLine;

// Display ^ in appropriate position, regardless of whether tabs or
// spaces are used:
let prefix = '';
for (const character of StringPrototypeSlice(line, 0, firstColumn)) {
prefix += (character === '\t') ? '\t' :
StringPrototypeRepeat(' ', getStringWidth(character));
}
prefix = StringPrototypeSlice(prefix, 0, -1); // The last character is '^'.

exceptionLine =
`${originalSourceNoScheme}:${firstLine}\n${line}\n${prefix}^\n\n`;
return exceptionLine;
return source;
}

module.exports = {
Expand Down
16 changes: 10 additions & 6 deletions lib/internal/source_map/source_map.js
Original file line number Diff line number Diff line change
Expand Up @@ -203,7 +203,8 @@ class SourceMap {
generatedColumn: entry[1],
originalSource: entry[2],
originalLine: entry[3],
originalColumn: entry[4]
originalColumn: entry[4],
name: entry[5],
};
}

Expand All @@ -214,6 +215,7 @@ class SourceMap {
let sourceIndex = 0;
let sourceLineNumber = 0;
let sourceColumnNumber = 0;
let nameIndex = 0;

const sources = [];
const originalToCanonicalURLMap = {};
Expand All @@ -229,7 +231,6 @@ class SourceMap {

const stringCharIterator = new StringCharIterator(map.mappings);
let sourceURL = sources[sourceIndex];

while (true) {
if (stringCharIterator.peek() === ',')
stringCharIterator.next();
Expand All @@ -256,12 +257,15 @@ class SourceMap {
}
sourceLineNumber += decodeVLQ(stringCharIterator);
sourceColumnNumber += decodeVLQ(stringCharIterator);
if (!isSeparator(stringCharIterator.peek()))
// Unused index into the names list.
decodeVLQ(stringCharIterator);

let name;
if (!isSeparator(stringCharIterator.peek())) {
nameIndex += decodeVLQ(stringCharIterator);
name = map.names?.[nameIndex];
}

this.#mappings.push([lineNumber, columnNumber, sourceURL,
sourceLineNumber, sourceColumnNumber]);
sourceLineNumber, sourceColumnNumber, name]);
}
};
}
Expand Down
3 changes: 3 additions & 0 deletions test/fixtures/source-map/enclosing-call-site-min.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
var functionA=function(){functionB()};function functionB(){functionC()}var functionC=function(){functionD()},functionD=function(){if(0<Math.random())throw Error("an error!");},thrower=functionA;try{functionA()}catch(a){throw a;};
//# sourceMappingURL=enclosing-call-site.js.map

27 changes: 27 additions & 0 deletions test/fixtures/source-map/enclosing-call-site.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
const functionA = () => {
functionB()
}

function functionB() {
functionC()
}

const functionC = () => {
functionD()
}

const functionD = () => {
(function functionE () {
if (Math.random() > 0) {
throw new Error('an error!')
}
})()
}

const thrower = functionA

try {
thrower()
} catch (err) {
throw err
}
8 changes: 8 additions & 0 deletions test/fixtures/source-map/enclosing-call-site.js.map

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

5 changes: 5 additions & 0 deletions test/message/source_map_enclosing_function.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
// Flags: --enable-source-maps

'use strict';
require('../common');
require('../fixtures/source-map/enclosing-call-site-min.js');
20 changes: 20 additions & 0 deletions test/message/source_map_enclosing_function.out
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
*enclosing-call-site.js:16
throw new Error('an error!')
^

Error: an error!
at functionD (*enclosing-call-site-min.js:1:156)
-> (*enclosing-call-site.js:16:17)
at functionC (*enclosing-call-site-min.js:1:97)
-> (*enclosing-call-site.js:10:3)
at functionB (*enclosing-call-site-min.js:1:60)
-> (*enclosing-call-site.js:6:3)
at functionA (*enclosing-call-site-min.js:1:26)
-> (*enclosing-call-site.js:2:3)
at Object.<anonymous> (*enclosing-call-site-min.js:1:199)
-> (*enclosing-call-site.js:24:3)
at Module._compile (node:internal/modules/cjs/loader:*)
at Object.Module._extensions..js (node:internal/modules/cjs/loader:*)
at Module.load (node:internal/modules/cjs/loader:*)
at Function.Module._load (node:internal/modules/cjs/loader:*)
at Module.require (node:internal/modules/cjs/loader:*)
4 changes: 2 additions & 2 deletions test/message/source_map_reference_error_tabs.out
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,9 @@

ReferenceError: alert is not defined
at Object.<anonymous> (*tabs.coffee:39:5)
-> *tabs.coffee:26:2
-> *tabs.coffee:26:2*
at Object.<anonymous> (*tabs.coffee:53:4)
-> *tabs.coffee:1:14
-> *tabs.coffee:1:14*
at Module._compile (node:internal/modules/cjs/loader:*
at Object.Module._extensions..js (node:internal/modules/cjs/loader:*
at Module.load (node:internal/modules/cjs/loader:*
Expand Down
4 changes: 2 additions & 2 deletions test/message/source_map_throw_catch.out
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,9 @@ reachable
^
Error: an exception
at branch (*typescript-throw.js:20:15)
-> *typescript-throw.ts:18:11
-> *typescript-throw.ts:18:11*
at Object.<anonymous> (*typescript-throw.js:26:1)
-> *typescript-throw.ts:24:1
-> *typescript-throw.ts:24:1*
at Module._compile (node:internal/modules/cjs/loader:*)
at Object.Module._extensions..js (node:internal/modules/cjs/loader:*)
at Module.load (node:internal/modules/cjs/loader:*)
Expand Down
4 changes: 2 additions & 2 deletions test/message/source_map_throw_first_tick.out
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,9 @@ reachable
^
Error: an exception
at branch (*typescript-throw.js:20:15)
-> *typescript-throw.ts:18:11
-> *typescript-throw.ts:18:11*
at Object.<anonymous> (*typescript-throw.js:26:1)
-> *typescript-throw.ts:24:1
-> *typescript-throw.ts:24:1*
at Module._compile (node:internal/modules/cjs/loader:*)
at Object.Module._extensions..js (node:internal/modules/cjs/loader:*)
at Module.load (node:internal/modules/cjs/loader:*)
Expand Down
4 changes: 2 additions & 2 deletions test/message/source_map_throw_icu.out
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,9 @@

Error: an error
at Object.createElement (*icu.js:5:7)
-> *icu.jsx:3:23
-> *icu.jsx:3:23*
at Object.<anonymous> (*icu.js:8:82)
-> *icu.jsx:9:5
-> *icu.jsx:9:5*
at Module._compile (node:internal/modules/cjs/loader:*
at Object.Module._extensions..js (node:internal/modules/cjs/loader:*
at Module.load (node:internal/modules/cjs/loader:*
Expand Down
4 changes: 2 additions & 2 deletions test/message/source_map_throw_set_immediate.out
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@

Error: goodbye
at *uglify-throw.js:1:43
-> *uglify-throw-original.js:5:9
-> at Hello *uglify-throw-original.js:5:9*
at Immediate.<anonymous> (*uglify-throw.js:1:60)
-> *uglify-throw-original.js:9:3
-> *uglify-throw-original.js:9:3*
at processImmediate (node:internal/timers:*)
20 changes: 13 additions & 7 deletions test/parallel/test-source-map-enable.js
Original file line number Diff line number Diff line change
Expand Up @@ -170,12 +170,15 @@ function nextdir() {
'--enable-source-maps',
require.resolve('../fixtures/source-map/uglify-throw.js')
]);
assert.ok(
output.stderr.toString().match(/->.*uglify-throw-original\.js:5:9/)
assert.match(
output.stderr.toString(),
/->.*uglify-throw-original\.js:5:9/
);
assert.ok(
output.stderr.toString().match(/->.*uglify-throw-original\.js:9:3/)
assert.match(
output.stderr.toString(),
/->.*uglify-throw-original\.js:9:3/
);
assert.match(output.stderr.toString(), /at Hello/);
}

// Applies source-maps generated by tsc to stack trace.
Expand Down Expand Up @@ -276,11 +279,14 @@ function nextdir() {
require.resolve('../fixtures/source-map/webpack.js')
]);
// Error in original context of source content:
assert.ok(
output.stderr.toString().match(/throw new Error\('oh no!'\)\r?\n.*\^/)
assert.match(
output.stderr.toString(),
/throw new Error\('oh no!'\)\r?\n.*\^/
);
// Rewritten stack trace:
assert.ok(output.stderr.toString().includes('webpack:///webpack.js:14:9'));
assert.match(output.stderr.toString(), /webpack:\/\/\/webpack\.js:14:9/);
assert.match(output.stderr.toString(), /at functionD.*14:9/);
assert.match(output.stderr.toString(), /at functionC.*10:3/);
}

// Stores and applies source map associated with file that throws while
Expand Down