perl -d:DProf foo.pl
####
perl -MDevel::Profiler foo.pl
##
##
dprofpp
##
##
main();
sub main {
my $now = time();
for( my $x = 0; $x <= 1_000_000; $x++ ) {
print scalar localtime, "\n" if $now != time();
$now = time();
}
return;
}
##
##
Total Elapsed Time = 1.859881 Seconds
User+System Time = 1.389881 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
98.5 1.370 1.370 1 1.3700 1.3700 main::main
0.72 0.010 0.010 2 0.0050 0.0050 main::BEGIN
##
##
main();
sub main { all_the_work() }
sub all_the_work {
my $now = time();
for( my $x = 0; $x <= 1_000_000; $x++ ) {
print scalar localtime, "\n" if $now != time();
$now = time();
}
return;
}
##
##
Total Elapsed Time = 1.809848 Seconds
User+System Time = 1.379848 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
98.5 1.360 1.360 1 1.3600 1.3600 main::all_the_work
0.00 - 1.360 1 - 1.3600 main::main
0.00 - 0.010 2 - 0.0050 main::BEGIN
##
##
main();
sub main {
do_nothing();
all_the_work();
}
sub do_nothing { sleep 5 }
sub all_the_work {
my $now = time();
for( my $x = 0; $x <= 1_000_000; $x++ ) {
print scalar localtime, "\n" if $now != time();
$now = time();
}
return;
}
##
##
Total Elapsed Time = 6.809867 Seconds
User+System Time = 1.459867 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
97.9 1.430 1.430 1 1.4300 1.4300 main::all_the_work
0.68 0.010 0.010 2 0.0050 0.0050 main::BEGIN
0.00 - -0.000 1 - - main::do_nothing
0.00 - 1.430 1 - 1.4300 main::main
##
##
Total Elapsed Time = 6.799829 Seconds
Real Time = 6.799829 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
73.5 5.000 5.000 1 5.0000 5.0000 main::do_nothing
26.1 1.780 1.780 1 1.7800 1.7800 main::all_the_work
0.15 0.010 0.020 2 0.0050 0.0100 main::BEGIN
0.00 - 6.780 1 - 6.7800 main::main