Performance logging in Chrome

perflog

function perfLog(fun, context) {
	var context = context || this;
	var realFun = context[fun.name];
	context[fun.name] = function() {
		console.time(fun.name);
		var result = realFun.apply(context, arguments);
		console.timeEnd(fun.name);
		return result;
	}
}

//How to use
perfLog(eval);
perfLog(document.body.appendChild, document.body);

Cool idea to do logging on existing methods and native APIs! This AOP-ish way of doing it can also easily be extended to have a debug-flag or regex-pattern where can filter out different log-statments to easier drill down on specific log-messages (all though you can have this functionality in for instance Developer Tools in Chrome).

In many cases, though, in the current JS implementation this wouldn't give expected result. Actually, you might end up overriding a lot of methods and re-naming them as empty string. Let's say we have an object literal:

var o = {
   foo: function () {
      // some implementation
   }
};

The name of o.foo in this case would be "" (empty string). This is due to the function being name-less (anonymous). Doing this, however, would work:

var o = {
   foo: function foo () {
      // some implementation
   }
};

Never fear, ECMAScript 6 to the rescue! In the new spec this is handled much better, as name is much more formalised (see this article: http://bocoup.com/weblog/whats-in-a-function-name/). This means that the code above would work as expected, and even:

var foo = function () { };
foo.name; //=> "foo"

Until then it might be a good idea to add a warning to the function:

function perfLog(fun, context) {
    context = context || this;
    if (!fun.name) {
        console.warn('No name found. Dropping performance logging for function:\n', fun.toString());
        return void 0;
    }
    var realFun = context[fun.name];
    return context[fun.name] = function() {
        console.time(fun.name);
        var result = realFun.apply(context, arguments);
        console.timeEnd(fun.name);
        return result;
    }
}

//How to use
perfLog(eval);
perfLog(document.body.appendChild, document.body);

That being said, this is probably not a side-effect you would want in production code, as it can affect things way outside your own code base and third party code. 😄

Maybe a more boring approach, but yet traditional:

function perfLog(fn) {
    var name = fn.name || "anon function";
    return function() {
        console.time(name);
        var result = fn.apply(this, arguments);
        console.timeEnd(name);
        return result;
    }
}

document.body.appendChild = perfLog(document.body.appendChild);

This might not look as smooth, but it works with anonymous methods/functions 👔

> var o = { foo : function () { console.log(this.bar);}, bar : "Hello" };
< undefined
> o.foo = perfLog(o.foo);
< function () {
        console.time(name);
        var result = fn.apply(this, arguments);
        console.timeEnd(name);
        return result;
    }
> o.foo();
   "Hello"
   "anon function: 0.320ms"
< undefined

Wow @mikaelbr. That's awesome feedback! Thanks!