Repository navigation
process.throwDeprecation hides original error stack #17871
Description
Activity
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.
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.
Reacted by Shenghan Gao, chris mckenzie and Alex YangRefs #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.
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:3It'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.
@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
xas it only knows things happening sync.I hope this explains the problem better.
Reacted by James NylenWe 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:3OTOH, 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.
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
Errorhere as opposed to re-using the error from the promise rejection?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.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.
This is still broken, and I still don't understand why this issue was closed.
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 ); } );
- added a commit that references this issue
on Mar 17, 2020 - added a commit that references this issue
on May 23, 2020
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 = trueornode --throw-deprecationhere, the behavior is the same.$ 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:3Expected behavior
Note concise output that preserves the original error stack without adding irrelevant stuff.
$ 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