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

No correct stack trace when reject value isn't an instanceof Error #41676

Closed
ItamarGronich opened this issue Jan 24, 2022 · 11 comments
Closed

No correct stack trace when reject value isn't an instanceof Error #41676

ItamarGronich opened this issue Jan 24, 2022 · 11 comments
Labels
feature request Issues that request new features to be added to Node.js. promises Issues and PRs related to ECMAScript promises.

Comments

@ItamarGronich
Copy link

ItamarGronich commented Jan 24, 2022

Version

15.x.x, 16.x.x, 17.x.x

Platform

Darwin ItamarGro-2.local 20.6.0 Darwin Kernel Version 20.6.0: Mon Aug 30 06:12:21 PDT 2021; root:xnu-7195.141.6~3/RELEASE_X86_64 x86_64

Subsystem

No response

What steps will reproduce the bug?

Node doesn't seem to add relevant stack trace information to where the error occurred in the case of unhandled rejection with a value that is not instance of Error.

This is a case that reproduces this undesired behavior:
run this with node index.js:

// index.js
function notOk() {
  return Promise.reject("Uh-oh!");
}

notOk();

The output of this script is:

node:internal/process/promises:246
          triggerUncaughtException(err, true /* fromPromise */);
          ^

[UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "Uh-oh!".] {
  code: 'ERR_UNHANDLED_REJECTION'
}

This is problematic because in the output above there's simply no information to help me understand where the error occurred.
In such a small script it is obvious where the problem is but in a larger codebase it's basically impossible to find.
I found it only by debugging and running through the functions.

In contrast, rejecting with a value that is an instance of Error will throw a stack trace correctly:

// index.js
function ok() {
  return Promise.reject(new Error("OK!"));
}

ok();

This script will output:

/Users/itamar/projects/test/index.js:2
  return Promise.reject(new Error("OK!"));
                        ^

Error: OK!
    at ok (/Users/itamar/projects/test/index.js:2:25)
    at Object.<anonymous> (/Users/itamar/projects/test/index.js:5:1)
    at Module._compile (node:internal/modules/cjs/loader:1101:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10)
    at Module.load (node:internal/modules/cjs/loader:981:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)
    at node:internal/main/run_main_module:17:47

In this case i know where the problem is and i can fix it.

How often does it reproduce? Is there a required condition?

It reproduces in node 15, 16 and 17 (with default value for flag --unhandled-rejections=throw and not --unhandled-rejections=warn-with-error-code or some other option) on every unhandled rejection with a value that is not instance of error.

What is the expected behavior?

It would be nice to at least get a stack trace to the place in my code where the reject happened.
something like this:

/Users/itamar/projects/test/index.js:2
  return Promise.reject("Uh-oh!");
                        ^

UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "Uh-oh!"
    at ok (/Users/itamar/projects/test/index.js:2:25)
    at Object.<anonymous> (/Users/itamar/projects/test/index.js:5:1)
    at Module._compile (node:internal/modules/cjs/loader:1101:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10)
    at Module.load (node:internal/modules/cjs/loader:981:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)
    at node:internal/main/run_main_module:17:47

What do you see instead?

I see a non descriptive error message that doesn't explain clearly where the problem is:

node:internal/process/promises:246
          triggerUncaughtException(err, true /* fromPromise */);
          ^

[UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "Uh-oh!".] {
  code: 'ERR_UNHANDLED_REJECTION'
}

Additional information

Basically the mechanism for throwing on uncaught rejections is nice but i think it's missing handling those edge cases where reject value isn't a native error.

@ItamarGronich
Copy link
Author

ItamarGronich commented Jan 24, 2022

I discovered while upgrading from node@10.9.0 to node@16.13.2 and running jest tests jest@24.9.0
jestjs/jest#10784
This happens on jest because jest basically provides it's own global object for each test process as far as i learned, and thereforejestGlobal.Error !== actualGlobal.Error that's why node will not recognise the error and throw a proper stack trace.
More details in the thread and in this comment specifically: jestjs/jest#10784 (comment)

@benjamingr
Copy link
Member

benjamingr commented Jan 24, 2022

Stacks are generated when an error object is created.

When a non-error is thrown (or rejected) no stack trace is generated. This isn't specific to Node it's inherent to the design of errors in JavaScript.

I think you've just run into why "Always throw Error objects or at least objects with Error.captureStackTrace called on them" is such an important error handling best practice.

(As a side note - you will get a stack trace if the debugger is connected when inspecting the error in the debugger but that's not a valid workaround in general - for example for seeing errors in your jest tests in CI)

@benjamingr
Copy link
Member

Also thanks for the detailed feature request and thorough explanation of where you ran into this!

@benjamingr benjamingr added feature request Issues that request new features to be added to Node.js. promises Issues and PRs related to ECMAScript promises. labels Jan 24, 2022
@benjamingr
Copy link
Member

benjamingr commented Jan 24, 2022

We should fix cross-realm errors (but not primitives) and change the instanceof check.

Edit: PR to fix the jest issue #41682

@ItamarGronich
Copy link
Author

@benjamingr Thanks for the quick reply & PR! really impressive.

However, while I agree on most of what you said, I must disagree on the primitives thing.

Browsers do handle that case:
okNotOk

The only difference is as you said, errors contain stack traces on the object itself so the toString() method on the error object concatenates part of the stack traces and prints it along with the error type and message.

I think of if from a usability & dev x perspective.
I think that once decided that nodejs will terminate the process and throw an error on unhandled rejections, you can't have some types of rejections not contain the relevant debugging information.
Every error thrown by the runtime should include all the relevant information to pinpoint the origin of the problem exactly.

I can think of some implementation maybe that the reject function itself should generate a stack trace once called and attach that to the error thrown by node if the rejected value isn't an error.

I totally agree that the best practice is rejecting with errors.
And the jest test that failed on me did in fact throw an actual error (but jest process object is different etc...).
We also have eslint rule to enforce that so i'm less concerned that we will run in to this issue very often after your fix.
However, I feel uncomfortable knowing that there are cases that nodejs can be totally ambiguous about errors occurring and terminating my process.
Because we, and most of the NodeJS community, rely heavily on third party npm open source libraries.
And you can't enforce good practices on third party code.
So you can run into this problem regardless of how strictly you follow that rule or not.

Therefore, I think all cases and all reject values should be handled and have enough information to be discoverable.

@benjamingr
Copy link
Member

benjamingr commented Jan 25, 2022

Browsers do handle that case:

Browsers only handle that case with the debugger connected - if you throw an Error without the devtools open and watch it in your instrumentation you will see it has no stack trace.

This is because this is both rare and incurs a performance overhead and because the debugger can "cheat" and do things that aren't standardized in JavaScript itself.

Node does this as well which is why I suggested running with the inspector and pausing in the debugger as a workaround locally. We can probably log a better message with an inspector connected (calling the relevant cdp function)

I think that once decided that nodejs will terminate the process and throw an error on unhandled rejections, you can't have some types of rejections not contain the relevant debugging information.

This is equally true (and has been for 10+ years) for regular uncaught exceptions and it's a property of JavaScript.

I can think of some implementation maybe that the reject function itself should generate a stack trace once called and attach that to the error thrown by node if the rejected value isn't an error.

That can't work since stacks in JavaScript are a property of the Error object itself rather than the throw statement (or reject in this case) like in other languages (like C# for example).

And the jest test that failed on me did in fact throw an actual error (but jest process object is different etc...).

I opened a PR for that :) It seems very reasonable to me to support cross-realm errors. It will sit around for another day and then I'll push test fixes, solicit reviews and merge it.

However, I feel uncomfortable knowing that there are cases that nodejs can be totally ambiguous about errors occurring and terminating my process.

I agree and if it was possible to entirely prohibit rejecting non-errors I would turn that switch. In bluebird (which I maintain(ed) before) we used to warn on this (with a stack trace in non-production builds).

I also don't agree with the argument regarding the ecosystem - every npm module can call process.exit() or while(1); which in practice hasn't been a problem and when it was it is explicitly so maliciously (that is: any npm module can delete the local filesystem or the node binary for example - isolation should be at the container level typically).

@benjamingr
Copy link
Member

benjamingr commented Jan 25, 2022

So to summarize my position:

  • I am a strong -1 on anything that will cause any slowdown in order to better support non-Error errors without a connected debugger (which is impossible to do anyway without asking for work from V8 and they will likely block it). It is simply incompatible with the language which doesn't give us (the platform) much wiggle room.
  • I think we should support cross-realm-errors in our error messages (hence the PR)
  • I am a +0 on developer experience improvements for non-Error throws in developer time with the debugger attached - that is: we can do a better job with the error we print when an inspector is attached to not require the user to go through the extra step of ticking "pause on uncaught error" to see the stack.
    • If this is something you want to work on - let me know and I can help guide you through the steps involved in making a PR for it.

@ItamarGronich
Copy link
Author

ItamarGronich commented Jan 26, 2022

Browsers only handle that case with the debugger connected - if you throw an Error without the devtools open and watch it in your instrumentation you will see it has no stack trace.

Not sure what you meant by "your instrumentation" exactly but i tried doing this in the browser using window.addEventListener('unhandledrejection', (e) => ....) and you're right! Good to know!

The Node api is a bit different and doesn't have this event and instead uses only the reason and the promise.
I wonder why this difference maybe you can help me understand since you wrote it? I understood that from your comment: jestjs/jest#10784 (comment)

This is equally true (and has been for 10+ years) for regular uncaught exceptions and it's a property of JavaScript.

However i tried this on a regular throw statement like throw "This is not an error" but this does in fact have a way to trace it.
There's no stack trace but there's filename, line number and column number on the error event.

window.addEventListener('error', function(e) {
  console.log(`Error: ${e.error}; thrown at: ${e.filename}:${e.lineno}:${e.colno}`); // => Error: This is not an error; thrown at: http://127.0.0.1:4200/index.js:5:1
})

throw 'This is not an error'

The error property on the event itself is indeed not an error instance (it's just a string of course) and doesn't include a stack trace for that reason. But you could still construct a valuable reference to where the error occurred and perhaps send it to your monitoring service (Datadog etc..).
Of course as i mentioned before, no similar information exists on the PromiseRejectionEvent as far as i could find.

This is because this is both rare and incurs a performance overhead and because the debugger can "cheat" and do things that aren't standardized in JavaScript itself.

Node does this as well which is why I suggested running with the inspector and pausing in the debugger as a workaround locally. We can probably log a better message with an inspector connected (calling the relevant cdp function)

That sounds cool but it doesn't solve the most important case - production.
When this happens in production you simply can't find the source of the problem.
You need to try and reproduce the error locally with the debugger attached which can be hard to impossible since you have absolutely no clue as to where to begin since there's no information on the error.
You maybe have to run your production instances with inspect on (?) just to be able to discover this error.
Not sure how that would go.

That can't work since stacks in JavaScript are a property of the Error object itself rather than the throw statement (or reject in this case) like in other languages (like C# for example).

Found this little lib that does something similar to what i said: https://github.com/grantila/trace-unhandled/blob/master/lib/core.ts#L128
They simply generate a new Error and just put it on the promise instance so they can later look it up and throw a stack trace to the rejected promise.
I'd hate to have to use that anyway - of course it would be better if the platform/language could give this to me.
So I'm not so sure that you should but i think you could technically do this in the NodeJS promise implementation no?

I opened a PR for that :) It seems very reasonable to me to support cross-realm errors. It will sit around for another day and then I'll push test fixes, solicit reviews and merge it.

Yep i saw! thanks for that again - for so quickly jumping onto this

I also don't agree with the argument regarding the ecosystem - every npm module can call process.exit() or while(1); which in practice hasn't been a problem and when it was it is explicitly so maliciously (that is: any npm module can delete the local filesystem or the node binary for example - isolation should be at the container level typically).

True, but doing those things (process.exit() and while(1)) is basically doing it intentionally and maliciously.
I'm not talking about that, i'm talking about innocently not following this particular best practice, and committing this kind of code to a lib, or possibly event as a design decision.
That would mean things will break and it would be super hard to detect.

If this is something you want to work on - let me know and I can help guide you through the steps involved in making a PR for it.

I'll be glad to. I might reach out to you sometime soon.

@devsnek
Copy link
Member

devsnek commented Jan 26, 2022

when node intercepts an uncaught exception that isn't an Error it can take a snapshot of the current stack to provide a traceback but that's not possible for the promise case because promise executors start from an empty stack. and even so it only does that when the uncaught exception is fatal. if you handle it with an event you don't get that, as you noticed.

@benjamingr
Copy link
Member

@ItamarGronich

The Node api is a bit different and doesn't have this event and instead uses only the reason and the promise.
I wonder why this difference maybe you can help me understand since you wrote it?

This was the proposal to unify unhandled rejections across promise libraries for better DX: https://gist.github.com/benjamingr/0237932cee84712951a2 (the formatting is dead, sort of because of markdown changes in GitHub).

I implemented it in promise libraries (like Q which was popular) and asked @petkaantonov for help with it in Node core (I wasn't a collaborator back then) - which resulted in #758 - there were several talks with different parties (namely nodejs/promises nodejs/promises-debugging and nodejs/promise-use-cases initiatives + collaborator summit sessions) which helped motivate things like async stack traces.

Additionally the last push (an initiative by Mary) to finally settle "what should Node do" and agree to crash the process finally making async exceptions behave like sync exceptions.

Node didn't have EventTarget back then (it was added later) and still doesn't have Window or anything comparable so it uses Node event syntax (like uncaughtException) rather than the DOM's. The person who specified the DOM's event helped us with ours (and the feedback/research) helped theirs).

However i tried this on a regular throw statement like throw "This is not an error" but this does in fact have a way to trace it.

I'm... not sure how you're doing that but I get null for e.error (97.0.4692.71 (Official Build) (x86_64) ,Revision | adefa7837d02a07a604c1e6eff0b3a09422ab88d-refs/branch-heads/4692@{#1247} ,OS | macOS Version 11.6.1 (Build 20G224), JavaScript | V8 9.7.106.18 ) and I don't see how I can access the stack on the event.

You maybe have to run your production instances with inspect on (?) just to be able to discover this error.

I connect debuggers to production machines all the time, it's actually pretty easy (you can send a node instance a signal to open the debugger then expose the port from docker and connect to it - the inspector is just a websocket).

That said, the solution is simply not to throw strings - that's as bad as doing process.exit() and then trying to figure out where it happened. Writing Node servers with correct production error handling is tricky for many other reasons :)

Found this little lib that does something similar to what i said: https://github.com/grantila/trace-unhandled/blob/master/lib/core.ts#L128

We did that at bluebird (https://github.com/petkaantonov/bluebird) the trick is you capture a stack whenever a promise is created, keep track of chains and if that promise is rejected you "stitch" the chains and has its own context stack (here: https://github.com/petkaantonov/bluebird/blob/e8006fc50dcfd6323639e2864aac9b52a9ec5466/src/context.js#L45 ) - it even used to work for primitives!

The thing is - incurring overhead (a stack trace is expensive) pre-emptively for an extremely rare use case is probably not worth it for the same reason async stack traces don't work for anything other than async functions.

As a fun exercise you can build this in userland using async_hooks where you get events for promises (there is a performance penalty though keep in mind!) see the promise tracking section for details.

I'm not talking about that, i'm talking about innocently not following this particular best practice, and committing this kind of code to a lib, or possibly event as a design decision.

We also used to wrap non-errors when promisifying stuff in bluebird - but note that's not really something Node gets to do as a platform since we really need to stick to "standard JavaScript" as much as possible. If you find modules that do this please consider PRing them with a fix!

I'll be glad to. I might reach out to you sometime soon.

Please do!

nodejs-github-bot pushed a commit that referenced this issue Jan 28, 2022
Support cross realm errors where `instanceof` errors in our
unhandledRejection warning to print better error with stack traces.

PR-URL: #41682
Refs: #41676
Reviewed-By: Nitzan Uziely <linkgoron@gmail.com>
Reviewed-By: Tierney Cyren <hello@bnb.im>
Linkgoron pushed a commit to Linkgoron/node that referenced this issue Jan 31, 2022
Support cross realm errors where `instanceof` errors in our
unhandledRejection warning to print better error with stack traces.

PR-URL: nodejs#41682
Refs: nodejs#41676
Reviewed-By: Nitzan Uziely <linkgoron@gmail.com>
Reviewed-By: Tierney Cyren <hello@bnb.im>
ruyadorno pushed a commit that referenced this issue Feb 8, 2022
Support cross realm errors where `instanceof` errors in our
unhandledRejection warning to print better error with stack traces.

PR-URL: #41682
Refs: #41676
Reviewed-By: Nitzan Uziely <linkgoron@gmail.com>
Reviewed-By: Tierney Cyren <hello@bnb.im>
@benjamingr
Copy link
Member

Going to go ahead and close this - when you want to work on better support for primitives please let me know and I'll reopen :)

danielleadams pushed a commit that referenced this issue Mar 2, 2022
Support cross realm errors where `instanceof` errors in our
unhandledRejection warning to print better error with stack traces.

PR-URL: #41682
Refs: #41676
Reviewed-By: Nitzan Uziely <linkgoron@gmail.com>
Reviewed-By: Tierney Cyren <hello@bnb.im>
danielleadams pushed a commit that referenced this issue Mar 3, 2022
Support cross realm errors where `instanceof` errors in our
unhandledRejection warning to print better error with stack traces.

PR-URL: #41682
Refs: #41676
Reviewed-By: Nitzan Uziely <linkgoron@gmail.com>
Reviewed-By: Tierney Cyren <hello@bnb.im>
danielleadams pushed a commit that referenced this issue Mar 14, 2022
Support cross realm errors where `instanceof` errors in our
unhandledRejection warning to print better error with stack traces.

PR-URL: #41682
Refs: #41676
Reviewed-By: Nitzan Uziely <linkgoron@gmail.com>
Reviewed-By: Tierney Cyren <hello@bnb.im>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
feature request Issues that request new features to be added to Node.js. promises Issues and PRs related to ECMAScript promises.
Projects
None yet
Development

No branches or pull requests

3 participants