emisqwe emisqwe - 2 months ago 17
Node.js Question

What does Winston callback actually mean?

I am a beginner in Node js and was wondering if someone could help me out.

Winston allows you to pass in a callback which is executed when all transports have been logged - could someone explain what this means as I am slightly lost in the context of callbacks and Winston?

From https://www.npmjs.com/package/winston#events-and-callbacks-in-winston I am shown an example which looks like this:

logger.info('CHILL WINSTON!', { seriously: true }, function (err, level, msg, meta) {
// [msg] and [meta] have now been logged at [level] to **every** transport.
});


Great... however I have several logger.info across my program, and was wondering what do I put into the callback? Also, do I need to do this for every
logger.info
- or can I put all the logs into one function?

I was thinking to add all of the log call into an array, and then use
async.parallel
so they all get logged at the same time? Good or bad idea?

The main aim is to log everything before my program continues with other tasks.

Explanation of the code above in callback and winston context would be greatly appreciated!

Answer

Winston allows you to pass in a callback which is executed when all transports have been logged

This means that if you have a logger that handles more than one transport (for instance, console and file), the callback will be executed only after the messages have been logged on all of them (in this case, on both the console and the file).

An I/O operation on a file will always take longer than just outputting a message on the console. Winston makes sure that the callback will be triggered, not at the end of the first transport logging, but at the end of the last one of them (that is, the one that takes longest).

You don't need to use a callback for every logger.info, but in this case it can help you make sure everything has been logged before continuing with the other tasks:

var winston = require('winston');
winston.add(winston.transports.File, { filename: './somefile.log' });
winston.level = 'debug';

const tasks = [x => {console.log('task1');x();},x => {console.log('task2');x();},x => {console.log('task3');x()}];

let taskID = 0;
let complete = 0;
tasks.forEach(task => {
    task(() => winston.debug('CHILL WINSTON!', `logging task${++taskID}`, waitForIt));
});

function waitForIt() {
    // Executed every time a logger has logged all of its transports 
    if (++complete===tasks.length) nowGo();
};

function nowGo() {
    // Now all loggers have logged all of its transports
    winston.log('debug', 'All tasks complete. Moving on!');
}

Sure... you probably won't define tasks that way, but just to show one way you could launch all the tasks in parallel and wait until everythings has been logged to continue with other tasks.

Just to explain the example code:

The const tasks is an array of functions, where each one accepts a function x as a parameter, first performs the task at hand, in this case a simple console.log('task1'); then executes the function received as parameter, x();

The function passed as parameter to each one of those functions in the array is the () => winston.debug('CHILL WINSTON!',`logging task${++taskID}`, waitForIt)

The waitForIt, the third parameter in this winston.debug call, is the actual callback (the winston callback you inquired about).

Now, taskID counts the tasks that have been launched, while complete counts the loggers that have finished logging.

Being async, one could launch them as 1, 2, 3, but their loggers could end in a 1, 3, 2 sequence, for all we know. But since all of them will trigger the waitForIt callback once they're done, we just count how many have finished, then call the nowGo function when they all are done.

Compare it to

var winston = require('winston');
var logger = new winston.Logger({
    level:'debug',
    transports: [
        new (winston.transports.Console)(),
        new (winston.transports.File)({filename: './somefile.log'})
    ]
});

const tasks = [x => {console.log("task1");x();},x => {console.log("task2");x();},x => {console.log("task3");x()}];

let taskID = 0;
let complete = 0;
tasks.forEach(task => {
    task(() => logger.debug('CHILL WINSTON!', `logging task${++taskID}`, (taskID===tasks.length)? nowGo : null));
});

logger.on('logging', () => console.log(`# of complete loggers: ${++complete}`));

function nowGo() {
    // Stop listening to the logging event
    logger.removeAllListeners('logging');
    // Now all loggers have logged all of its transports
    logger.debug('All tasks complete. Moving on!');
}

In this case, the nowGo would be the callback, and it would be added only to the third logger.debug call. But if the second logger finished later than the third, it would have continued without waiting for the second one to finish logging.

In such simple example it won't make a difference, since all of them finish equally fast, but I hope it's enough to get the concept.

While at it, let me recommend the book Node.js Design Patterns by Mario Casciaro for more advanced async flow sequencing patterns. It also has a great EventEmitter vs callback comparison.

Hope this helped ;)

Comments