Logging in Node.js with winston

Logging in Node.js with winston

·

5 min read

Node.js does not provides a built-in logging tool, so we need to use some third party packages to do this. The package winston is a pretty popular and powerful tool for logging. Let's see its usage in this article.

Hello world

First, install this package.

npm i winston

Then, we can log like below.

var winston = require("winston");
winston.log("info", "Hello world!");

Create new logger

In above hello world example, we log messages directly using winston package. This is done by the default winston logger. The recommended way is to create our own logger.

Below code I copy from the winston documentation, which shows the basic usage about how to create our own logger and use it to logger messages.

const winston = require('winston');

const logger = winston.createLogger({
    level: 'info',
    format: winston.format.json(),
    defaultMeta: { service: 'user-service' },
    transports: [
        //
        // - Write all logs with importance level of `error` or less to `error.log`
        // - Write all logs with importance level of `info` or less to `combined.log`
        //
        new winston.transports.File({ filename: 'error.log', level: 'error' }),
        new winston.transports.File({ filename: 'combined.log' }),
    ],
});

//
// If we're not in production then log to the `console` with the format:
// `${info.level}: ${info.message} JSON.stringify({ ...rest }) `
//
if (process.env.NODE_ENV !== 'production') {
    logger.add(new winston.transports.Console({
        format: winston.format.simple(),
    }));
}

Now let's use this new logger.

logger.info("this is info message");
logger.error("this is error message");

Then we should see a combined.log file containing below messages.

{"level":"info","message":"this is info message","service":"user-service"}
{"level":"error","message":"this is error message","service":"user-service"}

And a error.log file containing below messages.

{"level":"error","message":"this is error message","service":"user-service"}

Log level

This winston package use below log levels with a descending importance from error to silly.

// from most important to least important
const levels = {
  error: 0,
  warn: 1,
  info: 2,
  http: 3,
  verbose: 4,
  debug: 5,
  silly: 6
};

So with these levels, we can log with below 2 ways.

// first argument as logger level
logger.log("info", "hello world1");

// or use the level name as method name
logger.info("hello world1");

The point of logger level is that with tagging each messages a level, we can use different stategy to handle messages. For example, with below config, all 3 messages will be written into console, but only the error message will be written into the file.

const winston = require('winston');

const logger = winston.createLogger({
    level: "info",
    transports: [
        new winston.transports.File({ filename: 'error.log', level: 'error' }),
        new winston.transports.Console()
    ],
});

logger.info("hello info");
logger.warn("hello warn");
logger.error("hello error");

Format

A seperate package logform is used to control logging format. For example, if we want to add timestamp manually to each log message, we can create a formatter like below.

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

const timestampFormatter = format(info => {
    info.now = Date.now();
    return info;
});

const logger = createLogger({
    format: format.combine(
        timestampFormatter(),
        format.json() // this is important, to finally serialize the info object into string
    ),
    transports: [new transports.Console()]
});

logger.info("hello world");
// {"level":"info","message":"hello world","now":1663921275116}

The key is to pass a transform function to format function, and it will return a new formatter. Then run this formatter to get an instance and pass it to the new logger.

Inside the transform function, we can also return a false value, then this message will be filtered out.

const timestampFormatter = format(info => {
    if (info.private) return false;
    info.now = Date.now();
    return info;
});

// ...

logger.info("1111", { private: true }); // this message will not be filtered
logger.info("2222", { private: false });

The package logform already provides a lot of useful method to help configuring the output format. For example, we can use timestamp to add timestamp infomation, use label to add a speical label, and use printf to format the final message, etc.

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, label, printf } = format;

const myFormat = printf(({ level, message, label, timestamp }) => {
  return `${timestamp} [${label}] ${level}: ${message}`;
});

const logger = createLogger({
  format: combine(
    label({ label: 'right meow!' }),
    timestamp(),
    myFormat // this is our own final formatter
  ),
  transports: [new transports.Console()]
});

Transports

Transports are used to specify the destinations of logging messages. Just as we already saw, we can use winston.transports.File to pass messages to a file, and winston.transports.Console to pass messages to stardard output. There are also other options, for example, we can pass message to a http endpoint, DailyRotateFile, etc. We can see a full list in this repo.

Below example shows how to pass messages to mongodb.

const winston = require('winston');

/**
 * Requiring `winston-mongodb` will expose
 * `winston.transports.MongoDB`
 */
require('winston-mongodb');

logger.add(new winston.transports.MongoDB(options));

We can also write our own transport, code demo is like below.

const Transport = require('winston-transport');
const util = require('util');

//
// Inherit from `winston-transport` so you can take advantage
// of the base functionality and `.exceptions.handle()`.
//
module.exports = class YourCustomTransport extends Transport {
  constructor(opts) {
    super(opts);
    //
    // Consume any custom options here. e.g.:
    // - Connection information for databases
    // - Authentication information for APIs (e.g. loggly, papertrail,
    //   logentries, etc.).
    //
  }

  log(info, callback) {
    setImmediate(() => {
      this.emit('logged', info);
    });

    // Perform the writing to the remote service
    callback();
  }
};

Handling exceptions

We can set up a handler when creating loggers to handle exceptions when logging.

const logger = createLogger({
  transports: [
    new transports.File({ filename: 'combined.log' })
  ],
  exceptionHandlers: [
    new transports.File({ filename: 'exceptions.log' })
  ]
});

By default, winston will exit after logging an uncaughtException. If we want to prevent this behavior, we can set exitOnError to false.

const logger = winston.createLogger({ exitOnError: false });

For asynchronize operations like promises, we can set the rejectionHandlers to catch this kind of rejections.

const logger = createLogger({
  transports: [
    new transports.File({ filename: 'combined.log' })
  ],
  rejectionHandlers: [
    new transports.File({ filename: 'rejections.log' })
  ]
});