Hacker News new | ask | show | jobs
by perlgeek 3719 days ago
Here's an example of the result of profiling a a particular page view of a web application: http://moritz.faui2k3.org/tmp/otrs-nytprof/agentticketzoom-n...

The graph at the top shows you which methods took how much time. The wider a bar, the longer it took. So it's immediately obvious that there are two substitutions called from Kernel::Output::HTML::Layout::Output that take up nearly all of the time. That's where you can focus your optimizations on. The other methods only take so much time because they include calls to the offending methods.

You can click on the bars (or the the routines listed below the graph) to get a few of the code, annotated with call counts and time spent on each line.

This is from OTRS, when it still used its home-grown, hacky template system, which is the major offender here. After switching to a proper template system, this is what the same request looks like: http://moritz.faui2k3.org/tmp/otrs-nytprof/agentticketzoom-u...

You can see from the absolute numbers at the top that it's much faster (18.3s -> 2.12s), and there's no single spot anymore where all the time is spent.

It is rather typical that unoptimized code has one or more big time sinks, and profiling makes that obvious.