CODEWITHSUNDEEP
javascriptnode.jsloggingwinston
NickW
NickW

Reputation: 1343

Node logging uncaught exception (Winston V3)

I'm new to Winston, and I'm trying to use it to log uncaught exceptions and then exit. It is logging to the console, but doesn't seem to have time to log to a file before exiting

Here is an example:

index.js

const express = require('express');
const app = express();
const logger = require('./startup/logging');

process.on('uncaughtException', (ex) => {
    logger.error("Won't be logged in the File");
    process.exit(1);
});

throw new Error("Uncaught");

logging.js

const { createLogger, format, transports } = require('winston');

const logger = createLogger({     
    format: format.combine(
        format.timestamp({
            format: 'YYYY-MM-DD hh:mm:ss |'
        }),
        format.printf(info => `${info.timestamp} ${info.level}: ${info.message}`)
    ),
    transports: [
        new transports.Console({
            format: format.combine(
                format.colorize({
                    // all: true
                }),
                // this is repeated because for some reason colorize() won't work otherwise
                format.printf(info => `${info.timestamp} ${info.level}: ${info.message}`)            
            )
        }),
        new transports.File({ filename: './exceptions.log' })
    ]
});

module.exports = logger;

As mentioned, the uncaught exception is logged to the console, but not to the file. Removing process.exit(1) solves the problem of logging, but I do want the program to exit.

Adding handleExceptions: true to the File transport causes the same issue - it exits prior to logging the exception. I'm assuming this is the cause, as adding exitOnError: false then logs the exception.

Is this the intended behaviour? It seems strange to me, even as a beginner.

EDIT: 

process.on('uncaughtException', (ex) => {
    logger.log('error', 'Will be logged');
    setTimeout(function(){process.exit(1)}, 1000);
});

This works, but surely isn't a fix, just shows the problem i'm having

Upvotes: 3

Views: 3656

Answers (3)

NickW
NickW

Reputation: 1343

A good read on the problem spanning 2013 to date.

https://github.com/winstonjs/winston/issues/228

There are various work arounds mentioned, but it doesn't look like this is ever going to be fixed. Which is annoying. Going to look at log4js-node instead, which has apparently addressed this.

Upvotes: 1

dm03514
dm03514

Reputation: 55972

logging.error is probably an IO (async) operation and yields after invocation:

process.on('uncaughtException', (ex) => {
    logger.error("Won't be logged in the File"); # registers operation with node event loop and continues
    process.exit(1);
});

The node documentation shows a synchronous write but I am not sure of how to plug this in to winston:

process.on('uncaughtException', (err) => {
  fs.writeSync(1, `Caught exception: ${err}\n`);
  process.exit(1)
});

Upvotes: 1

Nick Cox
Nick Cox

Reputation: 6472

What version are you using? In v2 you could use a callback that executes after the log entry has been written.

process.on('uncaughtException', (ex) => {
    logger.error("Will be logged in the File", function() {
        process.exit(1);
    });
});

In v3 you're supposed to do:

logger.log('info', 'some message');
logger.on('finish', () => process.exit());
logger.end();

Upvotes: 1

Related Questions