When in Trouble, Draw a Picture

Graphs

Note: the following graphs broke on the nightlies this week. I would appreciate help with reducing this to a proper testcase. They work fine on older nightlies and released versions of Firefox. Non-spidermonkey JS engines wont work as they don’t support destructuring assignment and other goodies.

Once I graphed my file-access logs, most of my problems became clear. Here is the first graph(screenshot). The y-axis is time; once you click on a square, x-axis is the file offset. One can clearly see that libxul (4th rectangle) is a big chunk of our io. It’s also clear that initially the file is being accessed in the begining and near the end. One can also see that there is a some “backwards” io. It’s ugly stuff.

I first saw this picture on Friday evening, I spent the last 2 days trying to make libxul.so load less stupidly. Here is a graph(screenshot) from a hack I tried this morning (approach b in the bug) . The top is still stupid, but near the bottom, libxul is being read in a much more efficient manner (>50% less io).

This graph is from a lunch-time hack(approach c). IO is being spread across two processes so it’s evading my systemtap script forĀ  now. Fortunately, “approach c” also shaved off a second of my startup time, so I know the libxul graph would’ve been real pretty.

What follows is a story of how I ended up graphing stuff; more on lessons learned later…

Story

Last week I was about to give up and live with a meager 10% win on libxul.so cold startup. I just couldn’t squeeze any more useful ideas out of my timing and io logs. I reached out to Jim Blandy, who confirmed that things seemed to be working as expected (unlike me, Jim actually knows this stuff).

Upon hearing of my quest, surprising number of people strongly suggested that I chat with Michael Meeks. He was digging around in the binary cesspool for OpenOffice recently and asked many of the same questions. We had a fun conversation, where Michael proved me wrong. I said I couldn’t imagine a useful way to graph the file io logs. In response Michel, dug up this beauty. He built it with a fun mix of valgrind + c#.

Feeling massive diagram envy, I decided that I had to get an interactive graph of my SystemTap data. A brief Google search revealed that RaphaelJS would be awesome for my needs (the most j***worthy vector gfx library ever). After many happy hours of messing with with pretty graphics and colours, the ugly truth emerged (hint: it’s about the linker/kernel relationship). More on that soon.

3 comments

  1. This may be ignorant, but have you tried using the gold binutils linker? It’s supposed to be noticeably faster for c++ apps.

  2. The graph bustage started with the TM merge in http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=ddfecbc93934&tochange=a29d44f196a6

    Please get a bug filed?