Pm2: Logging before process.exit does not work

Created on 7 Apr 2015  路  11Comments  路  Source: Unitech/pm2

OS - Ubuntu 14.04.1 LTS
Node.js - 0.12.0
pm2 - 0.12.9

Sample code:

setTimeout(function() {
    throw new Error('Something went wrong!');
}, 1000);

process.on('uncaughtException', function(err) {
    console.error('PROCESS uncaughtException: ' + err.message);
    console.error('stack:', err.stack);

    process.exit(1);
});

Run code in cluster mode (1 instance).

1) Logs with process.exit:

Error: Something went wrong!
    at null._onTimeout (/home/dmitry/dev/app.js:53:11)
    at Timer.listOnTimeout (timers.js:110:15)

There are no my "uncaughtException" messages.

2) Logs without process.exit:

Error: Something went wrong!
    at null._onTimeout (/home/dmitry/dev/app.js:53:11)
    at Timer.listOnTimeout (timers.js:110:15)
2015-04-07 13:48:19: PROCESS uncaughtException: Something went wrong!
2015-04-07 13:48:19: stack: Error: Something went wrong!
    at null._onTimeout (/home/dmitry/dev/app.js:53:11)
    at Timer.listOnTimeout (timers.js:110:15)

All is good :+1:

Most helpful comment

No idea if it's still useful to comment; but I fixed it by simply doing
process.nextTick(function() {setTimeout(process.exit, 5000);});
I couldn't get it to work any other (simple) way, not even without the setTimeout withing the nextTick..

Just throwing it out there for those who couldn't find an answer, because I know I searched a long while and then half stumbled upon an answer here, but it still didn't properly work with just that.

All 11 comments

+1

+1

This is the most mysterious bug I have came across in ages.
I've been testing around a bit and I noticed that the console.log/error in the uncaughtException listener function are ... asynchronous o_O
It means process.exit(1) is called before the console.logs have finished.
I honestly have no clue how this is possible and why does it happen in this particular case.

I did some more tests with code:

setTimeout(function() {
    throw new Error('Something went wrong!');
}, 1000);

process.on('uncaughtException', function(err) {
    console.error( // console.log
        'Process uncaughtException:', err.message, '\n',
        'Stack:',                     err.stack
    );

    process.exit(1);
});

If I use console.log the logs are written to the file. But console.error does not work :)

Try this:

setTimeout(function() {
    throw new Error('Something went wrong!');
}, 1000);

process.on('uncaughtException', function(err) {
    console.error('Process uncaughtException:', err.stack) //stack does contain message FYI

    process.nextTick(function() { process.exit(1) }) // delaying it with a timeout should also work
});

It's working, but some new examples :)
1)

console.log('You will see only this log message');

process.nextTick(function() {
    console.log('You will not see this log message');
    console.error('You will see this error message');
    process.exit(1);
});

out.log: You will see only this log message
You will not see this log message was dropped.

err.log: You will see this error message

2)

console.error('You will see only this error message');

process.nextTick(function() {
    console.log('You will see this log message');
    console.error('You will not see this error message');
    process.exit(1);
});

out.log: You will see this log message

err.log: You will see only this error message
You will not see this error message was dropped.

So in case of uncaughtException pm2 writes to stderr and my console.error does not work

Those are normal behaviors. By calling process.exit the process is being killed and therefore it's stds streams are closed. If you're lucky, because exit is async, stream might not be closed by the time that console. writes to it.

I haven't understand your second example, console.error is supposed to write to stderr. I'd add that those kind of things have nothing to do with pm2.

Fix this problem with a little hack, this works good:

process.on('uncaughtException', function(e) {
    console.error(e.stack);

    /// Makesure error outputed before process exit.
    process.stderr.write('', function () {
        process.exit(1);
    });
});

鈥楥ause console is async, you guys can reference to my PR - how to exit process smoothly:
commit/3afad15fa0e47d77269a59179df5863cc67dc8fc

No idea if it's still useful to comment; but I fixed it by simply doing
process.nextTick(function() {setTimeout(process.exit, 5000);});
I couldn't get it to work any other (simple) way, not even without the setTimeout withing the nextTick..

Just throwing it out there for those who couldn't find an answer, because I know I searched a long while and then half stumbled upon an answer here, but it still didn't properly work with just that.

Was this page helpful?
0 / 5 - 0 ratings

Related issues

xzycn picture xzycn  路  3Comments

shaunwarman picture shaunwarman  路  3Comments

alexpts picture alexpts  路  3Comments

mario-mui picture mario-mui  路  3Comments

ghost picture ghost  路  3Comments