File Coverage

blib/lib/Benchmark/Stopwatch/Pause.pm

Criterion	Covered	Total	%
statement	73	73	100.0
branch	4	4	100.0
condition	1	3	33.3
subroutine	13	13	100.0
pod	7	7	100.0
total	98	100	98.0

use strict;
use warnings;
package Benchmark::Stopwatch::Pause;
use base q{Benchmark::Stopwatch};
our $VERSION = '0.04';

use Time::HiRes;
use Clone 'clone';

=head1 NAME

Benchmark::Stopwatch::Pause - simple timing of stages of your code with a pause option.

=head1 VERSION

Version 0.04

=head1 SYNOPSIS

   #!/usr/bin/perl
   use strict;
   use Benchmark::Stopwatch::Pause;

   # a stopwatch to track the whole run of this script
   my $stopwatch_whole = Benchmark::Stopwatch::Pause->new()->start;

   # a stopwatch to track just select sections of the code
   my $stopwatch_pause = Benchmark::Stopwatch::Pause->new()->start->pause;

   sleep(5);

   foreach (1..3) {
      $stopwatch_whole->lap('new loop ' . $_);
      $stopwatch_pause->unpause('time code ' . $_);
      sleep(2);
      $stopwatch_pause->pause;
      sleep(1);
   }

   print $stopwatch_whole->stop->summary;
   print "---------\n";
   print $stopwatch_pause->stop->summary;

   # NAME                        TIME        CUMULATIVE      PERCENTAGE
   #  start                       5.005       5.005           35.677%
   #  new loop 1                  3.008       8.013           21.440%
   #  new loop 2                  3.008       11.021          21.440%
   #  new loop 3                  3.009       14.030          21.443%
   # ---------
   # NAME                        TIME        CUMULATIVE      PERCENTAGE
   #  start                       0.000       0.000           0.000%
   #  time code 1                 2.004       2.004           33.332%
   #  time code 2                 2.004       4.008           33.332%
   #  time code 3                 2.004       6.012           33.336%

=head1 DESCRIPTION

   This is an extention of the handy Benchmark::Stopwatch module. This is an
attempt to allow very granular timeing of very specific sections of code. The
Stopwatch concept is carried thru in this module, while adding the ability to
pause your stopwatch as needed.

=head1 CHANGES

Things that differ from Benchmark::Stopwatch

=over 4

=item * Laps are now look ahead

The concept of a lap is diffrent from Benchmark::Stopwatch, they are now look ahead.

In Benchmark::Stopwatch :

   # ... code that is tracked by lap 'one'
   $stopwatch->lap('one');

In Benchmark::Stopwatch::Pause :

   $stopwatch->lap('one');
   # ... code that is tracked by lap 'one'

This allows the time from unpause till pause to be tied to your unpause.

=item * _start_ is displayed in the summary

Due to the change in the logic of what a lap is _start_ will be displayed.

=item * _stop_ is not displayed in summary

Due to the change in the logic of what a lap is _stop_ will always be a null event.

=back

=cut

=head1 METHODS

=head2 new

    my $stopwatch = Benchmark::Stopwatch::Pause->new;

Creates a new stopwatch.

=cut

=head2 start

    $stopwatch = $stopwatch->start;

Starts the stopwatch. Returns a reference to the stopwatch so that you can
chain.

=cut

sub start {
   my $self = shift;
   $self->{start} = $self->time;
   $self->lap('_start_');
   return $self;
}

=head2 lap

    $stopwatch = $stopwatch->lap( 'name of event' );

Notes down the time at which an event occurs. This event will later appear in
the summary.

=cut


sub lap {
    my $self = shift;
    my $name = shift;
    my $time = $self->time;

    # This differs from SUPER::lap as it now tracks the pause state
    push @{ $self->{events} }, { name  => $name,
                                 time  => $time,
                                 pause => $self->{pause},
                               };
    return $self;
}

=head2 pause

    $stopwatch = $stopwatch->pause;

Notes the time at which you paused the clock, this has the effect of pausing
the clock. This allows you to track a small portion of repeated code without
worrying about any other code.

=cut

sub pause {
    my $self = shift;
    $self->{pause} = 1;
    return $self->lap('pause');
}

=head2 unpause

    $stopwatch = $stopwatch->unpause( 'name of event' );

unpauses your stopwatch to allow for tracking again.

=cut

sub unpause {
    my $self = shift;
    my $name = shift;
    $self->{pause} = 0;
    return $self->lap($name)
}


=head2 stop

    $stopwatch = $stopwatch->stop;

Stops the stopwatch. Returns a reference to the stopwatch so you can chain.

=cut

=head2 total_time

    my $time_in_seconds = $stopwatch->total_time;

Returns the time that the stopwatch ran for in fractional seconds. If the
stopwatch has not been stopped yet then it returns time it has been running
for.

=cut


=head2 summary

    my $summary_text = $stopwatch->summary;
    -- or --
    print $stopwatch->summary;

Returns text summarizing the events that occured.

=cut

sub summary {
    my $self = shift;
    my $data = $self->as_data;

    my $header_format = "%-27.26s %-11s %-15s %s\n";
    my $result_format = " %-27.26s %-11.3f %-15.3f %.3f%%\n";

    my $out = sprintf $header_format, qw( NAME TIME CUMULATIVE PERCENTAGE);

    foreach my $event (@{ $data->{laps} }) {
        next if $event->{pause};
        $out .= sprintf($result_format,
                        $event->{name},
                        $event->{elapsed_time},
                        $event->{apparent_elapse_time},
                        ($event->{elapsed_time} / $data->{total_effective_time}) * 100,
                       );
    }

    return $out;
}


=head2 as_data

  my $data_structure_hashref = $stopwatch->as_data;

Returns a data structure that contains all the information that was logged.
This is so that you can use this module to gather the data but then use your
own code to manipulate it.

   print Dumper($stopwatch_pause->stop->as_data);

would look like:

   {
     'total_elapsed_time' => '14.0544471740723',
     'laps' => [
                 {
                   'pause_time' => 0,
                   'pause' => undef,
                   'apparent_elapse_time' => '1.59740447998047e-05',
                   'time' => '1179438668.5038',
                   'name' => '_start_',
                   'elapsed_time' => '1.59740447998047e-05'
                 },
                 {
                   'pause_time' => '5.00632405281067',
                   'pause' => 1,
                   'apparent_elapse_time' => '1.59740447998047e-05',
                   'time' => '1179438668.50382',
                   'name' => 'pause',
                   'elapsed_time' => '5.00632405281067'
                 },
                 {
                   'pause_time' => 0,
                   'pause' => 0,
                   'apparent_elapse_time' => '2.00797200202942',
                   'time' => '1179438673.51014',
                   'name' => 'time code 1',
                   'elapsed_time' => '2.00795602798462'
                 },
                 {
                   'pause_time' => '1.0080509185791',
                   'pause' => 1,
                   'apparent_elapse_time' => '2.00797200202942',
                   'time' => '1179438675.5181',
                   'name' => 'pause',
                   'elapsed_time' => '1.0080509185791'
                 },
                 {
                   'pause_time' => 0,
                   'pause' => 0,
                   'apparent_elapse_time' => '4.01593208312988',
                   'time' => '1179438676.52615',
                   'name' => 'time code 2',
                   'elapsed_time' => '2.00796008110046'
                 },
                 {
                   'pause_time' => '1.0080668926239',
                   'pause' => 1,
                   'apparent_elapse_time' => '4.01593208312988',
                   'time' => '1179438678.53411',
                   'name' => 'pause',
                   'elapsed_time' => '1.0080668926239'
                 },
                 {
                   'pause_time' => 0,
                   'pause' => 0,
                   'apparent_elapse_time' => '6.02388095855713',
                   'time' => '1179438679.54218',
                   'name' => 'time code 3',
                   'elapsed_time' => '2.00794887542725'
                 },
                 {
                   'pause_time' => '1.00811719894409',
                   'pause' => 1,
                   'apparent_elapse_time' => '6.02388095855713',
                   'time' => '1179438681.55012',
                   'name' => 'pause',
                   'elapsed_time' => '1.00811719894409'
                 }
               ],
     'stop_time' => '1179438682.55824',
     'start_time' => '1179438668.50379',
     'total_effective_time' => '6.0238881111145'
   };
=cut

sub as_data {
    use List::Util qw{sum};
    my $self = shift;
    my $data = {};

    $data->{start_time} = $self->{start};
    $data->{stop_time}  = $self->{stop} || $self->time;
    $data->{total_elapsed_time} = $data->{stop_time} - $data->{start_time} ;
    $data->{laps}       = [];

    my $laps = clone( $self->{events} );
    push @$laps , { name => '_stop_', time => $data->{stop_time}};

    my $apparent_elapse_time;
    while (scalar(@$laps) > 1 ) {
        my $a = shift @$laps;
        my $b = $laps->[0];

        $a->{elapsed_time} = $b->{time} - $a->{time};
        $a->{pause_time}   = ($a->{pause}) ? $a->{elapsed_time} : 0;
        $apparent_elapse_time += $a->{elapsed_time} - $a->{pause_time};
        $a->{apparent_elapse_time} = $apparent_elapse_time;

        push @{$data->{laps}},$a;
    }

    $data->{total_effective_time} = $data->{total_elapsed_time} - sum( map{$_->{pause_time}} @{ $data->{laps} });

    # ~IF~ you want to have the _stop_ line then uncomment this bit...
    #push @{$data->{laps}},{ %{$laps->[0]},
    #                        pause          => 0,
    #                        pause_time     => 0,
    #                        apparent_elapse_time => $apparent_elapse_time,
    #                        elapsed_time   => $data->{total_effective_time},
    #                      } ;

    return $data;
}


=head2 as_unpaused_data

  my $data_structure_hashref = $stopwatch->as_unpaused_data;

Returns the same data structure as as_data but with out the pause laps.

=cut

sub as_unpaused_data {
   my ($self) = @_;
   my $data = $self->as_data;
   $data->{laps} = [ grep{ ! $_->{pause} } @{ $data->{laps} } ];
   return $data;
}


=head1 AUTHOR

Ben Hengst, C<<  >>

=head1 BUGS

Please report any bugs or feature requests to
C, or through the web interface at
L.
I will be notified, and then you'll automatically be notified of progress on
your bug as I make changes.

=head1 SUPPORT

You can find documentation for this module with the perldoc command.

    perldoc Benchmark::Stopwatch::Pause

You can also look for information at:

=over 4

=item * AnnoCPAN: Annotated CPAN documentation

L

=item * CPAN Ratings

L

=item * RT: CPAN's request tracker

L

=item * Search CPAN

L

=back

=head1 ACKNOWLEDGMENTS

I couldn't have done this extention without Benchmark::Stopwatch,
Thanks so much Edmund von der Burg C<>

=head1 COPYRIGHT & LICENSE

Copyright 2007 Ben Hengst, all rights reserved.

This program is free software; you can redistribute it and/or modify it
under the same terms as Perl itself.

=cut


1;