Unhandled rejection overtakes synchronous exception through done()

[rogierschouten]

Seen with Bluebird 2.9.3.

The behavior below caused a programming error to become hidden, making debugging difficult. The done() method will terminate the application on a thrown error within a promise chain, but it might wait to do so for quite some time, even processing more promises. In the meantime, the application continues to run, generating all kinds of unexpected side effects - after all, we're already in an error state.

I'm aware that the whole thing is a-synchronous and that you cannot terminate the application immediately on an exception. However, it seems that arbitrarily long promise chains are still executed before the done() - they seem to overtake each other. I would at least expect some execution order to be preserved.

What happened in reality (below is a smaller example) is that an assertion error occurred within a promise chain that ended in .done(). After that, the application was in a state where it behaved wrongly and eventually caused another un-handled rejection. The un-handled rejection overtook the assertion error and only the rejection was shown, obscuring the real cause. Note that the rejection was quite far removed in terms of nodejs cycles.

The example below shows the problem

var Promise = require("bluebird");

// kill the process on unhandled rejections
Promise.onPossiblyUnhandledRejection(function(reason) {
        // do some custom logging
    console.log("possibly unhandled rejected Promise", reason);
    process.exit(1);
});

Promise.resolve()
    .then(function() {
        // longer chain expected to give error long after the process is dead
                // not because .done() but because of possibly unhandled rejection handler.
        Promise.resolve()
            .then(function() {              
                Promise.resolve()
                    .then(function() {              
                        Promise.reject(new Error("unhandled rejection"));
                    });
            });

        // exception expected to terminate the process
        throw new Error("unhandled thrown error which should end the process because of done()");
    })
    .done();

Console output:

possibly unhandled rejected Promise [Error: unhandled rejection]

Is this expected behavior?

[spion]

The problem is in async.js using setTimeout to throw the error, if available. By that time the possibly unhandled rejection has already happened and the process will exit. Maybe it can be fixed by a patch that rethrows both synchronously and asynchronously.

[rogierschouten]

We also have this:

Promise.setScheduler(function(callback) {
    setImmediate.apply(null, [callback]);
});

I would at least have expected that to be used also for .done(). But I agree that throwing synchronously would be even better.

EDIT: note that reproducing the error was done without this scheduler so in that sense it does not matter.

[petkaantonov]

I want to throw synchronously but if the application recovers from the exception (e.g. always in browser and sometimes in node if there is domain or uncaughtException handler that doesn't exit process), it will leave bluebird in inconsistent state

[rogierschouten]

Would that matter once you've made a programmer error?

[petkaantonov]

In practice, yes.. just open the console of any website, it's full of uncaught errors and the applications appear to be keep working just fine.

[rogierschouten]

Could we make it an option, then? So we can have a sync exception server-side, or while not in production?

[petkaantonov]

What if in node it did the same as event emitters... write stack trace to stderr and exit immediately? shouldn't that be effectively the same as throwing synchronously but without the risk that the application recovers?

[rogierschouten]

Yes that would be nice. But in that case I would expect a handler similar to onPossiblyUnhandledRejection() so that I can flush the logs.

[petkaantonov]

You mean process.on("exit"?

[rogierschouten]

Good point

[rogierschouten]

No wait, that means I cannot log the exception to my own logging system anymore and also I cannot flush the logs because process.on("exit" only allows sync actions.

[petkaantonov]

So if you need to do async stuff before the exception can be thrown, it will not be any different from the status quo because while you are waiting for the logs to flush, the unhandled rejection handler will be called and call process.exit

[petkaantonov]

@rogierschouten 3.0.0 will be soon released 2-4 weeks, do you have any input? I think you can synchronously flush logs with writeSync using stdout file descriptor.

Otherwise this will be left as (as it doesn't change anything if you need to flush logs asynchronously) and the next time it can be changed is 4.0.

[rogierschouten]

Hi Petka,

I agree with you, you can throw synchronously.Thank you.

Rogier

[petkaantonov]

Fixed in 3.0 release