Node.js real time logging with Winston, Redis and, p1

After I had the chance to hack some bugs on Firefox I noticed that they had a very strong logging system built in the project which made the act of logging stuff very easy and standardize.

A few built in logging macros that is very common to see across Firefox code are:


The complete list of macros can be found here

Keeping that in mind I thought it would be beneficial to implement something similar in the WebVirt project.
It not only helps developers to spot bugs and keep track of old issues that were appearing in the application, but it also helps users to have a direct access to the server logs, without the need to dig deep through several directories to find one text file with thousands of logs which makes very difficult to get any useful information out of it.

So the basic idea was to have different levels of logs, to make them more granular and provide a simple interface to allow users and developers to use the logs as a debugging tool.

Winston Logging Library

If you are working with Node.js there is a very solid library that is well maintained and used across several projects, the library being winston.

The beauty of winston it is the flexibility and the power it provides.
A quick overview on winston:

You can create different “Transports”, which are the final location where your logs are stored.
So it is possible to log everything to a database, the console and to a file at the same time.

There is support for metadata on a per log basis. Which can be very useful to add extra information about an error that you might be logging.

Querying Logs
Another functionality that is built in the library is the querying of existing logs.
Independently of the Transport you might be using to save your logs, winston can query all the logs and provide them to you in json format with all the metadata tags parsed.

Streaming Logs
This is a very handy feature if you are planning to implement a real time logging solution with web sockets for example.

After looking at all the features winston provided it was a no brainier to start leveraging its power instead of writing a new one from scratch.

So now lets get into the details of how winston is working on WebVirt.

WebVirt Custom Logger

First of all we created a CustomLogger module which wraped winston giving us the flexibility to play around with the CustomLogger implementation without breaking the whole system since we can keep the logger API constant through out the app.

var _logger;

var CustomLogger = function (config) {

CustomLogger.prototype = new events.EventEmitter(); = function (msg, metadata) {

CustomLogger.prototype.warn = function (msg, metadata) {

CustomLogger.prototype.error = function (msg, metadata) {

CustomLogger.prototype.query = function (options, cb) {

module.exports.inject = function (di) {
  if (!_logger) {
    _logger = new CustomLogger(di.config.logger);
  return _logger;

The CustomLogger implements a Singleton pattern which only instantiate one object for the whole app.
We allow a set of custom dependencies to be injected on the module which gives us even more flexibility to move things around without the risk of coupling them together.
We are also extending the EventEmitter functionality to give the options for the CustomLogger to emit its own events to whoever chooses to listen, that could be one option to implementing a real time web socket logging system but later on I’ll show that there is an easier way.
Finally, we just defined all methods we want to make publicly available on the logger.

After creating the skeleton for our CustomLogger we started to integrate winston in it.

var CustomLogger = function (config) {

  winston.handleExceptions(new winston.transports.Redis());
  winston.exitOnError = false;

  winston.add(winston.transports.Console, {
      handleExceptions: true,
      json: true
} = function (msg, metadata) {, metadata);

CustomLogger.prototype.warn = function (msg, metadata) {
  winston.warn(msg, metadata);

CustomLogger.prototype.error = function (msg, metadata) {
  winston.error(msg, metadata);

As you can see it’s very straight forward, the CustomLogger info, warn and error methods make a direct call to winston.
To initialize winston we require the winston-redis lib, which exposes the Redis Transport for Winston.
This leads me to the next topic:

Winston Redis Transport

Since we are already using Redis to store user information as well host details we chose to use Redis to store the logs too.
The winston-redis module is very easy to use and works out of the box, however, it didn’t fit the exact idea I had about the logging system of WebVirt.

We wanted to display different levels of logs to the user directly in the browser, however, we would need to have some sort of pagination control since the number of logs could go up to the thousands depending on the usage.
Not only that, we would also want to be able to search all logs of a particular level and also have a real time feature built in to display the logs with a websocket on the browser and even set some triggers to send some emails or any sort of notification based on pre-set filters.

With that being said, winston-redis saves all logs, independently of their level, to a single list on redis:

Screen Shot 2013-03-18 at 4.15.02 PM

So the ability to search and paginate the logs based on their level would be lost since they are all living in the same list.

To fix this issue and save logs on separate lists based on their levels we forked the lib and added an option to set a namespace for the redis container:

Redis.prototype.log = function (level, msg, meta, callback) {
  var self = this,
      container = this.container(meta),
      channel = &&;

  // Separate logs based on their levels
  container += ":" + level;
  this.redis.llen(container, function (err, len) {
    if (err) {
      if (callback) callback(err, false);
      return self.emit('error', err);
    // Assigns an unique ID to each log = len + 1
    var output = common.log({
      level: level,
      message: msg,
      meta: meta,
      timestamp: self.timestamp,
      json: self.json,

    // RPUSH may be better for poll-streaming.
    self.redis.lpush(container, output, function (err) {
      console.log("lpush callback");
      console.log("err: ", err);
      if (err) {
        if (callback) callback(err, false);
        return self.emit('error', err);

      self.redis.ltrim(container, 0, self.length, function () {
        if (err) {
          if (callback) callback(err, false);
          return self.emit('error', err);

        if (channel) {
          self.redis.publish(channel, output);

        // TODO: emit 'logged' correctly,
        // keep track of pending logs.

        if (callback) callback(null, true);

The only difference is that instead of logging everything to to a single “container” we append the level of the log to the “container”, thus splitting the logs into different lists:

Screen Shot 2013-03-18 at 4.15.36 PM

Now when we need to retrieve the logs we can specify how many and on which list we want to perform the query:

CustomLogger.prototype.query = function (options, cb) {
  var start = options.start || 1
    , rows = options.rows || 50
    , type = options.type || 'redis'
    , level = options.level || 'error';

    'start': +start,
    'rows': +rows,
    'level': level
  }, function (err, data) {
    cb(err, data.redis);

Something to keep in mind is that winston.query searches all Transports you have registered.
So if you are logging to multiple transports make sure you only use one Transport when reading the data back or you’ll get repeated values.

This sums it up the first part of the post.
Next I’ll post about how to integrate Socket.IO with Winston and stream logs real time to a browser.