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

Show correct stack traces for unhandled promise rejections #188

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

Conversation

arkadiyt
Copy link

Hi,

When an ES6 promise is rejected without being handled, node logs it to the console:

(node:61401) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 1): Error: blah

and emits an unhandledRejection event with the uncaught error. This PR adds support in the same way that uncaughtException is handled, and prints the correct stacktrace:

/Users/atetelman/workspace/project/index.js:70
    throw new Error('blah');
          ^
Error: blah
    at Object.<anonymous> (/Users/atetelman/workspace/project/src/index.js:70:11)
    at next (native)
    at step (/Users/atetelman/workspace/project/index-dist.js:246:191)
    at /Users/atetelman/workspace/project/index-dist.js:246:361
    at process._tickDomainCallback (internal/process/next_tick.js:135:7)

Thanks,

@LinusU
Copy link
Collaborator

LinusU commented Aug 25, 2017

This looks very good, the only thing that concerns me is that this will actually terminate the program, whereas the default behaviour is to just print a one line warning, or am I missing something?

@arkadiyt
Copy link
Author

@LinusU you're correct, I didn't realize the aptly named printErrorAndExit actually exited the process.

However the same argument could be made for uncaught exceptions - the default behavior is to continue running the program, but node-source-map-support will terminate the program. Is that fine/expected still?

Lemme know how you want this to look like and I can try to refactor it

@LinusU
Copy link
Collaborator

LinusU commented Aug 26, 2017

I believe that the default behaviour for uncaught exceptions is to exit the process, they are not handled equally by Node.js

@arkadiyt
Copy link
Author

My bad, I was testing in the REPL and that behaves differently with uncaught exceptions than running a node script on the command line.

I've pushed a new commit which prints + exits on uncaughtException, and only prints on unhandledRejection. I tested it against node 6.10.3 and 8.4 and it worked as expected.

Worth noting that in 8.4 an unhandled promise rejection also prints:

(node:72412) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

This is documented here: https://nodejs.org/api/deprecations.html#deprecations_dep0018_unhandled_promise_rejections

But that's not the behavior yet

@LinusU
Copy link
Collaborator

LinusU commented Aug 27, 2017

Hmm, just a thought. Do you think it would be possible to just modify the .stack property and then call the original implementation? Something like:

const originalEmit = process.emit

process.emit = function (type, data) {
  if (type === 'uncaughtException' || type === 'unhandledRejection') {
    if (data && data.stack) data.stack = getErrorSource(error) + '\n' + data.stack
  }

  oritinalEmit.call(this, type, data)
}

@arkadiyt
Copy link
Author

arkadiyt commented Aug 28, 2017

I gave it a try and ran into the following issue - consider the test file:

require('./source-map-support').install();
throw new Error('test');

When I run it I get:

$ node test.js
/workspace/node-source-map-support/test.js:2
throw new Error('test');
^

/workspace/node-source-map-support/test.js:2
throw new Error('test');
      ^
Error: test
    at Object.<anonymous> (/workspace/node-source-map-support/test.js:2:7)
    at Module._compile (module.js:570:32)
    at Object.Module._extensions..js (module.js:579:10)
    at Module.load (module.js:487:32)
    at tryModuleLoad (module.js:446:12)
    at Function.Module._load (module.js:438:3)
    at Module.runMain (module.js:604:10)
    at run (bootstrap_node.js:390:7)
    at startup (bootstrap_node.js:150:9)
    at bootstrap_node.js:505:3

It printed the error source twice. The bottom one is from getErrorSource in the line:

data.stack = getErrorSource(error) + '\n' + data.stack

and the top one is from the node internal exception handler. This is handled in C code:
https://github.com/nodejs/node/blob/79773f8af940912264b55e5255db9f50e25ac16a/src/node.cc#L1756-L1757
(node calls this the "arrow_string")

If I were to remove the getErrorSource then it would only print a single time (from the node implementation), but it would use the transpiled source, without taking the source map into account.

I believe it should be possible to modify the arrow string on the error as a hidden field - node does this here:
https://github.com/nodejs/node/blob/095357e26efc366b1cca389306e0780cc1fa81d9/lib/internal/util.js#L67-L78

but it requires changing fields that depend on node internals, and may not be consistent between different versions of node.

What do you think?

@LinusU
Copy link
Collaborator

LinusU commented Aug 28, 2017

Great investigation 👍 It's probably best to to not go that route...

Let's merge it as it

actually, I just realised that Node.js standard behaviour is to just print one line, and this will print a stack trace instead. It feels like we shouldn't stray away from the behaviour of standard Node.js, even though I personally think that it's better to print the stack 😄

How about only enabling this when --trace-warnings are given to Node? We should probably also print that deprecation warning that Node.js 8 is printing out behind a if (process.version.slice(0, 3) === 'v8.') or similar...

@arkadiyt
Copy link
Author

arkadiyt commented Aug 29, 2017

Added a deprecation warning that prints once, following https://github.com/nodejs/node/blob/689a64319864433b32235b9d6ac4889f4cdcfea5/lib/internal/process/promises.js#L69-L76. This warning was originally added here: nodejs/node@07dbf73 for all node versions 7.0.0+, so I default deprecationWarned depending on if the node major version is less than 7.

Both promise rejections and uncaught exceptions will now only print the source (without stack traces) unless --trace-warnings is given. To check for the flag I'm reading process.traceProcessWarnings, set here: https://github.com/nodejs/node/blob/689a64319864433b32235b9d6ac4889f4cdcfea5/src/node.cc#L3397-L3400. Strictly speaking it's also internal / not documented, but it seems stable and cleaner than depending on & parsing argv.

I also updated unhandledRejection emit to now return true - this prevents another duplicate warning that happens when --trace-warnings is on: https://github.com/nodejs/node/blob/689a64319864433b32235b9d6ac4889f4cdcfea5/lib/internal/process/promises.js#L87-L88

edit: I can try to look at the failing tests on Wednesday

@LinusU
Copy link
Collaborator

LinusU commented Aug 29, 2017

Both promise rejections and uncaught exceptions will now only print the source (without stack traces) unless --trace-warnings is given.

I think that uncaught exceptions should always print stack trace, it's only unhandled rejection that should only print when the --trace-warnings flag is given.

It seems like that is why the tests are failing as well...

@sungshon
Copy link

it's sad that this PR got stuck, i wasted a lot of time trying to get this module to work because i thought i was doing something wrong on my side, as unhandled promise rejections didn't show the correct stack trace

@aral
Copy link

aral commented Apr 10, 2020

@sungshon A year later, me too. Any way to bump this up somehow?

@jiffies
Copy link

jiffies commented Nov 3, 2023

Still can't ouput correct stack.
process.on('unhandledRejection', (error, promise) => { console.log(' Promise :', error); });
Error: could not detect network (event="noNetwork", code=NETWORK_ERROR, version=providers/5.7.2) at Logger.Logger.makeError (/home/node_modules/@ethersproject/logger/src.ts/index.ts:269:28) at Logger.Logger.throwError (/home/node_modules/@ethersproject/logger/src.ts/index.ts:281:20) at Provider.<anonymous> (/home/node_modules/@ethersproject/providers/src.ts/json-rpc-provider.ts:483:23) at step (/home/node_modules/@ethersproject/providers/src.ts/json-rpc-provider.ts:1:14) at Object.throw (/homenode_modules/@ethersproject/providers/src.ts/json-rpc-provider.ts:1:14) at rejected (/home/node_modules/@ethersproject/providers/src.ts/json-rpc-provider.ts:1:14) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) { reason: 'could not detect network', code: 'NETWORK_ERROR', event: 'noNetwork' }

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants