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

module: fix error reporting #55561

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

Conversation

geeksilva97
Copy link
Contributor

@geeksilva97 geeksilva97 commented Oct 27, 2024

Refs: #55350
Fixes: #55350

The error is incorrectly reported because the traceSync call is on the stack frame. The code that computes the message was getting the first frame expecting it to have the information needed. Something like

at Object.<anonymous> (/Users/edysilva/test-node/issue-55350/test.cjs:1:1)

With traceSync it's like

 at TracingChannel.traceSync (node:diagnostics_channel:322:14)
 at Object.<anonymous> (/Users/edysilva/test-node/issue-55350/test.cjs:1:1)

This PR fixes this behavior by skipping cutting frames about the user's frame.

@nodejs-github-bot
Copy link
Collaborator

Review requested:

  • @nodejs/loaders

@nodejs-github-bot nodejs-github-bot added module Issues and PRs related to the module subsystem. needs-ci PRs that need a full CI run. labels Oct 27, 2024
@geeksilva97 geeksilva97 force-pushed the 55350-issue branch 2 times, most recently from 35c501d to 07e16a1 Compare October 27, 2024 04:00
@geeksilva97 geeksilva97 changed the title loader: fix error reporting (wip) module: fix error reporting (wip) Oct 27, 2024
@geeksilva97 geeksilva97 marked this pull request as ready for review October 27, 2024 05:45
Copy link

codecov bot commented Oct 27, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 87.99%. Comparing base (4ee87b8) to head (7a97799).
Report is 2 commits behind head on main.

Additional details and impacted files
@@            Coverage Diff             @@
##             main   #55561      +/-   ##
==========================================
- Coverage   88.00%   87.99%   -0.01%     
==========================================
  Files         656      656              
  Lines      189000   189002       +2     
  Branches    35995    35991       -4     
==========================================
- Hits       166320   166313       -7     
- Misses      15840    15847       +7     
- Partials     6840     6842       +2     
Files with missing lines Coverage Δ
lib/internal/modules/cjs/loader.js 94.31% <100.00%> (+<0.01%) ⬆️

... and 23 files with indirect coverage changes

Copy link
Member

@mcollina mcollina 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 opening a PR! Can you please add a unit test?

@geeksilva97 geeksilva97 changed the title module: fix error reporting (wip) module: fix error reporting Oct 27, 2024
@geeksilva97
Copy link
Contributor Author

Thanks for opening a PR! Can you please add a unit test?

Sure! It's done 🫡

@geeksilva97 geeksilva97 force-pushed the 55350-issue branch 2 times, most recently from ded0ecb to 7dc8b15 Compare October 27, 2024 14:55
@RafaelGSS RafaelGSS added the request-ci Add this label to start a Jenkins CI on a PR. label Oct 31, 2024
@RafaelGSS
Copy link
Member

The PR changes this behavior by making the error reporting to get the last frame on the stack since it will be where all calls were triggered from.

I think this isn't what the error reporting should do? Let me investigate

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

Copy link
Member

@RafaelGSS RafaelGSS left a comment

Choose a reason for hiding this comment

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

See:

function main() {
  func1(func2(func3()))
}

function func1() {
  require('./app.js')
}
function func2() {}
function func3() {}

main()

Correct output:

➜  undefined git:(55350-issue) ✗ node -v
v22.3.0
➜  undefined git:(55350-issue) ✗ node test.cjs
/Users/rafaelgss/repos/os/node2/undefined/test.cjs:6
  require('./app.js')
  ^

Error [ERR_REQUIRE_ESM]: require() of ES Module /Users/rafaelgss/repos/os/node2/undefined/app.js from /Users/rafaelgss/repos/os/node2/undefined/test.cjs not supported.
Instead change the require of app.js in /Users/rafaelgss/repos/os/node2/undefined/test.cjs to a dynamic import() which is available in all CommonJS modules.
    at func1 (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:6:3)
    at main (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:2:3)
    at Object.<anonymous> (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:11:1) {
  code: 'ERR_REQUIRE_ESM'
}

Node.js v22.3.0

After #44340:

➜  undefined git:(55350-issue) ✗ node test.cjs
/Users/rafaelgss/repos/os/node2/undefined/test.cjs:315
undefined
             ^

Error [ERR_REQUIRE_ESM]: require() of ES Module /Users/rafaelgss/repos/os/node2/undefined/app.js from /Users/rafaelgss/repos/os/node2/undefined/test.cjs not supported.
Instead change the require of app.js in /Users/rafaelgss/repos/os/node2/undefined/test.cjs to a dynamic import() which is available in all CommonJS modules.
    at TracingChannel.traceSync (node:diagnostics_channel:315:14)
    at func1 (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:6:3)
    at main (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:2:3)
    at Object.<anonymous> (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:11:1) {
  code: 'ERR_REQUIRE_ESM'
}

Node.js v22.4.0

Your PR:

➜  undefined git:(55350-issue) ✗ ../node --no-experimental-require-module test.cjs
/Users/rafaelgss/repos/os/node2/undefined/test.cjs:11
main()
^

Error [ERR_REQUIRE_ESM]: require() of ES Module /Users/rafaelgss/repos/os/node2/undefined/app.js from /Users/rafaelgss/repos/os/node2/undefined/test.cjs not supported.
Instead change the require of app.js in /Users/rafaelgss/repos/os/node2/undefined/test.cjs to a dynamic import() which is available in all CommonJS modules.
    at TracingChannel.traceSync (node:diagnostics_channel:322:14)
    at func1 (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:6:3)
    at main (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:2:3)
    at Object.<anonymous> (/Users/rafaelgss/repos/os/node2/undefined/test.cjs:11:1) {
  code: 'ERR_REQUIRE_ESM'
}

Node.js v24.0.0-pre

I apologize; I haven’t had the bandwidth to look into how the fix should be structured yet. However, this change appears to be inaccurate

@geeksilva97
Copy link
Contributor Author

The PR changes this behavior by making the error reporting to get the last frame on the stack since it will be where all calls were triggered from.

I think this isn't what the error reporting should do? Let me investigate

Wrong assumption from my side. Thanks for pointing that out. I just pushed a fix.

It takes the first frame after TraseSync. I will also get this case you brought into a test.

@RafaelGSS
Copy link
Member

Wrong assumption from my side. Thanks for pointing that out. I just pushed a fix.

It takes the first frame after TraseSync. I will also get this case you brought into a test.

Can you try to use hideStackFrames instead? So we don't need to change the error stack trace creation. Example: https://github.com/nodejs/node/blob/main/lib/_http_outgoing.js#L667

@geeksilva97
Copy link
Contributor Author

geeksilva97 commented Nov 1, 2024

Wrong assumption from my side. Thanks for pointing that out. I just pushed a fix.
It takes the first frame after TraseSync. I will also get this case you brought into a test.

Can you try to use hideStackFrames instead? So we don't need to change the error stack trace creation. Example: https://github.com/nodejs/node/blob/main/lib/_http_outgoing.js#L667

Would you guide me how I can do that? I tried to add it in a few places:

  • wrapping traseSync
  • wrapping `Module._extensions['.js']
  • wrapping Module._load

None worked. It ended up messing with the stack.

at TracingChannel.traceSync (node:diagnostics_channel:322:14)
    at wrapModuleLoad (node:internal/modules/cjs/loader:220:24)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:170:5)
    at node:internal/main/run_main_module:36:49 {

It adds this wrapModuleLoad and some more frames.

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

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

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

@geeksilva97 geeksilva97 force-pushed the 55350-issue branch 3 times, most recently from ce81fff to e0ccecc Compare November 28, 2024 18:17
@aduh95
Copy link
Contributor

aduh95 commented Nov 29, 2024

@RafaelGSS are you still blocking?

@geeksilva97
Copy link
Contributor Author

@RafaelGSS are you still blocking?

he wanted to check if all tests would pass before. Tests were failing on windows though. A friend of mine helped me out and I realized it was due to backslashes.

I made some changes - and added some debugging stuff - hopefully, the next CI will pass. If not, at least, it will be clear what is missing. I will then remove this commit

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

@geeksilva97 geeksilva97 force-pushed the 55350-issue branch 2 times, most recently from 7eda507 to 96f5831 Compare November 30, 2024 04:50
@@ -1674,6 +1675,7 @@ function getRequireESMError(mod, pkg, content, filename) {
const usesEsm = containsModuleSyntax(content, filename);
const err = new ERR_REQUIRE_ESM(filename, usesEsm, parentPath,
packageJsonPath);
ErrorCaptureStackTrace(err, Module.prototype.require);
Copy link
Contributor Author

@geeksilva97 geeksilva97 Nov 30, 2024

Choose a reason for hiding this comment

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

The whole stack - including internals for reference - is something like

at getRequireESMError (node:internal/modules/cjs/loader:1683:15)
    at Object..js (node:internal/modules/cjs/loader:1724:17)
    at Module.load (node:internal/modules/cjs/loader:1310:32)
    at Function._load (node:internal/modules/cjs/loader:1124:12)
    at TracingChannel.traceSync (node:diagnostics_channel:322:14)
    at wrapModuleLoad (node:internal/modules/cjs/loader:229:12)
    at Module.require (node:internal/modules/cjs/loader:1333:12)
    at require (node:internal/modules/helpers:136:16)
    at Object.<anonymous> (/Users/edysilva/projects/contributions/node/test/fixtures/es-modules/package-type-module/require-esm-error-annotation/index.cjs:1:13) {
  code: 'ERR_REQUIRE_ESM'

We would then need to strip from require and above.

Copy link
Contributor Author

@geeksilva97 geeksilva97 Nov 30, 2024

Choose a reason for hiding this comment

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

Using the hideStackFrames would work too - wrapping the Module.prototype.require function.

I don't know the possible impacts of doing that though. That's why I used ErrorCaptureStackTrace.

Let me know if hideStackFrames can be used instead.

cc @RafaelGSS

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
module Issues and PRs related to the module subsystem. needs-ci PRs that need a full CI run.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Wrong error annotation when commonjs requires an ES module
6 participants