OSCON 2008: Ultimate Perl Code Profiling

Lunch is over and I’m here to listen to Tim Bunce talk about Ultimate Perl Code Profiling with Devel::NYTProf.

The Devel::DProf module is old and a waste of time and is broken. Stop using it. Take it out and shoot it.

The first obvious distinction between profilers is CPU time versus real time. CPU time tends to be highly granular, but doesn’t include I/O, context switching, or other kinds of blocking. That’s where real time comes in. It’s far more useful in the real world.

Tim, as with many of us, is interested in line-based profiling. It provides a high level of granularity The total subroutine time is not always useful, particularly in larger subroutines.

The NYTProf module is exremely fast, discounting the time taken by profiling overhead, making it quite a bit more useful for real world analysis. It also allows profile times per block, and can be aggregated up to the subroutine level. It’s a module with dual profilers: line-based and subroutine-based.

It gets better, every location that calls the subroutine keeps separate track of the subroutine time. This allows us to determine where the majority of the subroutine calls are coming from. For control flow statements, the decision expression is not taken into account when profiling the block that is executed. This is useful if the loop control itself takes time that should be discounted.

And that’s it for the description. Now we have half an hour to play with it.

The HTML-based reporting is inspired by Devel::Cover‘s reporting. Reported for each file are the number of statements executed, the time spent in the source file and the line, block, and subroutine reports. The subroutine reports include the amount of time spent within the subroutine and the amount of time spent in other called subroutines. The coloring of each line of the report—red, orange, yellow, and green—give a relative measure of deviation from the norm. Very impressive.

Even more impressive, Devel::NYTProf is capable of reporting exactly what a subroutine reference is called, even when it’s an anonymous subroutine compiled within an eval. With a handy link also provided, the called code can be easily inspected.

In summary, Devel::NYTProf is awesome. Use it. I know I will.

Tim Bunce is even more impressive than most people think he is. He is the only presenter I’ve seen so far who has managed to use IRC while giving his talk. Well, he didn’t actually type on IRC, but he had Colloquy running in the background. This particular IRC client uses Apple’s Growl feature to display notifications when you are mentioned in a channel. After he’s opened up the session to questions, one of those notifications pops up on the projected display:

<sirhc> Adam Kennedy (to Tim Bunce): Why are you so awesome?

It got a laugh, and Tim seemed to take it all in stride, even joking that he was not looking very professional on his screen cast. Important safety tip for session presenters, don’t leave your IRC client open.

[tags]oscon, oscon08, oscon2008, Perl, programming, profiling[/tags]

Leave a Reply

Your email address will not be published. Required fields are marked *

*

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong> <pre lang="" line="" escaped="" highlight="">