package Devel::SmallProf; # To help the CPAN indexer to identify us our $VERSION = '2.02'; package DB; # do not profile subs BEGIN { $^P=0x122 } use strict; sub Time::HiRes::time (); our ($profile, $drop_zeros, $grep_format, %packages); my ($cdone, $done, $cstart, $start, $prevf, $prevl, $nulltime, %listings, %profiles, %times, %ctimes); sub sub; # even if it is not used it has to be declared! sub DB { $profile || return; my($pkg,$filename,$line) = caller; %packages && !$packages{$pkg} && return; $done = Time::HiRes::time; my ($u,$s,$cu,$cs) = times; $cdone = $u+$s+$cu+$cs; # Now save the _< array for later reference. If we don't do this here, # evals which do not define subroutines will disappear. no strict 'refs'; $listings{$filename} = \@{"main::_<$filename"} if defined(@{"main::_<$filename"}); use strict 'refs'; my($delta); $delta = $done - $start; $delta = ($delta > $nulltime) ? $delta - $nulltime : 0; $profiles{$filename}->[$line]++; $times{$prevf}->[$prevl] += $delta; $ctimes{$prevf}->[$prevl] += ($cdone - $cstart); ($prevf, $prevl) = ($filename, $line); ($u,$s,$cu,$cs) = times; $cstart = $u+$s+$cu+$cs; $start = Time::HiRes::time; } use Time::HiRes; BEGIN { $drop_zeros = 0; $profile = 1; $grep_format = 0; if (-e '.smallprof') { do '.smallprof'; } my $env=$ENV{SMALLPROF_CONFIG}||''; $drop_zeros = 1 if $env=~/z/; $profile = 1 if $env=~/p/; $grep_format = 1 if $env=~/g/; # print STDERR "drop_zeros=$DB::drop_zeros grep_format=$DB::grep_format\n"; $prevf = ''; $prevl = 0; my($diff,$cdiff); my($testDB) = sub { my($pkg,$filename,$line) = caller; $profile || return; %packages && !$packages{$pkg} && return; }; # "Null time" compensation code $nulltime = 0; for (1..100) { my($u,$s,$cu,$cs) = times; $cstart = $u+$s+$cu+$cs; $start = Time::HiRes::time; &$testDB; ($u,$s,$cu,$cs) = times; $cdone = $u+$s+$cu+$cs; $done = Time::HiRes::time; $diff = $done - $start; $nulltime += $diff; } $nulltime /= 100; my($u,$s,$cu,$cs) = times; $cstart = $u+$s+$cu+$cs; $start = Time::HiRes::time; } END { # Get time on last line executed. my($u,$s,$cu,$cs) = times; $cdone = $u+$s+$cu+$cs; $done = Time::HiRes::time; my($delta); $delta = $done - $start; $delta = ($delta > $nulltime) ? $delta - $nulltime : 0; $times{$prevf}->[$prevl] += $delta; $ctimes{$prevf}->[$prevl] += ($cdone - $cstart); # Now write out the results. open(OUT,">smallprof.out"); select OUT; if ($grep_format) { my @unsorted=(); for my $file (keys %profiles) { my @line=@{$profiles{$file}}; for my $i (0..@line) { my ($rfile, $ri, $eval)= ($file=~/^\(eval\s*(\d+)\)\[(.*):(\d+)\]$/) ? ($2, $3, "(eval $1:$i) ") : ($file, $i, ""); $drop_zeros and !$line[$i] and next; my $line=sprintf('%s:%s:%d:%d:%d: %s%s', $rfile, $ri, $line[$i], int($times{$file}[$i]*1000), int($ctimes{$file}[$i]*1000), $eval, $listings{$file}[$i]||'?' ); chomp $line; push @unsorted, [ $line, $times{$file}[$i]]; } } my @sorted=sort { $b->[1] <=> $a->[1] } @unsorted; print "* file name : line number : line count : time (ms) : ctime (ms) : line source\n"; for (@sorted) { print "$_->[0]\n"; } } else { my($i,$stat,$time,$ctime,$line,$file,$page); $page = 1; format OUT_TOP= @|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| '================ SmallProf version '.$Devel::SmallProf::VERSION.' ================' @|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Page @<< "Profile of $file",$page++ ================================================================= count wall tm cpu time line . format OUT= @######## @##.##### @##.##### @####:^<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< $stat,$time,$ctime,$i,$line . foreach $file (sort keys %profiles) { $- = 0; if (defined($listings{$file})) { $i = -1; foreach $line (@{$listings{$file}}) { ++$i or next; if (defined($line)) { chomp($line); } else { $line = ''; } $stat = $profiles{$file}->[$i] || 0 or !$drop_zeros or next; $time = defined($times{$file}->[$i]) ? $times{$file}->[$i] : 0; $ctime = defined($ctimes{$file}->[$i]) ? $ctimes{$file}->[$i] : 0; write OUT; } } else { $line = "The code for $file is not in the symbol table."; for ($i=1; $i <= $#{$profiles{$file}}; $i++) { next unless ($stat = $profiles{$file}->[$i] || 0 or !$drop_zeros); $time = defined($times{$file}->[$i]) ? $times{$file}->[$i] : 0; $ctime = defined($ctimes{$file}->[$i]) ? $ctimes{$file}->[$i] : 0; write OUT; } } } } close OUT; } 1; __END__ =head1 NAME Devel::SmallProf - per-line Perl profiler =head1 SYNOPSIS perl5 -d:SmallProf test.pl =head1 DESCRIPTION The Devel::SmallProf profiler is focused on the time taken for a program run on a line-by-line basis. It is intended to be as "small" in terms of impact on the speed and memory usage of the profiled program as possible and also in terms of being simple to use. Those statistics are placed in the file F in the following format: