[node.js] Simple Logging in tweeter.js

tweeter.js is a simple OAuth implementation I started working on for a node.js application I had envisioned. The library works, as in it runs through the whole OAuth dance and allows the client to make API calls. There are some more in-depth things I never got around to (like caching the tokens and clearing sessions and whatnot) before I realized I don’t like Twitter. Oh well.

I was just looking through my github repositories and I thought it would be cool to post about the simple logging mechanism I created for tweeter.js. Although not the coolest pattern I used in the project (which probably goes to mixins), I like how simple the solution is. Check out the code for other cool features..

Logging

The cool thing about this logging framework is that it allows you to write out logs to different streams. For instance, suppose you want to write all logging information other than errors to log.txt, but you want to keep errors in errors.txt.

The way I implemented this was to create an object of streams on the Log object. I used getters/setters to provide validation that an object being assigned to one of the properties is actually a stream. Although I didn’t bother with it, this object could possibly be sealed or frozen.

// An object with safe getters/setters for each stream.  
// Streams are:  
// debug, info, error, warn
Log.prototype.streams = {
    get none() { return { write: function() { }}; },
    get debug() { return this._debug; },
    set debug(val) {
        requiresStream(val);
        this._debug = val;
    },
    get info() { return this._info; },
    set info(val) {
        requiresStream(val);
        this._info = val;
    },
    get warn() { return this._warn; },
    set warn(val) { 
        requiresStream(val);
        this._warn = val;
    },
    get error() { return this._error; },
    set error(val) {
        requiresStream(val);
        this._error = val;
    }
}

Because this is written for node.js, requiresStream() verifies the value is an instance of EventEmitter with a write function.

Defaults for these streams are set in the constructor with a default logLevel of -1 (disabled).

var Log = module.exports = exports = function Log(level) {
    // default error to stderr and the rest to stdout
    this.streams.debug = process.stdout;
    this.streams.info = process.stdout;
    this.streams.warn = process.stdout;
    this.streams.error = process.stderr;

    // default the logLevel to disabled
    this.logLevel = level || -1;
}

An interesting thing about this logger is how I make the calling convention flexible. I use .NET regularly and I would call a logging function in .NET with an enum value to specify the logLevel. I wanted a similar functionality in this logger, so I created a lookup object to map a key (i.e. DEBUG) to a logLevel (0) and a stream (debug).

// [DISABLED] else [DEBUG > INFO > WARN > ERROR]
Log.prototype.logLevels = {
    DISABLED:   { value: -1, stream: 'none' },
    DEBUG:      { value: 0, stream: 'debug' },
    INFO:       { value: 1, stream: 'info' },
    WARN:       { value: 2, stream: 'warn' },
    ERROR:      { value: 3, stream: 'error' }
}

I considered accessing these on the streams object directly, but did it this way for readability and flexibility. A major deciding factor in choosing this route was the ability to reorder logging levels in a single place in the code.

// ## log(level msg);
// logs the output with a nice colorful indicator of the stream.  
// `msg` may be a string or a formattable string and options.
Log.prototype.log = function(level, msg) {
    var original = level;
    try {
        if(typeof level === 'string'){
            level = this.logLevels[level.toUpperCase()];
        }
        // get logLevel value
        if( (this.logLevel > -1) && (level.value >= this.logLevel) ) {
            var stream = this.streams[level.stream];
            stream.write( util.format.call(this, '[\033[%sm%s\033[39m]\t', colors[level.value], level.stream) );
            stream.write( util.format.apply(this, slice.call(arguments,1) ) + '\n');
        }
    } catch (err) { 
        console.error("logging is improperly configured!\nIs %j a supported logLevel?\nError:\n%j\n",original, err);
    }
}

An example

I’ve uploaded an example to github.

In this example, I write out logs for each of the 4 supported levels. The default is to write these out to stdout. After writing to the defaults, I set

var Log = require('./log.js'),
    fs = require('fs');

var level = process.argv[2] || 1;
var logger = new Log(level),
    level = logger.logLevels;

logger.log(level.DEBUG, "This is a debug message");
logger.log(level.INFO, "This is an info message");
logger.log(level.WARN, "This is a warning message");
logger.log(level.ERROR, "This is an error message");

var debugStream = fs.createWriteStream('./debug.txt');
var infoStream = fs.createWriteStream('./info.txt');
var warnStream = fs.createWriteStream('./warn.txt');
var errorStream = fs.createWriteStream('./error.txt');

logger.streams.debug = debugStream;
logger.streams.info = infoStream;
logger.streams.warn = warnStream;
logger.streams.error = errorStream;

logger.log(level.DEBUG, "This is a debug message");
logger.log(level.INFO, "This is an info message");
logger.log(level.WARN, "This is a warning message");
logger.log(level.ERROR, "This is an error message");

debugStream.end();
infoStream.end();
warnStream.end();
errorStream.end();

This provides the following input when passing a log level in via the command line:

Flattr this!