Dan's CS Thoughts

Shark, for those who don't know, is Apple's profiling tool. You don't need to run in their IDE to use it, which is good... It's impressed me in many ways with both its precision and its versatility, but what it did for me just now was particularly cool.

A website that I run was being slow. So I start up Shark and record a trace as I load the page from my test server, running on the local system. I don't want to assume without checking that the problem is in my code and not in, say, the Apache config causing things to be done in a slower way than necessary, so I tell it to record the whole system.

So it records the whole system and chews on its data and pops up a box informing me that the most-time-consuming function in the most-time-consuming process is Perl_utf8_length, with a self time of 41% of the total userspace time of that process during the sampling period. Hah! After a moment of thought I realize that this just confirms what I suspected anyway, namely that XML::SAX::PurePerl is way too damn slow, but still, it's nice to know that for sure.

But the slick part of all this is in what I didn't have to do. Notice how I didn't tell it the path to my script. In fact I just let it loose on the whole system and it realized that the program that was thinking hardest was probably the one I was most interested in hearing about, so it showed me that one first - with a drop-down menu to see all the others. It wasn't able to decipher the Perl call-stack, only the Perl runtime library, so I couldn't tell the name of the Perl function that was calling Perl_utf8_length, but that's still helpful; it's clearly something parsing-related. And notice also that I didn't have to tell it how to find the debug symbols for that systemwide library. Or even tell it to go fetch them at all; it did that on its own.

One other amusing thing I noticed, although it wasn't useful to me this time. I wondered whether IO operations might be the main expense, so I looked at the special process which is used to account for time spent in kernelspace - and it informed me that something like 90% of kernel time was spent in the library AppleIntelCPUPowerManagement. After a moment of thought, I realized this meant it was sleeping in the idle loop. (I have two CPUs, and parsing is inherently serial, so it can still be idle while working hard.) Pause for a moment to reflect on how slick this is. It wasn't able to get me the symbols from that driver, although it does get symbols from the kernel at large. But it continued its sampling uninterrupted (pardon the pun!), even in kernelspace, even going the extra mile to figure out what driver the PC was in.

Usability and stuff is all great too, but let me tell you, it's things like this that really warm my heart towards Apple.