Implementing a modern JS Logger

I  my last post I’ve talked about using ES decorators in your Js code. This time, I’ll try and implement a fairly simple Js Logger using class and method decorators. The idea is to have a decorator that logs something to the console every time a method is called without having to add the logging code in the method itself.

Let’s start by creating a class that will be used to test our logger.

class Person {
    constructor(name = 'Bob', age = 28){
        this._name = name;
        this._age = age;
    }

    set name(value){
        this._name = value;
    }

    setAge(value){
        this._age = value;
    }
}

Decorators are not allowed on class constructors so if we want to log something every time a new instance of Person is created, we need to decorate the class and wrap the constructor with our custom code.

Let’s create the Log decorator.

function Log(target) {

    // Create a wrapper over original constructor
    const LoggerWrapper = function () {
        // Log something every time a new instance is created
        console.log('A new instance was created');

        // Call the original constructor
        target.apply(this, arguments);
    };

    // Copy the original prototype and constructor function to the new one.
    LoggerWrapper.prototype = Object.create(target.prototype);
    LoggerWrapper.prototype.constructor = target;

    // Return the new constructor.
    return LoggerWrapper;
}

Now if we use the Log decorator on Person class we should see something in the console every time a new instance is created.

@Log
class Person {
    constructor(name = 'Bob', age = 28) {
        this._name = name;
        this._age = age;
    }

    set name(value) {
        this._name = value;
    }

    setAge(value) {
        this._age = value;
    }
}

const firstPerson = new Person(); // A new instance was created
const secondPerson = new Person(); // A new instance was created

So far, so good but this logger is not very useful if we cannot set our custom message. In order to do that, we need to modify our Log decorator to return a function instead of the target class.

function Log(message) {
    return function(target){
        // Create a wrapper over original constructor
        const LoggerWrapper = function () {
            // Log something every time a new instance is created
            console.log(message);

            // Call the original constructor
            target.apply(this, arguments);
        };

        // Copy the original prototype and constructor function to the new one.
        LoggerWrapper.prototype = Object.create(target.prototype);
        LoggerWrapper.prototype.constructor = target;

        // Return the new constructor.
        return LoggerWrapper;
    }
}

Now we can update our Person class to use the new decorator.

@Log('A new instance was created')
class Person {
    constructor(name = 'Bob', age = 28) {
        this._name = name;
        this._age = age;
    }

    set name(value) {
        this._name = value;
    }

    setAge(value) {
        this._age = value;
    }
}

const person = new Person(); // A new instance was created

Everything works exactly like before but now we can specify what message we want to log.

Now that we have this in place, we can replace our console.log with a Logger class and we should also add a logging level parameter.

We start by creating a LogLevel class.

class LogLevel {
    static DEBUG = 0;
    static INFO = 1;
    static WARN = 2;
    static ERROR = 3;
}

A Logger class.

class Logger {
    static log(message, logLevel = LogLevel.INFO) {
        // Use different console methods based on the supplied logLevel. Default is INFO.
        switch (logLevel) {
            case LogLevel.DEBUG:
                console.log(Logger.getFormattedMessage(message));
                break;
            case LogLevel.INFO:
                console.info(Logger.getFormattedMessage(message));
                break;
            case LogLevel.WARN:
                console.warn(Logger.getFormattedMessage(message));
                break;
            case LogLevel.ERROR:
                console.error(Logger.getFormattedMessage(message));
                break;
        }
    }

    // Add the time to the message
    static getFormattedMessage(message) {
        return `[${new Date().toJSON()}] - ${message}`;
    }
}

And finally we update the Log decorator to add the logging level and use our new Logger class.

function Log(message, logLevel) {
    return function(target){
        // Create a wrapper over original constructor
        const LoggerWrapper = function () {
            // Log something every time a new instance is created
            Logger.log(message, logLevel);

            // Call the original constructor
            target.apply(this, arguments);
        };

        // Copy the original prototype and constructor function to the new one.
        LoggerWrapper.prototype = Object.create(target.prototype);
        LoggerWrapper.prototype.constructor = target;

        // Return the new constructor.
        return LoggerWrapper;
    }
}

Now the output should be something like this:

[2016-02-04T16:10:10.795Z] - A new instance was created

Much better isn’t it? The only problem with using console.log to log stuff is that the browser console will tell you that the “logging” happened in Logger.js file (were the console.log is actually called) and not your class constructor. We can easily fix this by also logging the class name.

We need to update the Logger to accept a target parameter.

class Logger {
    static log(message, logLevel = LogLevel.INFO, target) {
        // Use different console methods based on the supplied logLevel. Default is INFO.
        switch (logLevel) {
            case LogLevel.DEBUG:
                console.log(Logger.getFormattedMessage(message, target));
                break;
            case LogLevel.INFO:
                console.info(Logger.getFormattedMessage(message, target));
                break;
            case LogLevel.WARN:
                console.warn(Logger.getFormattedMessage(message, target));
                break;
            case LogLevel.ERROR:
                console.error(Logger.getFormattedMessage(message, target));
                break;
        }
    }

    // Add the time to the message
    static getFormattedMessage(message, target) {
        return `[${new Date().toJSON()}][${target.name}] - ${message}`;
    }
}

and the Log decorator to send that target.

function Log(message, logLevel) {
    return function(target){
        // Create a wrapper over original constructor
        const LoggerWrapper = function () {
            // Log something every time a new instance is created
            Logger.log(message, logLevel, this.constructor);

            // Call the original constructor
            target.apply(this, arguments);
        };

        // Copy the original prototype and constructor function to the new one.
        LoggerWrapper.prototype = Object.create(target.prototype);
        LoggerWrapper.prototype.constructor = target;

        // Return the new constructor.
        return LoggerWrapper;
    }
}

After this our output will be (notice that the class name is now present in the log):

[2016-02-04T16:23:47.321Z][Person] - A new instance was created

All good for now but what if we want to use this decorator to also log something when a class method is called? In order to do this, we need to modifyour Log decorator because a method decorator needs to return the method/property descriptor and not a constructor function.

function Log(message, logLevel) {
    return function () {
        const [target, name, descriptor] = arguments;

        if (!descriptor) {
            // Create a wrapper over original constructor
            const LoggerWrapper = function () {
                // Log something every time a new instance is created
                Logger.log(message, logLevel, this.constructor);

                // Call the original constructor
                target.apply(this, arguments);
            };

            // Copy the original prototype and constructor function to the new one.
            LoggerWrapper.prototype = Object.create(target.prototype);
            LoggerWrapper.prototype.constructor = target;

            // Return the new constructor.
            return LoggerWrapper;
        }
        else {
            // If the annotated method is not a setter or getter
            if (descriptor.value) {
                // save the original method
                const method = descriptor.value;
                // and wrap it with our custom code
                descriptor.value = function (value) {
                    Logger.log(message, logLevel, target.constructor);
                    method.call(this, value);
                };
            }
            return descriptor;
        }
    }
}

Now we can use our awesome decorator on methods also.

@Log('A new instance was created')
class Person {
    constructor(name = 'Bob', age = 28) {
        this._name = name;
        this._age = age;
    }

    set name(value) {
        this._name = value;
    }

    @Log('A new age was set')
    setAge(value) {
        this._age = value;
    }
}

const person = new Person(); // [2016-02-04T16:37:14.109Z][Person] - A new instance was created
person.setAge(20); // [2016-02-04T16:37:14.110Z][Person] - A new age was set

This decorator can be extended further to automatically log the parameters passed to the constructor/method and maybe also print the method name in the logs. This can be done easily because we can use the arguments in the wrapped functions. Do you have any other improvement ideas?

P.S: Try to update the decorator to work with setters also 😛 It needs just a small change.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google+ photo

You are commenting using your Google+ account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

w

Connecting to %s