Beefy Boxes and Bandwidth Generously Provided by pair Networks
P is for Practical
 
PerlMonks  

comment on

( #3333=superdoc: print w/replies, xml ) Need Help??

We're currently working on an application that is having some performance issues. Some of these issues are significant enough that they're killing the application and simply analyzing the error, access, and event logs has let us know where to turn. Now that we've gotten many of the serious issues out of the way, we still need to improve its performance, but since the application is no longer crashing, no one knew where to look in the logs.

Meetings were getting ugly. Everyone would have some sort of theory as to what was slowing things down.

"It's foo that's killing performance."
"No, it's bar I tell you.

I decided to avoid the arguments and simply start gathering evidence for whatever was going on. I did a little research and discovered Devel::Dprof. I ran it against a program that analyzes Web pages and here's the output I (after running it through dprofpp and asking for the running time of the 15 longest running subs).

Total Elapsed Time = -0.00541 Seconds User Time = 0.299186 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 26.7 0.080 0.169 5 0.0160 0.0338 main::BEGIN 13.3 0.040 0.079 6 0.0067 0.0132 IO::File::BEGIN 10.0 0.030 0.040 3 0.0100 0.0133 HTML::TokeParser::BEG +IN 6.68 0.020 0.030 7 0.0029 0.0043 vars::BEGIN 6.68 0.020 0.030 4 0.0050 0.0074 IO::Seekable::BEGIN 6.68 0.020 0.050 3 0.0067 0.0166 CGI::BEGIN 3.34 0.010 0.010 1 0.0100 0.0100 Exporter::export 3.34 0.010 0.010 1 0.0100 0.0100 warnings::BEGIN 3.34 0.010 0.010 3 0.0033 0.0033 File::Spec::Win32::BE +GIN 3.34 0.010 0.010 6 0.0017 0.0016 IO::Handle::BEGIN 0.00 0.000 0.020 2 0.0000 0.0100 CGI::Util::BEGIN 0.00 0.000 0.010 20 0.0000 0.0005 Exporter::import 0.00 0.000 -0.000 2 0.0000 - warnings::register::i +mport 0.00 0.000 -0.000 4 0.0000 - warnings::register::m +kMask 0.00 0.000 -0.000 1 0.0000 - Exporter::heavy_expor +t

After reviewing results, playing with the code, and rerunning Devel::Dprof several times, I discovered chunks of old debugging code and plenty of code that could be subtly tweaked for a performance boost. In less than a quarter hour I had the following:

Total Elapsed Time = -0.00433 Seconds User Time = 0.191344 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 26.1 0.050 0.060 3 0.0167 0.0199 HTML::TokeParser::BEG +IN 15.6 0.030 0.079 6 0.0050 0.0132 IO::File::BEGIN 10.4 0.020 0.030 4 0.0050 0.0074 IO::Seekable::BEGIN 5.23 0.010 0.010 16 0.0006 0.0006 Exporter::import 5.23 0.010 0.010 1 0.0100 0.0100 IO::bootstrap 5.23 0.010 0.010 28 0.0004 0.0004 main::update_element_ +hash 5.23 0.010 0.010 6 0.0017 0.0017 vars::BEGIN 5.23 0.010 0.009 74 0.0001 0.0001 HTML::TokeParser::get +_tag 5.23 0.010 0.010 11 0.0009 0.0009 main::untainting_rege +xes 5.23 0.010 0.020 3 0.0033 0.0066 File::Spec::Win32::BE +GIN 5.23 0.010 0.070 1 0.0100 0.0697 main::BEGIN 0.00 0.000 -0.000 1 0.0000 - warnings::BEGIN 0.00 0.000 -0.000 1 0.0000 - warnings::register::i +mport 0.00 0.000 -0.000 2 0.0000 - warnings::register::m +kMask 0.00 0.000 -0.000 2 0.0000 - HTML::Parser::BEGIN

This wasn't any of our production code (that's next), but according to elapsed User Time, performance was boosted over 30% -- I ran the before and after results several times to verify the gains. Interestingly, this was code that I had written. I knew it well and I knew that there was little, if anything, that I could optimize.

Boy, was I wrong.

Check out Devel::Dprof next time you have performance issues. It's well worth learning.

Cheers,
Ovid

Vote for paco!

Join the Perlmonks Setiathome Group or just click on the the link and check out our stats.


In reply to Devel::Dprof is your friend by Ovid

Title:
Use:  <p> text here (a paragraph) </p>
and:  <code> code here </code>
to format your post; it's "PerlMonks-approved HTML":



  • Posts are HTML formatted. Put <p> </p> tags around your paragraphs. Put <code> </code> tags around your code and data!
  • Titles consisting of a single word are discouraged, and in most cases are disallowed outright.
  • Read Where should I post X? if you're not absolutely sure you're posting in the right place.
  • Please read these before you post! —
  • Posts may use any of the Perl Monks Approved HTML tags:
    a, abbr, b, big, blockquote, br, caption, center, col, colgroup, dd, del, div, dl, dt, em, font, h1, h2, h3, h4, h5, h6, hr, i, ins, li, ol, p, pre, readmore, small, span, spoiler, strike, strong, sub, sup, table, tbody, td, tfoot, th, thead, tr, tt, u, ul, wbr
  • You may need to use entities for some characters, as follows. (Exception: Within code tags, you can put the characters literally.)
            For:     Use:
    & &amp;
    < &lt;
    > &gt;
    [ &#91;
    ] &#93;
  • Link using PerlMonks shortcuts! What shortcuts can I use for linking?
  • See Writeup Formatting Tips and other pages linked from there for more info.
  • Log In?
    Username:
    Password:

    What's my password?
    Create A New User
    Chatterbox?
    and the web crawler heard nothing...

    How do I use this? | Other CB clients
    Other Users?
    Others wandering the Monastery: (9)
    As of 2020-02-28 16:40 GMT
    Sections?
    Information?
    Find Nodes?
    Leftovers?
      Voting Booth?
      What numbers are you going to focus on primarily in 2020?










      Results (125 votes). Check out past polls.

      Notices?