`process.throwDeprecation` hides original error stack #17871

nylen · 2017-12-26T21:01:35Z

Node v9.3.0 on Linux (I would expect other versions since the introduction of the deprecation warning stuff - and other platforms - to behave the same way)

Current behavior

It doesn't matter whether you use process.throwDeprecation = true or node --throw-deprecation here, the behavior is the same.

async function x() {
    throw new Error( 'aaaa' );
}

process.throwDeprecation = true;

x().then( r => console.log( r ) );

$ node test1.js
internal/process/warning.js:143
        throw warning;
        ^

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.
    at emitWarning (internal/process/promises.js:92:15)
    at emitPendingUnhandledRejections (internal/process/promises.js:109:11)
    at runMicrotasksCallback (internal/process/next_tick.js:118:9)
    at process._tickCallback (internal/process/next_tick.js:150:11)
    at Function.Module.runMain (module.js:703:11)
    at startup (bootstrap_node.js:194:16)
    at bootstrap_node.js:618:3

Expected behavior

Note concise output that preserves the original error stack without adding irrelevant stuff.

async function x() {
        throw new Error( 'aaaa' );
}

process.on( 'unhandledRejection', err => {
        console.error( 'Unhandled promise rejection:', err );
        process.exit( 1 );
} );

x().then( r => console.log( r ) );

$ node test2.js 
Unhandled promise rejection: Error: aaaa
    at x (../test2.js:2:8)
    at Object.<anonymous> (.../test2.js:10:1)
    at Module._compile (module.js:660:30)
    at Object.Module._extensions..js (module.js:671:10)
    at Module.load (module.js:573:32)
    at tryModuleLoad (module.js:513:12)
    at Function.Module._load (module.js:505:3)
    at Function.Module.runMain (module.js:701:10)
    at startup (bootstrap_node.js:194:16)
    at bootstrap_node.js:618:3

The text was updated successfully, but these errors were encountered:

BridgeAR · 2017-12-26T21:21:03Z

This is normal behavior as the error is thrown async as most errors in Node.js. Tracking errors better can be done with async hooks on your side. Currently there is nothing that can be done to further improve this. Therefore I am closing this issue.

nylen · 2017-12-26T22:14:38Z

When an error occurs in my code, I expect to see the place in my code where it occurred. I think this is a pretty reasonable expectation and this issue should stay open until it's met for the case I described.

BridgeAR · 2017-12-26T22:24:15Z

Refs #11865

@nylen there you will find more information about the problem. It has nothing to do with "your code". What is actually happening is something like

function throwing() { throw new Error() }
function notIncludedInStack() { setTimeout(throwing, 1) }
notIncludedInStack()

This will only show "throwing" in the stack trace and not the original function because the error is thrown async.

nylen · 2017-12-26T22:36:16Z

Thanks for the context.

Of course I'd like to have full async stack traces, but that's not really what this issue is about. In this specific case, I don't want to see any of these stack trace lines, because they're not relevant to the actual problem that occurred:

    at emitWarning (internal/process/promises.js:92:15)
    at emitPendingUnhandledRejections (internal/process/promises.js:109:11)
    at runMicrotasksCallback (internal/process/next_tick.js:118:9)
    at process._tickCallback (internal/process/next_tick.js:150:11)
    at Function.Module.runMain (module.js:703:11)
    at startup (bootstrap_node.js:194:16)
    at bootstrap_node.js:618:3

It's a bit frustrating to have this closed as "question" because all of the information needed to print a better stack trace is readily available.

BridgeAR · 2017-12-26T23:12:58Z

@nylen I will try to explain it with your code

async function x() {
    throw new Error( 'aaaa' );
}

This translates into

function x() {
  return Promise.reject(new Error('aaaa'));
}

As soon as the promise is rejected Node.js tracks if it was caught on the nextTick. This is not the case here and as soon as Node.js realizes this (remember, it is already in the next tick), a new Error is created. This error has a stack trace that has no knowledge about the function x as it only knows things happening sync.

I hope this explains the problem better.

bnoordhuis · 2017-12-26T23:45:14Z

We could defer the deprecation warning by a tick, that gives the UnhandledPromiseRejectionWarnings time to print. I.e., this diff:

diff --git a/lib/internal/process/promises.js b/lib/internal/process/promises.js
index 82f15f9f9d..8985cd1a63 100644
--- a/lib/internal/process/promises.js
+++ b/lib/internal/process/promises.js
@@ -89,11 +89,18 @@ function setupPromises(scheduleMicrotasks) {
     process.emitWarning(warning);
     if (!deprecationWarned) {
       deprecationWarned = true;
-      process.emitWarning(
-        '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.',
-        'DeprecationWarning', 'DEP0018');
+      const warn = () => {
+        process.emitWarning(
+          '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.',
+          'DeprecationWarning', 'DEP0018');
+      };
+      if (process.throwDeprecation)
+        process.nextTick(warn);  // Give warnings time to print.
+      else
+        warn();
     }
   }

Produces this output:

(node:77108) UnhandledPromiseRejectionWarning: Error: aaaa
    at x (/home/bnoordhuis/src/bug17871.js:2:11)
    at Object.<anonymous> (/home/bnoordhuis/src/bug17871.js:7:1)
    at Module._compile (module.js:660:30)
    at Object.Module._extensions..js (module.js:671:10)
    at Module.load (module.js:577:32)
    at tryModuleLoad (module.js:517:12)
    at Function.Module._load (module.js:509:3)
    at Function.Module.runMain (module.js:701:10)
    at startup (bootstrap_node.js:194:16)
    at bootstrap_node.js:645:3
(node:77108) UnhandledPromiseRejectionWarning: Unhandled promise rejection. 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(). (rejection id: 2)
internal/process/warning.js:143
        throw warning;
        ^

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.
    at process.nextTick (internal/process/promises.js:93:17)
    at process._tickCallback (internal/process/next_tick.js:114:11)
    at Function.Module.runMain (module.js:703:11)
    at startup (bootstrap_node.js:194:16)
    at bootstrap_node.js:645:3

OTOH, a one-off hack like that is kind of yuck and it's not as if node isn't doing exactly what it's being told to - throw instead of emit.

@nylen You can try opening a PR and see what others think.

nylen · 2017-12-28T00:30:15Z

as soon as Node.js realizes this (remember, it is already in the next tick), a new Error is created. This error has a stack trace that has no knowledge about the function x as it only knows things happening sync.

This is the root of the problem, I think. Why does Node have to create a new Error here as opposed to re-using the error from the promise rejection?

nylen · 2017-12-28T01:03:36Z

OTOH, a one-off hack like that is kind of yuck and it's not as if node isn't doing exactly what it's being told to - throw instead of emit.

I agree with all of this. I think a better fix involves throwing the original error instead of throw warning, but I am not sure the best way to achieve it.

nylen · 2018-08-05T18:45:21Z

Just wrote this in another script:

// https://github.com/nodejs/node/issues/17871 :(
// process.throwDeprecation = true;
process.on( 'unhandledRejection', err => {
    console.error( 'Unhandled promise rejection:', err );
    process.exit( 1 );
} );

I want to like developing against Node.js with promises and async/await, but stuff like this doesn't make it easy.

nylen · 2018-11-12T20:41:47Z

This is still broken, and I still don't understand why this issue was closed.

nylen · 2020-03-16T19:52:13Z

I'm still writing this at the top of almost all my scripts:

// https://github.com/nodejs/node/issues/17871 :(
process.on( 'unhandledRejection', err => {
    console.error( 'Unhandled promise rejection:', err );
    process.exit( 1 );
} );

This makes sure all warnings that were triggered before a deprecation warning during the same tick are properly handled and logged. It also guarantees that users can not catch the error anymore. Fixes: nodejs#17871

BridgeAR · 2020-03-17T01:40:01Z

@nylen I am sorry, I somehow misread your original issue. I just opened a PR to fix the issue. The warning mechanism was a bit off by delaying the actual warnings but not the error.

See #32312

nylen mentioned this issue Dec 26, 2017

doc: add documentation for deprecation properties #16539

Closed

2 tasks

BridgeAR closed this as completed Dec 26, 2017

BridgeAR added the question Issues that look for answers. label Dec 26, 2017

This was referenced Mar 7, 2020

[Snyk] Security upgrade gatsby from 2.13.73 to 2.16.2 meghasfdc/node#4

Open

[Snyk] Security upgrade gatsby from 2.13.73 to 2.16.2 kissofire/node#3

Open

BridgeAR added confirmed-bug Issues with confirmed bugs. and removed question Issues that look for answers. labels Mar 17, 2020

BridgeAR mentioned this issue Mar 17, 2020

process: delay throwing an error using throwDeprecation #32312

Closed

4 tasks

BridgeAR reopened this Mar 17, 2020

BridgeAR closed this as completed in 49745cd May 23, 2020

nylen mentioned this issue May 27, 2020

Add a new process.unhandledRejections runtime flag #33577

Closed

nylen mentioned this issue Aug 18, 2020

doc: add unhandled promise rejection survey nodejs/TSC#857

Closed

ArshErgon mentioned this issue Oct 31, 2022

Unhandled promises while starting up the project local remoteintech/remote-jobs#1574

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`process.throwDeprecation` hides original error stack #17871

`process.throwDeprecation` hides original error stack #17871

nylen commented Dec 26, 2017

BridgeAR commented Dec 26, 2017

nylen commented Dec 26, 2017

BridgeAR commented Dec 26, 2017

nylen commented Dec 26, 2017

BridgeAR commented Dec 26, 2017

bnoordhuis commented Dec 26, 2017

nylen commented Dec 28, 2017

nylen commented Dec 28, 2017

nylen commented Aug 5, 2018

nylen commented Nov 12, 2018

nylen commented Mar 16, 2020

BridgeAR commented Mar 17, 2020

process.throwDeprecation hides original error stack #17871

process.throwDeprecation hides original error stack #17871

Comments

nylen commented Dec 26, 2017

Current behavior

Expected behavior

BridgeAR commented Dec 26, 2017

nylen commented Dec 26, 2017

BridgeAR commented Dec 26, 2017

nylen commented Dec 26, 2017

BridgeAR commented Dec 26, 2017

bnoordhuis commented Dec 26, 2017

nylen commented Dec 28, 2017

nylen commented Dec 28, 2017

nylen commented Aug 5, 2018

nylen commented Nov 12, 2018

nylen commented Mar 16, 2020

BridgeAR commented Mar 17, 2020

`process.throwDeprecation` hides original error stack #17871

`process.throwDeprecation` hides original error stack #17871