JavaScript Function Call Profiling


With jQuery 1.3.2 out the door I’ve been looking for more ways to profile and optimize jQuery.

Previously I did a survey of jQuery-using sites to figure out which selectors they were using. This led to the construction of the new Sizzle Selector Engine which targeted those selectors for improvement.

Additionally, I constructed a deep profiling plugin for jQuery which helped to spot methods that were taking a long time to run in live jQuery sites. This helped bring about the improvements in jQuery 1.2.6, 1.3, and 1.3.2.

What do we tackle next? A good place to start would be to tackle optimizing methods that are obviously inefficient – but how do we determine that? One way would be to measure the number of function calls that occur every time a method is run. Firebug provides this information in its profiling data (along with how long it takes to run each method). Unfortunately it’s very clunky to manually type out code, check the results in the console, and determine if they’re bad or if they’ve changed. If only there was a way to progamatically get at those numbers.

FireUnit Profiling Methods

Yesterday I did some work to make getting at the profiling data possible, adding two new methods to FireUnit.

fireunit.getProfile();

Run this method after you’ve run console.profile(); and console.profileEnd(); to get a full dump of the profiling information. For example, given the following profile run:

You’ll get the following JavaScript object returned from fireunit.getProfile():

  1. {
  2.   "time": 8.443,
  3.   "calls": 611,
  4.   "data":[
  5.   {
  6.     "name":"makeArray()",
  7.     "calls":1,
  8.     "percent":23.58,
  9.     "ownTime":1.991,
  10.     "time":1.991,
  11.     "avgTime":1.991,
  12.     "minTime":1.991,
  13.     "maxTime":1.991,
  14.     "fileName":"jquery.js (line 2059)"
  15.   },
  16.   // etc.
  17. ]}

fireunit.profile( fn );

The second method added to FireUnit provides an easy way to execute and profile a single function. Roughly, this method starts the profiler, executes the function, stops the profiler, and then returns the results from getProfile(). Additionally, it watches for any exceptions that might be thrown and makes sure that the profiler is cleanly turned off anyway (a frequent frustration of mine).

You would use it like this:

  1. fireunit.profile(function(){
  2.   document.getElementsByClassName("foo");
  3. });

How To Use

First, you’ll need to be sure to have the latest copy of FireUnit installed. I’ve built a copy of the latest code, into an extension, if you wish to install it:

When running it you’ll need to make sure that:

  1. Both the Console and Script tabs are enabled in Firebug
  2. That the ‘extensions.firebug.throttleMessages’ property in ‘about:config’ is set to ‘false’.

The Results

I put up a test page so that I could quickly run through some jQuery methods to see how they stacked up.

Here are the results of running against jQuery 1.3.2 (“Method” is the jQuery method that was called, with the specified arguments, “Calls” is the number of function calls that occurred when executing the method, “Big-O” is a very rough Big-O Notation for the function calls):

Method Calls Big-O
.addClass(“test”); 542 6n
.addClass(“test”); 592 6n
.removeClass(“test”); 754 8n
.removeClass(“test”); 610 6n
.css(“color”, “red”); 495 5n
.css({color: “red”, border: “1px solid red”}); 887 9n
.remove(); 23772 2n+n2
.append(“<p>test</p>”); 307 3n
.append(“<p>test</p><p>test</p>
<p>test</p><p>test</p><p>test</p>”);
319 3n
.show(); 394 4n
.hide(); 394 4n
.html(“<p>test</p>”); 28759 3n+n2
.empty(); 28452 3n+n2
.is(“div”); 110
.filter(“div”); 216 2n
.find(“div”); 1564 16n

We can immediately see, by looking at the big-O notation, that most jQuery methods execute at least one function for every element that they have to operate against. addClass runs about 6 functions per element, filter runs about 2, and ‘is’ runs only 1.

We can see the problematic functions sticking out like a massive sore thumb: .remove(), .empty(), and .html() – they all run over n2 function calls, which is a huge issue. (These numbers are all large for a simple reason: .html() uses .empty(), .empty() uses .remove(), and .remove() is obviously inefficient.) While function calls do not, necessarily, indicate slow code (a lot of jQuery’s internal functions are pretty lightweight) it is very likely to indicate inefficiently-written code.

I poked around the code for a little bit and realized that .remove() could be dramatically simplified. I filed a ticket and landed a patch which resulted in these much-improved numbers:

Method Calls Big-O
.remove(); 298 3n
.html(“<p>test</p>”); 507 5n
.empty(); 200 2n

I’m really excited by this new tool. Automating the process of code profiling opens up whole avenues of exploration. Even using nothing more than the above tool I can immediately see room for improving just about every jQuery method.

It’s also be very interesting to have this running in some sort of continuous integration setting, to catch any egregious regressions – but I’ll leave that for another day.

Posted: February 23rd, 2009


If you particularly enjoy my work, I appreciate donations given with Gittip.

46 Comments (Show Comments)



Comments are closed.
Comments are automatically turned off two weeks after the original post. If you have a question concerning the content of this post, please feel free to contact me.


Secrets of the JavaScript Ninja

Secrets of the JS Ninja

Secret techniques of top JavaScript programmers. Published by Manning.

Ukiyo-e Database and Search

Ukiyo-e.org

Japanese woodblock print database and search engine.


John Resig Twitter Updates

@jeresig

Infrequent, short, updates and links.