The Perl Toolchain Summit needs more sponsors. If your company depends on Perl, please support this very important event.
NAME
    Devel::Timer - Track and report execution time for parts of code

SYNOPSIS
      use Devel::Timer;

      my $t = Devel::Timer->new();

      $t->mark("first db query");

      ## do some work

      $t->mark("second db query");

      ## do some more work

      $t->mark("end of second db query");

      $t->report();

DESCRIPTION
    Devel::Timer allows developers to accurately time how long a specific
    piece of code takes to execute. This can be helpful in locating the
    slowest parts of an existing application.

    First, the Devel::Timer module is used and instantiated.

      use Devel::Timer;

      my $t = Devel::Timer->new();

    Second, markers are placed before and after pieces of code that need to
    be timed. For this example, we are profiling the methods
    get_user_score() and get_average_user_score().

      $t->mark("first db query");
      &get_user_score($user);

      $t->mark("second db query");
      &get_average_user_score();

    Finally, at the end of the code that you want to profile, and end marker
    is place, and a report is generated on stderr.

      $t->mark("END");
      $t->report();

    Sample report:

      Devel::Timer Report -- Total time: 0.3464 secs
      Interval  Time    Percent
      ----------------------------------------------
      02 -> 03  0.3001  86.63%  second db query -> END
      01 -> 02  0.0461  13.30%  first db query -> second db query
      00 -> 01  0.0002   0.07%  INIT -> first db query

    The report is output using the method Devel::Timer::print() which
    currently just prints to stderr. If you want to send the output to a
    custom location you can override the print() method. The initialize()
    and shutdown() methods can also overridden if you want to open and close
    log files or database connections.

METHODS
  new
    Create a new instance. No parameters are processed.

  initialize
    Empty method. Can be implemented in the subclass.

  mark(NAME)
    Set a timestamp with a NAME.

  print
    Prints to STDERR. Can be overridden in the subclass.

  report
    Prints the report to STDOUT. By default report() looks like this:

      $t->report;

      Devel::Timer Report -- Total time: 7.0028 secs
      Interval  Time    Percent
      ----------------------------------------------
      05 -> 06  3.0006  42.85%  something begin -> something end
      03 -> 04  2.0007  28.57%  something begin -> something end
      06 -> 07  1.0009  14.29%  something end -> END
      01 -> 02  1.0004  14.29%  something begin -> something end
      00 -> 01  0.0000   0.00%  INIT -> something begin
      04 -> 05  0.0000   0.00%  something end -> something begin
      02 -> 03  0.0000   0.00%  something end -> something begin

    Which is great for small or non-iterative programs, but if there's
    hundreds of loops of "something begin -> something end" the report gets
    very painful very quickly. :)

    In that scenario you might find collapse useful:

      $t->report(collapse => 1);

      Devel::Timer Report -- Total time: 7.0028 secs
      Count     Time    Percent
      ----------------------------------------------
             3  6.0018  85.71%  something begin -> something end
             1  1.0009  14.29%  something end -> END
             2  0.0001   0.00%  something end -> something begin
             1  0.0000   0.00%  INIT -> something begin

    The stats for all combinations of labels are added together.

    We also accept a sort_by parameter. By default the report is sorted by
    total time spent descending (like the default report()), but you can
    sort by count descending instead if you want:

      $t->report(collapse => 1, sort_by => 'count');

      Devel::Timer Report -- Total time: 7.0028 secs
      Count     Time    Percent
      ----------------------------------------------
             3  6.0018  85.71%  something begin -> something end
             2  0.0001   0.00%  something end -> something begin
             1  0.0000   0.00%  INIT -> something begin
             1  1.0009  14.29%  something end -> END

  get_stats
    Returns the accumulated statistics for a specific a combination of
    mark()'s that have occurred while your program ran. These values are the
    exact same statistics that report() prints. get_stats() simply returns
    them to you so you can do something creative with them.

    For example, to get the cumulative stats for every time your program has
    specifically moved from mark("X") to mark("Y"), you can run this:

      my ($time, $percent, $count) = $t->get_stats("X", "Y");

    $time is the total number of seconds elapsed between "X" and "Y".

    $percent is the percentage of total program run time that you have spent
    between "X" and "Y".

    $count is the number of times your program has moved from "X" to "Y".

  shutdown
    Empty method. Can be implemented in subclass.

SUBCLASSING
    e.g.

    package MyTimer;

    use strict; use Devel::Timer; use vars qw(@ISA);

    @ISA = ("Devel::Timer");

    sub initialize { my $log = "/tmp/timer.log"; open(LOG, ">>$log") or
    die("Unable to open [$log] for writing."); }

    sub print { my($self, $msg) = @_; print LOG $msg . "\n"; }

    sub shutdown { close LOG; }

    You would then use the new module MyTimer exactly as you would use
    Devel::Timer.

      use MyTimer;
      my $t = MyTimer->new();
      $t->mark("about to do x");
      $t->mark("about to do y");
      $t->mark("done y");
      $t->report();

TO DO
    Devel::Timer does not currently do any reporting or statistics of any
    kind based on nested trees of mark() calls. So if your program runs
    these mark() calls:

      A 
        B, C
        B, C
      D
      E

    Devel::Timer never tells you anything about how much time you spent
    moving from A to D. Depth aware reporting might be an interesting
    project to tackle.

SEE ALSO
    Time::HiRes

COPYRIGHT
    Jason Moore

    This is free software. It is licensed under the same terms as Perl
    itself.

AUTHOR
      Author:      Jason Moore - jmoore@sober.com (no longer valid)
      Maintainer:  Gabor Szabo - gabor@pti.co.il
      Contributor: Jay Hannah  - jay@jays.net