Perf/Stopwatch version 0.10 =========================== INSTALLATION To install this module type the following: perl Makefile.PL make make test make install DEPENDENCIES This module requires these other modules and libraries: Time::HiRes NAME Perf::Stopwatch - A Simple Time Management module SYNOPSIS use Perf::Stopwatch qw( :normal :burst ); $sw_norm = new Perf::Stopwatch(); $sw_burst = new Perf::Stopwatch( type=> "burst" ); $sw_norm->start(); for( $i=0; $i<$max_iter; $i++ ){ $sw_burst->start(); # do something... $sw_burst->stop(); # do some more... } $sw_norm->stop(); $elapsed1 = $sw_norm->getTime(); $elapsed2 = $sw_burst->getTime(); use Perf::Stopwatch qw( :lap ); $sw_lap = new Perf::Stopwatch( type => "lap", laps => $max_iter ); for( $i=0, $sw_lap->start(); $i<$max_iter; $i++ ){ # do something ... $sw_lap->lap(); } $elapsed3 = $sw_lap->getTime(); @all_laps = @{$sw_lap->getLaps()}; $num_laps = $sw_lap->numLaps(); $min_lap = $sw_lap->getMinLap(); $max_lap = $sw_lap->getMaxLap(); $avg_lap = $elapsed / $num_laps; DESCRIPTION The three types of Stopwatches are "normal", "burst", and "lap". A "normal" Stopwatch has only "start()" and "stop()" abilities and "getTime()" returns the difference between these two times. A "burst" Stopwatch uses the "start" and "stop" as well, but does not reset the time with every call, but keeps a cumulative time difference. Such as stop1-start1 + stop2-start2 + ... = final. This is useful for measuring a part of the loop without calculating the overall time of the loop, as in "normal" and "lap", thus allowing you to diagnose which portion of the loop is causing the slowdown. A "lap" Stopwatch uses "start()" and "lap()" to mark intervals in the overall time. This is useful for getting statistics on minimum, maximum, and average loop times so you can determine best-case, worst-case, and average-runs on sections of code. Uses Time::HiRes to calculate the most accurate results within fast loops new( type => ("normal"|"lap"|"burst"), [laps => N] ) Creates a Stopwatch object of type "type" if specified, with a default type of "normal". You may also give a number of laps to optimize the array handling, the default number of laps is 100. start() Starts the Stopwatch, or (code-wise) saves the current time in a local 'start' reference. stop() Stops the Stopwatch, or (code-wise) saves the current time in a local 'stop' reference, and does the following based on type of Stopwatch. If "normal", saves the difference of the start and stop. If "burst", calculates the difference and adds it to the running total. If "lap", saves the difference as the current lap and increments lap counter. lap() Records a lap time, or (code-wise) saves the difference as the current lap and increments lap counter. clear() Resets the running total to 0. Useful when using a "burst" Stopwatch and want to re-use the same object for another area of the script. getTime() Returns the time value of the Stopwatch to the 6th decimal place (10e-6) or in microseconds, the smallest time unit available to Time::HiRes. numLaps() Returns the number of laps actually executed. Useful for when you exit a loop before you pre-declared number of laps is completed. getLaps() Returns a reference to the lap-array with a size of the pre-declared number of laps, or more if you ran over. Use "numLaps()" to finde the final valid index of the lap-array. getMaxLap() Returns the maximum time found on the lap-array. getMinLap() Returns the minimum time found in the lap-array. EXAMPLE use strict; use Perf::Stopwatch qw( :all ); my $max = @ARGV ? shift @ARGV : 500; my $nrm = new Perf::Stopwatch( type => "normal" ); my $brs = new Perf::Stopwatch( type => "burst" ); my $lap = new Perf::Stopwatch( type => "lap", laps => $max ); my( $i, $j, $x, $y ); $nrm->start(); $lap->start(); for( $i=0; $i<$max; $i++ ){ while( int(rand()*1000) < 975 ){ $brs->start(); for( $j=0; $j<10; $j++ ){ $x = cos(rand()*360)+cos(rand()*360); $y = sin(rand()*360)+sin(rand()*360); } $brs->stop(); } $lap->lap(); } $nrm->stop(); my( $l_time, $l_avg, $l_min, $l_max ); my( $b_time, $b_avg, $n_time, $n_avg ); $l_time = sprintf "%.7f", $lap->getTime(); $l_avg = sprintf "%.7f", ($l_time/$lap->numLaps()); $l_min = sprintf "%.7f", $lap->getMinLap(); $l_max = sprintf "%.7f", $lap->getMaxLap(); $b_time = sprintf "%.7f", $brs->getTime(); $b_avg = sprintf "%.7f", ($b_time/$lap->numLaps()); $n_time = sprintf "%.7f", $nrm->getTime(); $n_avg = sprintf "%.7f", ($n_time/$lap->numLaps()); print qq~ Times from $max runs are: [ Burst] Avg: $b_avg Tot: $b_time [ Lap ] Min: $l_min Avg: $l_avg Max: $l_max Tot: $l_time [ Norm ] Avg: $n_avg Tot: $n_time ~; OUTPUT Using the EXAMPLE code as is: Times from 500 runs are: [ Burst] Avg: 0.0016151 Tot: 0.8075600 [ Lap ] Min: 0.0000080 Avg: 0.0021507 Max: 0.0167070 Tot: 1.0753620 [ Norm ] Avg: 0.0021624 Tot: 1.0812210 Using the EXAMPLE code after moving the "burst" Stopwatch outside of the while-loop and then removing the inner-most while-loop: Times from 500 runs are: [ Burst] Avg: 0.0000053 Tot: 0.0026270 [ Lap ] Min: 0.0000240 Avg: 0.0000244 Max: 0.0000500 Tot: 0.0121820 [ Norm ] Avg: 0.0000357 Tot: 0.0178360 As seen above, just starting and stopping the Stopwatch takes a few microseconds. Im sure that these can be optimized further, but it is useful for comparisons and references. NOTES This was created to be inserted quickly into any script as a reference (SEE CAVEATS), since it requires very little modification of the original code that is being debugged, and is just as easy to remove when code is put into production. It is not designed for benchmarking or serious calculations since the module code itself is not optimized. As mentioned in CAVEATS, a simple for-loop takes about 5 microseconds to just start and stop a "lap" Stopwatch on my test systems. CAVEATS Uses Time::HiRes and is thus succeptible to all CAVEATS listed therein. Another known issue unreliable results in a multi-thread environment that also propagates from Time::HiRes. This is just a simple reference of time elapsed throughout a script and should be used for debugging and optimiziation purposes only. In only a simple loop, Perf::Stopwatch has a minimum number of microseconds that it takes to copy the retrieve and copy time-values and increment lap-indices. In my test cases, this has been approximately 5 microseconds in a simple for-loop. This only becomes a factor when comparing already optimized loops. If your loops have execution times in the 100ths of a second or more, then the time use by Perf::Stopwatch is neglible. COPYRIGHT and LICENSE Copyright (c) 2003 Kit DeKat. All rights reserved. This program is free software; you can redistribute it and/or modify it under the same terms as Perl itself.