Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logging before process.exit does not work #1149

Closed
Jokero opened this issue Apr 7, 2015 · 11 comments
Closed

Logging before process.exit does not work #1149

Jokero opened this issue Apr 7, 2015 · 11 comments

Comments

@Jokero
Copy link

Jokero commented Apr 7, 2015

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.

  1. 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 👍

@jshkurti jshkurti self-assigned this Apr 7, 2015
@tamtakoe
Copy link

tamtakoe commented Apr 8, 2015

+1

1 similar comment
@grushikhin
Copy link

+1

@jshkurti
Copy link
Contributor

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.

@Jokero
Copy link
Author

Jokero commented May 21, 2015

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 :)

@soyuka
Copy link
Collaborator

soyuka commented May 21, 2015

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
});

@Jokero
Copy link
Author

Jokero commented May 21, 2015

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

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

@soyuka
Copy link
Collaborator

soyuka commented May 21, 2015

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.

@jshkurti
Copy link
Contributor

nodejs/node#1771 related

@tangxinfa
Copy link

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);
    });
});

@Tjatse
Copy link
Collaborator

Tjatse commented Sep 25, 2015

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

@DQuinn97
Copy link

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants