Wednesday, July 29, 2009
Announcing Log to Netpanel
This blog post announces a free Firebug extension I wrote, inspired by my visit to the Velocity 2009 conference and especially the workshop by Steve Souders and the talk by (among others) Jan Odvarko on Firebug and its extensibility [end of this video].
When finding performance bottlenecks in web pages, it can be very useful to look at the exact timing of the network traffic from the browser. There is a fair number of tools that helps you doing this. My personal favorite for doing this is the Net panel of Firebug.
Now often, when looking at a web pages loading times, I am especially intrigued by the holes in the graph (see below). These holes are caused by the browser needing time for other activities than downloads from the network. These can be client script parsing, client script running, parsing of HTML, CSS and the like, painting and repainting the screen, and so on. It is hard to guess what exactly the browser is doing in the holes and in this post, I present a Firebug extension that helps you fill in the holes: "Log to Netpanel". This extension can be downloaded here, but is not production ready and you'll have to install it manually.
Tutorial
Our web page is very simple: it contains some external javascript, some inline javascript and very little HTML. Below it the full source code of the page (the external library is actually not used in the page, which is not important for the example): As you can see, the page is very simple, including the jquery 1.3 core library from the Google API service and doing a bit of processing in a loop to create a long string concatenating numbers and spaces. If we load this page, the Firebug NET panel looks like this:
We see the load time of the HTML page and the javascript document. After that comes a considerable hole before the blue vertical line that indicates the DOMDocumentLoad event. So what happens between completely loading the javascript and the end of loading the HTML? A number of options come to mind:
Note that we use the standard console object as provided by Firebug to log information from your script. If you log on the level "debug" and pass "netpanel" as the first argument, the time will be added to the NET panel. In the second argument, you can pass a short descriptive text. If you call the function multiple times with the same text, only one line will show up, spanning the time from the first call until the last.
So if we instrument this page (test here), the NET panel will show something like this:
The timings from javascript combined with the loading times in the NET panel reveal the the hole is mostly spent doing the parsing and evaluating of the javascript. Only a fraction of that time is used concatenating strings and even less in writing it to the document. The time after writing, but before DOMDocumentLoad is presumably spent in rendering/painting.
So what next? The extension has proved itself useful already (to me that is). The code is open sourced under the BSD license (same as Firebug itself). I would like to invite other developers with some problems that need solving.
- I would like to attach the extension to the console.time() function instead of the console.debug(), as the fit seems better. I didn't figure out how to listen for this event though.
- I now add the log lines to the first 'phase' the the Firebug.netProgress object exposes. Not sure if that is right
- In some cases you might want to log even before the first 'real' download is started (this happens when the page itself comes from cache or local file system). This is now impossible. Would like to fix this.
- I could very well imagine that the further development of Firebug will make this extension obsolete eventually.
Enjoy!
Labels: firebug, performance, velocityconf
