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

lib: fix inspector links for stack traces #35725

Open
wants to merge 7 commits into
base: main
Choose a base branch
from

Conversation

Dragiyski
Copy link

@Dragiyski Dragiyski commented Oct 20, 2020

When the chrome inspector (chrome://inspect) display stack traces, it
makes the filename clickable, and developer can easily locate the
relevant source with a single click. This only works when filenames are
valid URLs. The CJS loader seems to compile sources with absolute path
instead of URL, breaking the inspector functionality. This is especially
apparent when node_modules contain "at" symbol (@). The loader already
presents module to the inspector using file URL, the same URL should be
used for compiling the source.

For example the current stack trace looks like this:

Current Stack Trace

TypeError: (...)
    at Object.<anonymous> (/home/dragiyski/(...)/@dragiyski/(...)/test.js:19:5)

and as shown the link covers only the part after the first slash after the @ directory. The link leads to URL starting with slash (/), which opens an empty (about:blank) tab within the browser. This is an expected behavior, because in URLs @ represents user@host delimiter and the path is not valid absolute URL as it does not have protocol. A properly fixed URL looks like this:

Fixed Stack Trace

TypeError: (...)
    at Object.<anonymous> (file:///home/dragiyski/(...)/@dragiyski/(...)/test.js:19:5)

and clicking on the link provided in inspector opens the actual location of the source for all call sites, including node_modules containing @ symbol in their path. For the console, the path is printed with file:// in front and clickable in some terminals.

Note: (...) replaces a valid path omitted for security reasons.

Checklist
  • make -j4 test (UNIX), or vcbuild test (Windows) passes
  • tests and/or benchmarks are included
  • commit message follows commit guidelines

@nodejs-github-bot
Copy link
Collaborator

Review requested:

  • @nodejs/modules

@Trott Trott added the request-ci Add this label to start a Jenkins CI on a PR. label Oct 21, 2020
@github-actions github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Oct 21, 2020
@nodejs-github-bot
Copy link
Collaborator

@Dragiyski Dragiyski changed the title fix: inspector links for stack traces lib: fix inspector links for stack traces Oct 21, 2020
@codecov-io
Copy link

Codecov Report

Merging #35725 into master will decrease coverage by 0.00%.
The diff coverage is 89.47%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master   #35725      +/-   ##
==========================================
- Coverage   96.40%   96.40%   -0.01%     
==========================================
  Files         222      223       +1     
  Lines       73682    73713      +31     
==========================================
+ Hits        71034    71061      +27     
- Misses       2648     2652       +4     
Impacted Files Coverage Δ
lib/internal/source_map/source_map_cache.js 84.66% <76.47%> (-0.68%) ⬇️
lib/assert.js 98.11% <100.00%> (+0.01%) ⬆️
lib/internal/modules/cjs/loader.js 94.41% <100.00%> (+0.01%) ⬆️
lib/internal/source_map/prepare_stack_trace.js 95.08% <100.00%> (+0.12%) ⬆️
lib/util/types.js 100.00% <0.00%> (ø)

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 6b6bbfe...f976a8b. Read the comment docs.

@Trott Trott added the request-ci Add this label to start a Jenkins CI on a PR. label Oct 31, 2020
@github-actions github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Oct 31, 2020
@nodejs-github-bot
Copy link
Collaborator

@Trott
Copy link
Member

Trott commented Oct 31, 2020

This could use some reviews. @nodejs/inspector @nodejs/assert @nodejs/modules-active-members @nodejs/testing @bcoe (source maps)

I keep meaning to take a closer look and don't, so I'll ask my question here without having done that (sorry): How does this affect non-inspector output? Will file URLs start showing up in my stack traces at the command line? Or is this inspector-output only?

@Dragiyski
Copy link
Author

Dragiyski commented Oct 31, 2020

This could use some reviews. @nodejs/inspector @nodejs/assert @nodejs/modules-active-members @nodejs/testing @bcoe (source maps)

I keep meaning to take a closer look and don't, so I'll ask my question here without having done that (sorry): How does this affect non-inspector output? Will file URLs start showing up in my stack traces at the command line? Or is this inspector-output only?

Yes, it will affect the console output (stderr/stdout) and the inspector output. Current implementation seems inconsistent, there are already URLs in the output when ESM modules are involved:

// error.mjs
export default function test() {
    throw new Error();
}
// main.js
(function () {
    'use strict';

    (async () => {
        const test = await import('./error.mjs');
        test.default();
    })().catch(error => {
        console.error(error);
    });
})();
Output:
Error
    at Module.test (file:///home/dragiyski/projects/nodejs/test/error.mjs:2:11)
    at /home/dragiyski/projects/nodejs/test/main.js:6:21
New Output:
Error
    at Module.test (file:///home/dragiyski/projects/nodejs/test/error.mjs:2:11)
    at file:///home/dragiyski/projects/nodejs/test/main.js:6:21

There is also URLs even the error is thrown in the CJS module:

// main.mjs
import test from './error.js';

test();
// error.js
module.exports = function () {
    throw new Error();
};
Output:
/home/dragiyski/projects/nodejs/test/error.js:2
    throw new Error();
          ^

Error
    at module.exports (/home/dragiyski/projects/nodejs/test/error.js:2:11)
    at file:///home/dragiyski/projects/nodejs/test/main.mjs:3:1
    at ModuleJob.run (node:internal/modules/esm/module_job:146:23)
    at async Loader.import (node:internal/modules/esm/loader:165:24)
    at async Object.loadESM (node:internal/process/esm_loader:68:5)
New Output:
file:///home/dragiyski/projects/nodejs/test/error.js:2
    throw new Error();
          ^

Error
    at module.exports (file:///home/dragiyski/projects/nodejs/test/error.js:2:11)
    at file:///home/dragiyski/projects/nodejs/test/main.mjs:3:1
    at ModuleJob.run (node:internal/modules/esm/module_job:146:23)
    at async Loader.import (node:internal/modules/esm/loader:165:24)
    at async Object.loadESM (node:internal/process/esm_loader:68:5)

As it can be seen, ESM modules already report local files as URLs. If any module on NPM examine CallSite object to retrieve a filename and use that filename to fs functions, it would break if it was included from ESM module. This will make the output consistent, so any new module would not need to check if CallSite is an URL (ESM, native node modules, etc) or absolute path (CJS), it would always be an URL.

P.S. It might be useful to allow using file: URLs in fs.

@Trott
Copy link
Member

Trott commented Oct 31, 2020

It looks like this needs some changes for tests to pass on Windows.

06:53:28 not ok 512 parallel/test-source-map-enable
06:53:28   ---
06:53:28   duration_ms: 0.664
06:53:28   severity: fail
06:53:28   exitcode: 1
06:53:28   stack: |-
06:53:28     node:assert:108
06:53:28       throw new AssertionError(obj);
06:53:28       ^
06:53:28     
06:53:28     AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
06:53:29     + actual - expected
06:53:29     
06:53:29     + 'file://C:\\workspace\\node-test-binary-windows-js-suites\\node\\test\\fixtures\\source-map'
06:53:29     - 'file:///C:/workspace/node-test-binary-windows-js-suites/node/test/fixtures/source-map'
06:53:29         at Object.<anonymous> (file:///C:/workspace/node-test-binary-windows-js-suites/node/test/parallel/test-source-map-enable.js:90:10)
06:53:29         at Module._compile (node:internal/modules/cjs/loader:1087:30)
06:53:29         at Object.Module._extensions..js (node:internal/modules/cjs/loader:1116:10)
06:53:29         at Module.load (node:internal/modules/cjs/loader:948:32)
06:53:29         at Function.Module._load (node:internal/modules/cjs/loader:789:14)
06:53:29         at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:72:12)
06:53:29         at node:internal/main/run_main_module:17:47 {
06:53:29       generatedMessage: true,
06:53:29       code: 'ERR_ASSERTION',
06:53:29       actual: 'file://C:\\workspace\\node-test-binary-windows-js-suites\\node\\test\\fixtures\\source-map',
06:53:29       expected: 'file:///C:/workspace/node-test-binary-windows-js-suites/node/test/fixtures/source-map',
06:53:29       operator: 'strictEqual'
06:53:29     }
06:53:29   ...

Not entirely sure why those are showing up in Jenkins but not in GitHub Actions CI, but I think it's because we have to skip a bunch of fs tests on GitHub Actions CI on Windows because of something about the underlying file system that is escaping my memory right now.

@richardlau
Copy link
Member

Not entirely sure why those are showing up in Jenkins but not in GitHub Actions CI, but I think it's because we have to skip a bunch of fs tests on GitHub Actions CI on Windows because of something about the underlying file system that is escaping my memory right now.

We don’t currently run any tests on Windows in GitHub actions. We used to in the workflow for testing building from the source tarball until #34440.

@Dragiyski Dragiyski force-pushed the fix-inspector-filename branch from 3124565 to 8b5bf16 Compare November 1, 2020 03:12
@bcoe
Copy link
Contributor

bcoe commented Nov 1, 2020

I'm excited to have another person looking at stack traces 😄

A couple initial questions (I'll give a more thorough review in the next couple days).

  1. I see you're updating the stack traces when source maps are enabled too (thanks for catching this). Does the inspector handle the linking appropriately for the original call sites added by --enable-source-maps?
  2. I think we should take the time to make sure the paths are handled appropriately in the inspector UI on windows as well.

I will be curious to hear other people's feedback. The addition of the scheme seems a little redundant for the terminal output, but I appreciate that it makes for a better experience in the inspector.

@Dragiyski
Copy link
Author

Dragiyski commented Nov 1, 2020

1. I see you're updating the stack traces when source maps are enabled too (thanks for catching this). Does the inspector handle the linking appropriately for the original call sites added by --enable-source-maps?

Yes, when source maps are enabled, the line plugged in into the stack is clickable and links to the source mapped by the source map. The original line is also shown and it leads to the minified file.

Chrome's devtools client have some kind of link detection algorithm. You can put in the console any link (including http:// or https://) and it will be clickable even when the link is suffixed with colon (:) and a line number. If it matches registered script exactly it will jump to it, otherwise it will open a new tab in the last focused browser window. However this does not properly detects all URLs in general. For node modules node:internal/url.js will have only /url.js clickable. However, when printing a stack trace the entire part node:internal/url.js would be detected properly and it will be clickable. I have no idea why there would be any difference here. Even worse, when not all call sites are detected as URLs, call sites for node: are shown wrong (URL starts after the first slash), but when all call sites (that have filename) are URLs it works... 😕 It seems having slashes (like node://) helps to detect URL in general, but it does not lead to any registered files. I think that's a bug the devtools devs must fix, but they probably won't because, in websites, all call sites that have filename (they are not native C++) are URLs (scripts in HTML page or remote scripts).

Anyway, the idea here is to register all scripts in v8::ScriptCompiler as URL, which is possible since v15.x. Node modules in lib are valid URLs with node: protocol. ESM modules are valid URLs with file:// protocol, even when they are loaded from the local filesystem. The only modules that fail to follow that format are the CJS modules. Because of the ESM modules all facilities to handle path to file URL conversion (or vice versa) are already present and used.

2. I think we should take the time to make sure the paths are handled appropriately in the inspector UI on windows as well.

I tried to address that in sourcesToAbsolute, but there is no safe portable way to manually build a file:// URL using string concatenation and I do not see why we need to do that. The final goal is an URL and url module already provides suicient utilities for handling that logic even for more complex cases (detecting if URL is already absolute for any protocol). Originally I tried to apply minimal changes to address sources appended to the call stack, but as it is mentioned in #35903, the source could by absolute pseudo-URL from an external library (i.e. webpack://).

@Dragiyski Dragiyski force-pushed the fix-inspector-filename branch from ab38a76 to 9df7683 Compare November 1, 2020 16:30
Copy link
Contributor

@bcoe bcoe left a comment

Choose a reason for hiding this comment

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

It seems having slashes (like node://) helps to detect URL in general, but it does not lead to any registered files. I think that's a bug the devtools devs must fix, but they probably won't because, in websites, all call sites that have filename (they are not native C++) are URLs (scripts in HTML page or remote scripts).

It might be worth talking to some folks who work on inspector, see if they have any thoughts. Where would we want node: to link to? the node.js docs?, the source code on GitHub?

tried to address that in sourcesToAbsolute, but there is no safe portable way to manually build a file:// URL using string concatenation and I do not see why we need to do that.

I'm less concerned about the unit tests passing (I'm sure you'll end up finding the edge cases causing problems).

What I'd like to make sure, is that the inspector UI works as we'd hope on a few testing platforms:

  • you've already tested that adding schemes makes the user experience better on OSX/Linux ✅ .
  • It would be good to have someone run an inspector session on Windows and confirm the same UX improvement.
  • I'd be curious to see how VS Code handles this new style of errors, does it link the error paths too?

const line = call.getLineNumber() - 1;
let column = call.getColumnNumber() - 1;
let identifier;
let code;

if (filename && StringPrototypeStartsWith(filename, 'file:')) {
try {
filename = fileURLToPath(filename);
Copy link
Contributor

Choose a reason for hiding this comment

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

With the check for file:, under what conditions do we expect this to fail?

If we leave this try/catch, we might want to put a debug in the catch.

Copy link
Author

Choose a reason for hiding this comment

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

fileURLToPath and normalizeReferrerURL call URL constructor with a single argument. There was a string (I do not remember exactly, but I can try to remove the try/catch and rebuild to find it) like [eval something] that makes URL throws an ERR_INVALID_URL error. Since that is in the unit tests, it might be used in the future. Moreover, users of vm can pass any string for filename or have source map containing any string. The combination of both is possible to make otherwise invalid URL to appear as valid module and in general invalid URLs supplied by the user should not crush for the proper reason: MODULE_NOT_FOUND for example.

Copy link
Contributor

Choose a reason for hiding this comment

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

Might be worth getting a unit test around the edge case if possible 👌

@@ -995,10 +995,14 @@ function wrapSafe(filename, content, cjsModuleInstance) {
});
}
let compiled;
let filenameUrl = filename;
try {
filenameUrl = normalizeReferrerURL(filename);
Copy link
Contributor

Choose a reason for hiding this comment

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

likewise, if we can instead test for filename patterns that would make normalizeReferrerURL throw, it might be better than a catch all try/catch.

// If source is any form of full URL (for any protocol)
// it will remain full URL. If it is relative, it will
// become file:// url, because the baseUrl is file URL.
source = (new URL(source, baseUrl)).href;
Copy link
Contributor

Choose a reason for hiding this comment

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

I just ended up undertaking close to this same refactor in #35903

Copy link
Author

Choose a reason for hiding this comment

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

Yes, that function is affected in both issues. I traced its usage to ensure the first parameter is always a directory path and then converted it to URL. It seems your solution is to first convert it to URL and then call sourcesToAbsolute. Please, make sure it ends with slash /. WHATWG rules for URL will threat the last part as as file otherwise and return one directory upwards. Otherwise both solutions are identical in their core: new URL(source, baseURL).href.

P.S. I am not familiar with the nodejs source, so I try to minimize the amount of dependent changes.

@Dragiyski
Copy link
Author

What I'd like to make sure, is that the inspector UI works as we'd hope on a few testing platforms:

  • It would be good to have someone run an inspector session on Windows and confirm the same UX improvement.

I tested the behavior of devtools on both Windows 10 (Pro June 2020 with Chrome 86.0.4240.111, on VirtualBox) and Ubuntu 20.04, it shows identical behavior:

  • with --enable-source-maps: Screenshot
    • all file:// URLs are shown in full and clickable. Clicking open the containing file and it works for both the original and the mapped source. The file is scrolled to the specified line and the cursor is set to the column specified in the URL.
    • The node: URLs for native node modules are URLs after the first slash. Clicking on them does not lead to a source file, but opens about:blank in the nearest browser.
  • without --enable-source-maps: Screenshot
    • All file:// URLs are now reduced to the a base name and still clickable. Even if source maps are not processed by the node, devtools process them and include the original source. In this case there is no link to the mapped source, only to the original specified in the source map. Links scroll to the proper line and put the cursor on the proper column.
    • All node: are fully shown and this time all the URL is clickable and lead to proper source file, line and column. Internal node modules are listed as (no domain) as expected and links open the specified file.

With both Webstorm (2020.2.3 on Ubuntu 20.04) (Screenshot) and VS Code (configuration above) (Screenshot) the file:// entire URL is visible and:

  • with --enable-source-maps
    • All file:// URLs are clickable and open the referenced source file, line and column for both the original and mapped file.
    • Other URLs (including node:) are not clickable at all.
  • without --enable-source-maps: same as above, but now since the lines for the original files are missing, there is only link to the mapped file. It does not seems those programs process source maps by themselves by default.

If someone have the tools and the platform, the following is still not tested:

  • Mac OS
  • v8::Function from a v8::FunctionTemplate on the stack trace.
  • Negative scenarios:
    • Source maps with invalid URLs, URLs to non-existing original, Invalid source map data, etc.
    • Function compiled by vm with invalid URLs for a filename.

@Dragiyski Dragiyski force-pushed the fix-inspector-filename branch 2 times, most recently from 2a0b2db to 8f67a90 Compare November 3, 2020 18:35
@joyeecheung
Copy link
Member

@bcoe bcoe added notable-change PRs with changes that should be highlighted in changelogs. semver-major PRs that contain breaking changes and should be released in the next major version. labels Nov 4, 2020
@bcoe
Copy link
Contributor

bcoe commented Nov 4, 2020

I think we should probably call this a SemVer major, as upstream libraries tend to assert against error strings (which will change to having a file:// prefix).

Copy link
Contributor

@bcoe bcoe left a comment

Choose a reason for hiding this comment

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

Thanks for the screen shots, I think this will be a definitely usability improvement for folks using inspectors.


Not for this PR, but two questions I'd like to eventually answer:

  1. how can we better handle node:// URIs.
  2. how should we handle special paths like [eval something].

const line = call.getLineNumber() - 1;
let column = call.getColumnNumber() - 1;
let identifier;
let code;

if (filename && StringPrototypeStartsWith(filename, 'file:')) {
try {
filename = fileURLToPath(filename);
Copy link
Contributor

Choose a reason for hiding this comment

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

Might be worth getting a unit test around the edge case if possible 👌

@nodejs-github-bot
Copy link
Collaborator

@bcoe
Copy link
Contributor

bcoe commented Nov 4, 2020

@nodejs/modules @nodejs/tooling friendly nudge, it would be good to get a few more sets of eyes on this. It will alter stack trace output in a significant way.

Copy link
Member

@benjamingr benjamingr left a comment

Choose a reason for hiding this comment

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

Changes look good. I think this should probably land even with the benchmark regression though I believe it's probably a good idea to test this with a real module (like require('webpack')) for example and measure the regression there.

@Dragiyski Dragiyski force-pushed the fix-inspector-filename branch from 4139ef1 to d30dbbf Compare November 8, 2020 01:16
@Dragiyski
Copy link
Author

Dragiyski commented Nov 8, 2020

but could we move the resolution logic to the prepareStackTrace step

Yes, this could solve the regression, but I am reluctant to do that, since v8::ScriptOrigin would remain a path, not an URL, which in case of custom Error.prepareStackTrace would still result in inconsistent result between ESM and CJS modules (file URL vs path). If no other solution is found, this would do.

In the latest commit I attempted another approach. I stopped using pathToFileURL due to huge number of checks and errors thrown for certain path in windows, as neither of those checks would be reachable when called from wrapSafe. The path here already passed validation and most likely it is a valid path to existing file. Here is my local benchmark result compared to upstream/master (f06f3c0):

                                                                                   confidence improvement accuracy (*)   (**)  (***)
 module/module-loader-circular.js n=10000                                                 ***     -6.99 %       ±1.06% ±1.41% ±1.84%
 module/module-loader-deep.js cache='false' files=1000 ext='.js'                          ***     -6.85 %       ±1.64% ±2.18% ±2.83%
 module/module-loader-deep.js cache='false' files=1000 ext=''                             ***     -5.96 %       ±1.87% ±2.49% ±3.24%
 module/module-loader-deep.js cache='true' files=1000 ext='.js'                                    0.66 %       ±3.78% ±5.04% ±6.56%
 module/module-loader-deep.js cache='true' files=1000 ext=''                                      -2.90 %       ±5.17% ±6.87% ±8.95%
 module/module-loader.js cache='false' n=1 files=500 dir='abs' name=''                    ***     -6.32 %       ±2.22% ±2.96% ±3.85%
 module/module-loader.js cache='false' n=1 files=500 dir='abs' name='/'                   ***     -6.25 %       ±2.48% ±3.30% ±4.30%
 module/module-loader.js cache='false' n=1 files=500 dir='abs' name='/index.js'            **     -3.61 %       ±2.40% ±3.21% ±4.19%
 module/module-loader.js cache='false' n=1 files=500 dir='rel' name=''                    ***     -5.93 %       ±1.90% ±2.53% ±3.29%
 module/module-loader.js cache='false' n=1 files=500 dir='rel' name='/'                   ***     -5.50 %       ±2.38% ±3.16% ±4.12%
 module/module-loader.js cache='false' n=1 files=500 dir='rel' name='/index.js'           ***     -6.82 %       ±2.40% ±3.20% ±4.17%
 module/module-loader.js cache='false' n=1000 files=500 dir='abs' name=''                          0.20 %       ±2.08% ±2.76% ±3.59%
 module/module-loader.js cache='false' n=1000 files=500 dir='abs' name='/'                        -1.41 %       ±2.47% ±3.29% ±4.29%
 module/module-loader.js cache='false' n=1000 files=500 dir='abs' name='/index.js'                -0.91 %       ±3.38% ±4.50% ±5.87%
 module/module-loader.js cache='false' n=1000 files=500 dir='rel' name=''                         -0.87 %       ±2.51% ±3.34% ±4.34%
 module/module-loader.js cache='false' n=1000 files=500 dir='rel' name='/'                         0.25 %       ±2.94% ±3.92% ±5.10%
 module/module-loader.js cache='false' n=1000 files=500 dir='rel' name='/index.js'                 0.86 %       ±3.04% ±4.04% ±5.27%
 module/module-loader.js cache='true' n=1 files=500 dir='abs' name=''                             -2.48 %       ±2.89% ±3.84% ±5.00%
 module/module-loader.js cache='true' n=1 files=500 dir='abs' name='/'                             2.15 %       ±3.21% ±4.27% ±5.57%
 module/module-loader.js cache='true' n=1 files=500 dir='abs' name='/index.js'                    -1.27 %       ±3.51% ±4.68% ±6.11%
 module/module-loader.js cache='true' n=1 files=500 dir='rel' name=''                             -1.33 %       ±2.54% ±3.38% ±4.40%
 module/module-loader.js cache='true' n=1 files=500 dir='rel' name='/'                             1.12 %       ±2.21% ±2.95% ±3.85%
 module/module-loader.js cache='true' n=1 files=500 dir='rel' name='/index.js'                     2.48 %       ±4.07% ±5.43% ±7.09%
 module/module-loader.js cache='true' n=1000 files=500 dir='abs' name=''                   **     -3.22 %       ±2.21% ±2.94% ±3.83%
 module/module-loader.js cache='true' n=1000 files=500 dir='abs' name='/'                         -0.21 %       ±2.21% ±2.95% ±3.84%
 module/module-loader.js cache='true' n=1000 files=500 dir='abs' name='/index.js'                 -0.94 %       ±1.68% ±2.24% ±2.91%
 module/module-loader.js cache='true' n=1000 files=500 dir='rel' name=''                          -0.41 %       ±1.69% ±2.25% ±2.93%
 module/module-loader.js cache='true' n=1000 files=500 dir='rel' name='/'                         -0.42 %       ±1.48% ±1.97% ±2.57%
 module/module-loader.js cache='true' n=1000 files=500 dir='rel' name='/index.js'                  0.87 %       ±2.38% ±3.17% ±4.13%

Be aware that when doing many comparisons the risk of a false-positive
result increases. In this case there are 29 comparisons, you can thus
expect the following amount of false-positive results:
  1.45 false positives, when considering a   5% risk acceptance (*, **, ***),
  0.29 false positives, when considering a   1% risk acceptance (**, ***),
  0.03 false positives, when considering a 0.1% risk acceptance (***)

There is still significant regression, but not as severe as before. Here is the comparison to upstream/master before the optimization with the same settings on the same machine:

                                                                                   confidence improvement accuracy (*)   (**)   (***)
 module/module-loader-circular.js n=10000                                                 ***    -13.80 %       ±0.96% ±1.28%  ±1.67%
 module/module-loader-deep.js cache='false' files=1000 ext='.js'                          ***     -9.94 %       ±1.74% ±2.32%  ±3.01%
 module/module-loader-deep.js cache='false' files=1000 ext=''                             ***     -9.36 %       ±1.83% ±2.43%  ±3.17%
 module/module-loader-deep.js cache='true' files=1000 ext='.js'                                   -5.13 %       ±5.92% ±7.88% ±10.29%
 module/module-loader-deep.js cache='true' files=1000 ext=''                                      -1.26 %       ±5.62% ±7.48%  ±9.75%
 module/module-loader.js cache='false' n=1 files=500 dir='abs' name=''                    ***     -7.98 %       ±1.49% ±1.98%  ±2.58%
 module/module-loader.js cache='false' n=1 files=500 dir='abs' name='/'                   ***    -10.36 %       ±2.00% ±2.66%  ±3.47%
 module/module-loader.js cache='false' n=1 files=500 dir='abs' name='/index.js'           ***     -7.77 %       ±2.34% ±3.11%  ±4.05%
 module/module-loader.js cache='false' n=1 files=500 dir='rel' name=''                    ***     -8.97 %       ±1.91% ±2.54%  ±3.31%
 module/module-loader.js cache='false' n=1 files=500 dir='rel' name='/'                   ***     -8.40 %       ±2.35% ±3.13%  ±4.07%
 module/module-loader.js cache='false' n=1 files=500 dir='rel' name='/index.js'           ***     -8.25 %       ±1.81% ±2.41%  ±3.14%
 module/module-loader.js cache='false' n=1000 files=500 dir='abs' name=''                 ***     -3.84 %       ±2.19% ±2.91%  ±3.79%
 module/module-loader.js cache='false' n=1000 files=500 dir='abs' name='/'                  *     -2.50 %       ±2.28% ±3.03%  ±3.95%
 module/module-loader.js cache='false' n=1000 files=500 dir='abs' name='/index.js'        ***     -4.77 %       ±2.36% ±3.15%  ±4.10%
 module/module-loader.js cache='false' n=1000 files=500 dir='rel' name=''                   *     -2.26 %       ±2.26% ±3.00%  ±3.91%
 module/module-loader.js cache='false' n=1000 files=500 dir='rel' name='/'                        -1.81 %       ±2.29% ±3.04%  ±3.97%
 module/module-loader.js cache='false' n=1000 files=500 dir='rel' name='/index.js'          *     -2.93 %       ±2.84% ±3.78%  ±4.92%
 module/module-loader.js cache='true' n=1 files=500 dir='abs' name=''                             -1.27 %       ±3.16% ±4.21%  ±5.49%
 module/module-loader.js cache='true' n=1 files=500 dir='abs' name='/'                            -2.34 %       ±2.97% ±3.95%  ±5.15%
 module/module-loader.js cache='true' n=1 files=500 dir='abs' name='/index.js'                    -2.43 %       ±2.92% ±3.90%  ±5.09%
 module/module-loader.js cache='true' n=1 files=500 dir='rel' name=''                      **     -3.81 %       ±2.46% ±3.28%  ±4.28%
 module/module-loader.js cache='true' n=1 files=500 dir='rel' name='/'                             0.66 %       ±2.77% ±3.68%  ±4.79%
 module/module-loader.js cache='true' n=1 files=500 dir='rel' name='/index.js'                    -2.57 %       ±3.27% ±4.35%  ±5.66%
 module/module-loader.js cache='true' n=1000 files=500 dir='abs' name=''                   **     -4.86 %       ±3.28% ±4.38%  ±5.71%
 module/module-loader.js cache='true' n=1000 files=500 dir='abs' name='/'                 ***     -2.29 %       ±1.30% ±1.73%  ±2.26%
 module/module-loader.js cache='true' n=1000 files=500 dir='abs' name='/index.js'                 -1.92 %       ±2.39% ±3.18%  ±4.14%
 module/module-loader.js cache='true' n=1000 files=500 dir='rel' name=''                   **     -2.72 %       ±1.76% ±2.35%  ±3.06%
 module/module-loader.js cache='true' n=1000 files=500 dir='rel' name='/'                         -1.73 %       ±1.82% ±2.42%  ±3.16%
 module/module-loader.js cache='true' n=1000 files=500 dir='rel' name='/index.js'                 -1.39 %       ±1.51% ±2.01%  ±2.63%

Be aware that when doing many comparisons the risk of a false-positive
result increases. In this case there are 29 comparisons, you can thus
expect the following amount of false-positive results:
  1.45 false positives, when considering a   5% risk acceptance (*, **, ***),
  0.29 false positives, when considering a   1% risk acceptance (**, ***),
  0.03 false positives, when considering a 0.1% risk acceptance (***)

@Trott
Copy link
Member

Trott commented Nov 8, 2020

@Dragiyski Is this ready for review/landing in your view, or is there still some work you're hoping to do on it first?

@Trott Trott added the request-ci Add this label to start a Jenkins CI on a PR. label Nov 8, 2020
@github-actions github-actions bot removed the request-ci Add this label to start a Jenkins CI on a PR. label Nov 8, 2020
@nodejs-github-bot
Copy link
Collaborator

@Dragiyski
Copy link
Author

@Dragiyski Is this ready for review/landing in your view, or is there still some work you're hoping to do on it first?

Yes, I think it is ready for review.

@bcoe
Copy link
Contributor

bcoe commented Nov 10, 2020

I agree with @benjamingr's recommendation, let's benchmark a couple real world modules that are quite large, pulling in the index of googleapis would be a great candidate (its dependency graph is huge, and probably represents a good worst case).

Ultimately, I'll trust to @joyeecheung and @benjamingr, as to whether the regression is acceptable.

Otherwise, I'm happy with this functionality and am excited that it makes behavior more consistent between ESM and CJS 👍

@Trott
Copy link
Member

Trott commented Nov 13, 2020

@nodejs/tsc (Semver major so needs at least 2 TSC approvals.)

@joyeecheung
Copy link
Member

I am still not sure whether making inspector stack traces nicer (a mostly dev-only feature) is worth the cost of the performance regression and potential breakage in the ecosystem. I think we should at least investigate how this would impact real-world packages.

@bcoe
Copy link
Contributor

bcoe commented Dec 1, 2020

Yes, this could solve the regression, but I am reluctant to do that, since v8::ScriptOrigin would remain a path, not an URL, which in case of custom Error.prepareStackTrace would still result in inconsistent result between ESM and CJS modules (file URL vs path). If no other solution is found, this would do.

@joyeecheung @Dragiyski why don't we start with improvement in Error.prepareStackTrace, since it's less controversial?

@joyeecheung
Copy link
Member

@bcoe Starting with the Error.prepareStackTrace sounds good, since we are likely to be dealing with errors in those cases

@aduh95
Copy link
Contributor

aduh95 commented Jan 18, 2021

@Dragiyski can you please rebase on top of master to solve the git conflict?

When the chrome inspector (chrome://inspect) display stack traces, it
makes the filename clickable, and developer can easily locate the
relevant source with a single click. This only works when filenames are
valid URLs. The CJS loader seems to compile sources with absolute path
instead of URL, breaking the inspector functionality. This is especially
apparent when node_modules contain "at" symbol (@). The loader already
presents module to the inspector using file URL, the same URL should be
used for compiling the source.
It seems getErrMessage() function uses filename from a CallSite to
open a file and extract source code location of the statement. The
CallSite now returns file URL, so it must be converted back to path.
Various tests explore the stack trace or CallSite objects' filename.
They are modified now to match file URL instead.
Windows path (using backslash) won't be found in stack trace anymore.
Use appropriate url.fileURLToPath and url.pathToFileURL when examine
the stack trace.
It seems `wrapSafe` filename is always absolute path. Certain aspects
for validating paths in `pathToFileURL` can be skipped in favor of
better performance of CJS synchrnous loading while keeping the origin.
@Dragiyski Dragiyski force-pushed the fix-inspector-filename branch from f519f30 to ca1ebbd Compare January 19, 2021 14:37
@bcoe bcoe self-requested a review January 22, 2021 01:51
@bcoe
Copy link
Contributor

bcoe commented Jan 22, 2021

@Dragiyski please let me know when you have something that you'd like folks to take another look at.

1 similar comment
@bcoe
Copy link
Contributor

bcoe commented Jan 22, 2021

@Dragiyski please let me know when you have something that you'd like folks to take another look at.

@aduh95
Copy link
Contributor

aduh95 commented Mar 19, 2021

This needs a rebase.

@aduh95
Copy link
Contributor

aduh95 commented Sep 15, 2021

@Dragiyski would be able to rebase on top of master to solve the git conflict please?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
notable-change PRs with changes that should be highlighted in changelogs. semver-major PRs that contain breaking changes and should be released in the next major version.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

10 participants