nodejs/node

unhandledRejection Stack Traces are unhelpful

Closed this issue Β· 23 comments

Version: v6.9.1
Platform: Linux

If possible, please provide code that demonstrates the problem, keeping it as
simple and free of external dependencies as you are able.

If I could I would, but the whole problem is that I can't figure out where the problematic code is.

I have an unhandled promise rejection warning, and for obvious reasons I'd like to get rid of it. However when I try to figure out where it's coming from (by turning on stack traces for unhandled rejections) I get a trace like:

(node:31438) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 1): TypeError: Cannot read property 'bottom' of undefined
    at emitPendingUnhandledRejections (internal/process/promises.js:57:27)
    at runMicrotasksCallback (internal/process/next_tick.js:61:9)
    at _combinedTickCallback (internal/process/next_tick.js:67:7)
    at process._tickDomainCallback (internal/process/next_tick.js:122:9)

... which of course is completely unhelpful since it doesn't reference a single line of my code. But clearly my code caused the rejection, so is there any way that Node could point me to the source of the problem with the stack trace?

Since promises are asynchronous, the only way to trace what occurred prior to next_tick is via a deep/long stack tracing, which is a feature supported by Bluebird, as one example, but not by Node.js.

Man, and I was really trying to avoid using a 3rd-party promise library. Bummer.

But thanks for taking the time to provide clarification.

I’ll take the liberty to reopen this because I think this would be really useful and I can’t see any reason why the .stack property the Error with which the promise was rejected would not be useful information here.

Thanks @addaleax. I didn't think this was a feature that could/would be implemented, but I'm quite happy to be wrong!

@addaleax to be honest, seems like a bug to me. There is no reason to show such stack trace at all

I can’t see any reason why the .stack property the Error with which the promise was rejected would not be useful information here.

For one thing, because it would be a very heavy feature, to be used with care. In fact, it is a real performance killer, if someone by mistake deploys to PROD with it, so, be careful adding it πŸ˜‰

I'm taking about long promise loops, such as pseudo-recursion πŸ˜‰

@vitaly-t you are talking about long stack traces, it's a different issue

@vkurchatkin exactly. Why is it a different issue? What did I miss? πŸ˜„

You would need long stack tracing in order to capture the extra stack calls that's being discussed.

@vitaly-t It’s just about displaying the stack trace that was created along with the error object itself, no deep or long traces or anything. :)

(idk if that’s the source of the confusion but the stack trace in the OP showed the stack at the time of the warning being emitted, not the Error object being generated)

@machineghost try process.on('unhandledRejection', r => console.log(r));. Not sure why do you see a stack trace at all

I think that might come from --trace-warnings?

Not sure why do you see a stack trace at all

I turned them on with --trace-warnings (the unhandled promise rejection warning was really bugging me ...)

try process.on('unhandledRejection', r => console.log(r));

Will do, and will report back.

EDIT
It worked, thank you! I got:

TypeError: Cannot read property 'bottom' of undefined
    at \*my code\*

That seems like a perfectly awesome way of tracing the origin of unhandled promise rejections ... if you're aware of it. I just feel bad for anyone who has the same problem as me, who doesn't have the luck to find this issue in a Google search.

Yeah, in that case it is expected, I think

@vkurchatkin Expected but pretty much useless πŸ˜‰ I’ll try to put together a patch for this and we’ll see whether it gains any traction.

PR @ #9525

d668 commented

hm, I have

process.on('unhandledRejection', err => {
    console.log("Caught unhandledRejection");
    console.log(err);
});

and the output I get is

Caught unhandledRejection
null

with node --trace-warnings app

any ideas?

Is there any reason process.on('unhandledRejection', r => console.log(r)) shouldn't be the default? It is a much more useful behavior, and there shouldn't be any harm from having it on.

I went through some pain for hours. Finally found this. And I agree: Why isn't that the default behavior? The default behavior is going to scare people away from using Promises.

For anybody else coming from Google or elsewhere, I am sorry for your arduous journey. Here lies your answer...

@vkurchatkin's code above was all I needed to fix this problem.

while catching unhandledRejection does work and provides backtrace:

ReferenceError: name is not defined
at handleInvoiceAdd (/Users/lukas/Desktop/www/trafikito.com/src/backend/api/routes/invoice/add.js:194:7)
at
at process._tickCallback (internal/process/next_tick.js:188:7)

I would not recommend to use it in production while unhandledRejection may cause the app to stay in broken state and should be restarted. So what I did, is I run it in non-production env + I still kill the app after logging the details.

  process.on('unhandledRejection', (r) => {
    console.error('#dfkfjks tracing unhandledRejection: ');
    console.error(r);
    process.kill(1);
  });

So i have the trace, app is still killed and restarted by pm2.

For anybody else coming from Google or elsewhere, I am sorry for your arduous journey. Here lies your answer...

@vkurchatkin's code above was all I needed to fix this problem.

The real MVP ^^^

marcj commented

Not exiting the process when unhandledRejection is occured is very dangerous as it returns an exit code of 0, which means 'everything went fine'. Terrible for shell scripts, for CI, process manager, and the overall behaviour of your application.

Use instead:

process.on('unhandledRejection', error => {
    console.log(error);
    process.exit(1);
});

Don't use the code from @liesislukas either, as it does not kill your process, but the one with PID = 1, which is in Docker container your process, but in none-docker it will probably restart your whole operating system (https://unix.stackexchange.com/questions/7441/can-root-kill-init-process).

Why was this closed without being fixed (yes, there's a workaround)? Why is the PR to fix the same issue open since 2017? evanw/node-source-map-support#188