use Config;
use File::Basename qw(&basename &dirname);
+use File::Spec;
# List explicitly here the variables you want Configure to
# generate. Metaconfig only looks for shell variables, so you
# This forces PL files to create target in same directory as PL file.
# This is so that make depend always knows where to find PL derivatives.
chdir(dirname($0));
-($file = basename($0)) =~ s/\.PL$//;
-$file =~ s/\.pl$// if ($Config{'osname'} eq 'OS2'); # "case-forgiving"
-$file =~ s/\.pl$/.com/ if ($Config{'osname'} eq 'VMS'); # "case-forgiving"
+($file = basename($0)) =~ s/\.PL$//i;
+$file .= '.COM' if ($^O eq 'VMS');
-my $dprof_pm = '../ext/Devel/DProf/DProf.pm';
+my $dprof_pm = File::Spec->catfile(File::Spec->updir, 'ext', 'Devel', 'DProf', 'DProf.pm');
my $VERSION = 0;
open( PM, "<$dprof_pm" ) || die "Can't open $dprof_pm: $!";
while(<PM>){
if( $VERSION == 0 ){
die "Did not find VERSION in $dprof_pm";
}
+my $stty = 'undef';
+foreach my $s (qw(/bin/stty /usr/bin/stty)) {
+ if (-x $s) {
+ $stty = qq["$s"];
+ last;
+ }
+}
open OUT,">$file" or die "Can't create $file: $!";
print "Extracting $file (with variable substitutions)\n";
require 5.003;
my \$VERSION = '$VERSION';
+my \$stty = $stty;
!GROK!THIS!
The I<dprofpp> command interprets profile data produced by a profiler, such
as the Devel::DProf profiler. Dprofpp will read the file F<tmon.out> and
-will display the 15 subroutines which are using the most time. By default
+display the 15 subroutines which are using the most time. By default
the times for each subroutine are given exclusive of the times of their
child subroutines.
To profile a Perl script run the perl interpreter with the B<-d> switch. So
-to profile script F<test.pl> with Devel::DProf the following command should
-be used.
+to profile script F<test.pl> with Devel::DProf use the following:
$ perl5 -d:DProf test.pl
=item B<-S>
-Display I<merged> subroutine call tree to stdout. Statistics is
+Display I<merged> subroutine call tree to stdout. Statistics are
displayed for each branch of the tree.
When a function is called multiple (I<not necessarily consecutive>)
the next level. A repeat count is output together with combined
inclusive, exclusive and kids time.
-Branches are sorted w.r.t. inclusive time.
+Branches are sorted with regard to inclusive time.
=item B<-U>
=item B<-P>
-Used with -G to aggregate "Pull" together all calls that did not match -G.
+Used with -G to aggregate "Pull" together all calls that did not match -G.
=item B<-f> <regexp>
Filter all calls matching the pattern.
+=item B<-h>
+
+Display brief help and exit.
+
+=item B<-H>
+
+Display long help and exit.
+
=back
=head1 ENVIRONMENT
=cut
+sub shortusage {
+ print <<'EOF';
+dprofpp [options] [profile]
+
+ -A Count autoloaded to *AUTOLOAD
+ -a Sort by alphabetic name of subroutines.
+ -d Reverse sort
+ -E Sub times are reported exclusive of child times. (default)
+ -f Filter all calls mathcing the pattern.
+ -G Group all calls matching the pattern together.
+ -g subr Count only those who are SUBR or called from SUBR
+ -H Display long manual page.
+ -h Display this short usage message.
+ -I Sub times are reported inclusive of child times.
+ -l Sort by number of calls to subroutines.
+ -O cnt Specifies maximum number of subroutines to display.
+ -P Used with -G to pull all other calls together.
+ -p script Specifies name of script to be profiled.
+ -Q Used with -p to indicate the dprofpp should quit
+ after profiling the script, without interpreting the data.
+ -q Do not print column headers.
+ -R Count anonyms separately even if from the same package
+ -r Use real elapsed time rather than user+system time.
+ -S Create statistics for all the depths
+ -s Use system time rather than user+system time.
+ -T Show call tree.
+ -t Show call tree, compressed.
+ -U Do not sort subroutines.
+ -u Use user time rather than user+system time.
+ -V Print dprofpp's version.
+ -v Sort by average amount of time spent in subroutines.
+ -z Sort by user+system time spent in subroutines. (default)
+EOF
+}
+
use Getopt::Std 'getopts';
use Config '%Config';
Setup: {
- my $options = 'O:g:G:Pf:dlzaAvuTtqrRsUFEIp:QVS';
+ my $options = 'O:g:G:Pf:dlzaAvuTtqrRsUFEIp:QVShH';
$Monfile = 'tmon.out';
if( exists $ENV{DPROFPP_OPTS} ){
@ARGV = @tmpargv;
}
- getopts( $options );
+ getopts( $options ) or die "Try 'dprofpp -h' for help.\n";
if( @ARGV ){
# there was a filename, it overrides any earlier name.
$Monfile = shift;
}
-# -O cnt Specifies maximum number of subroutines to display.
-# -a Sort by alphabetic name of subroutines.
-# -z Sort by user+system time spent in subroutines. (default)
-# -l Sort by number of calls to subroutines.
-# -v Sort by average amount of time spent in subroutines.
-# -T Show call tree.
-# -t Show call tree, compressed.
-# -q Do not print column headers.
-# -u Use user time rather than user+system time.
-# -s Use system time rather than user+system time.
-# -r Use real elapsed time rather than user+system time.
-# -U Do not sort subroutines.
-# -E Sub times are reported exclusive of child times. (default)
-# -I Sub times are reported inclusive of child times.
-# -V Print dprofpp's version.
-# -p script Specifies name of script to be profiled.
-# -Q Used with -p to indicate the dprofpp should quit after
-# profiling the script, without interpreting the data.
-# -A count autoloaded to *AUTOLOAD
-# -R count anonyms separately even if from the same package
-# -g subr count only those who are SUBR or called from SUBR
-# -S Create statistics for all the depths
-
-# -G Group all calls matching the pattern together.
-# -P Used with -G to pull all other calls together.
-# -f Filter all calls mathcing the pattern.
-# -d Reverse sort
+ if ( defined $opt_h ) {
+ shortusage();
+ exit;
+ }
+ if ( defined $opt_H ) {
+ require Pod::Usage;
+ Pod::Usage::pod2usage( {-verbose => 2, -input => $0 } );
+ exit;
+ }
if( defined $opt_V ){
my $fh = 'main::fh';
$hz ||= 1;
if( $opt_r ){
- $$runtime = ($rrun_rtime - $overhead - $over_rtime * $total_marks/$over_tests/2)/$hz;
+ $$runtime = ($rrun_rtime - $overhead)/$hz;
}
elsif( $opt_s ){
- $$runtime = ($rrun_stime - $overhead - $over_stime * $total_marks/$over_tests/2)/$hz;
+ $$runtime = ($rrun_stime - $overhead)/$hz;
}
elsif( $opt_u ){
- $$runtime = ($rrun_utime - $overhead - $over_utime * $total_marks/$over_tests/2)/$hz;
+ $$runtime = ($rrun_utime - $overhead)/$hz;
}
else{
- $$runtime = ($rrun_ustime - $overhead - ($over_utime + $over_stime) * $total_marks/$over_tests/2)/$hz;
+ $$runtime = ($rrun_ustime - $overhead)/$hz;
}
$$runtime = 0 unless $$runtime > 0;
}
exclusives_in_tree($deep_times);
my $kid;
- local *kids = $deep_times->{kids}; # %kids
my $time;
- if (%kids) {
+ if (%{$deep_times->{kids}}) {
$time = sprintf '%.*fs = (%.*f + %.*f)',
$time_precision, $deep_times->{incl_time}/$hz,
$time_precision, $deep_times->{excl_time}/$hz,
print ' ' x (2*$level), "$name x $deep_times->{count} \t${time}s\n"
if $deep_times->{count};
- for $kid (sort kids_by_incl keys %kids) {
+ for $kid (sort kids_by_incl %{$deep_times->{kids}}) {
display_tree( $deep_times->{kids}{$kid}, $kid, $level + 1 );
}
}
sub move_keys {
my ($source, $dest) = @_;
- my $kid;
-
- for $kid (keys %$source) {
- if (exists $dest->{$kid}) {
- $dest->{count} += $source->{count};
- $dest->{incl_time} += $source->{incl_time};
- move_keys($source->{kids},$dest->{kids});
+
+ for my $kid_name (keys %$source) {
+ my $source_kid = delete $source->{$kid_name};
+
+ if (my $dest_kid = $dest->{$kid_name}) {
+ $dest_kid->{count} += $source_kid->{count};
+ $dest_kid->{incl_time} += $source_kid->{incl_time};
+ move_keys($source_kid->{kids},$dest_kid->{kids});
} else {
- $dest->{$kid} = delete $source->{$kid};
+ $dest->{$kid_name} = $source_kid;
}
}
}
$name = $curdeep_times->[-1]{name};
}
die "Shorted?!" unless @$curdeep_times >= 2;
- $curdeep_times->[-2]{kids}{$name} = { count => 0 , kids => {},
- incl_time => 0,
- }
- unless exists $curdeep_times->[-2]{kids}{$name};
- my $entry = $curdeep_times->[-2]{kids}{$name};
+ my $entry = $curdeep_times->[-2]{kids}{$name} ||= {
+ count => 0,
+ kids => {},
+ incl_time => 0,
+ };
# Now transfer to the new node (could not do earlier, since name can change)
$entry->{count}++;
$entry->{incl_time} += $t - $curdeep_times->[-1]{enter_stamp};
my( $x, $z, $c, $id, $pack );
my @stack = ();
my @tstack = ();
+ my %outer;
my $tab = 3;
my $in = 0;
my $l_name = '';
my $repcnt = 0;
my $repstr = '';
- my $dprof_t = 0;
my $dprof_stamp;
my %cv_hash;
my $in_level = not defined $opt_g; # Level deep in report grouping
my $ot = $t;
if ( $dir eq '/' ) {
- $syst = $stack[-1][0];
+ $syst = $stack[-1][0] if scalar @stack;
$usert = '&';
$dir = '-';
#warn("Inserted exit for $stack[-1][0].\n")
$name = defined $syst ? $syst : $cv_hash{$usert};
}
- next unless $in_level or $name eq $opt_g or $dir eq '*';
+ next unless $in_level or $name eq $opt_g;
if ( $dir eq '-' or $dir eq '*' ) {
my $ename = $dir eq '*' ? $stack[-1][0] : $name;
$overhead += $over_per_call;
if ($name eq "Devel::DProf::write") {
- $dprof_t += $t - $dprof_stamp;
+ $overhead += $t - $dprof_stamp;
next;
} elsif (defined $opt_g and $ename eq $opt_g) {
$in_level--;
}
add_to_tree($curdeep_times, $ename,
- $t - $dprof_t - $overhead) if $opt_S;
- exitstamp( \@stack, \@tstack,
- $t - $dprof_t - $overhead,
- $times, $ctimes, $ename, \$in, $tab,
- $curdeep_times );
+ $t - $overhead) if $opt_S;
+ exitstamp( \@stack, \@tstack,
+ $t - $overhead,
+ $times, $ctimes, $name, \$in, $tab,
+ $curdeep_times, \%outer );
}
next unless $in_level or $name eq $opt_g;
if( $dir eq '+' or $dir eq '*' ){
push( @$idkeys, $name );
}
$calls->{$name}++;
+ $outer{$name}++;
push @$curdeep_times, { kids => {},
name => $name,
- enter_stamp => $t - $dprof_t - $overhead,
+ enter_stamp => $t - $overhead,
} if $opt_S;
- $x = [ $name, $t - $dprof_t - $overhead ];
+ $x = [ $name, $t - $overhead ];
push( @stack, $x );
# my children will put their time here
print ' ' x $l_in, "$l_name$repstr\n";
}
+ while (my ($key, $count) = each %outer) {
+ next unless $count;
+ warn "$key has $count unstacked calls in outer\n";
+ }
+
if( @stack ){
if( ! $opt_F ){
warn "Garbled profile is missing some exit time stamps:\n";
foreach $x ( reverse @stack ){
$name = $x->[0];
exitstamp( \@stack, \@tstack,
- $t - $dprof_t - $overhead, $times,
+ $t - $overhead, $times,
$ctimes, $name, \$in, $tab,
- $curdeep_times );
+ $curdeep_times, \%outer );
add_to_tree($curdeep_times, $name,
- $t - $dprof_t - $overhead)
+ $t - $overhead)
if $opt_S;
}
}
}
sub exitstamp {
- my($stack, $tstack, $t, $times, $ctimes, $name, $in, $tab, $deep) = @_;
+ my($stack, $tstack, $t, $times, $ctimes, $name, $in, $tab, $deep, $outer) = @_;
my( $x, $c, $z );
$x = pop( @$stack );
$c = pop( @$tstack );
# total time this func has been active
$z = $t - $x->[1];
- $ctimes->{$name} += $z;
- $times->{$name} += ($z > $c)? $z - $c: 0;
+ $ctimes->{$name} += $z
+ unless --$outer->{$name};
+ $times->{$name} += $z - $c;
# pass my time to my parent
if( @$tstack ){
$c = pop( @$tstack );
format CSTAT_top =
Total Elapsed Time = @>>>>>>> Seconds
-(($rrun_rtime - $overhead - $over_rtime * $total_marks/$over_tests/2) / $hz)
+(($rrun_rtime - $overhead) / $hz)
@>>>>>>>>>> Time = @>>>>>>> Seconds
$whichtime, $runtime
@<<<<<<<< Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
.
-format STAT =
- ^>>> ^>>>> ^>>>>> ^>>>>> ^>>>>> ^>>>>> ^<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
-$pcnt, $secs, $csecs, $ncalls, $percall, $cpercall, $name
-.
+BEGIN {
+ my $fmt = ' ^>>> ^>>>> ^>>>>> ^>>>>> ^>>>>> ^>>>>> ^<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<';
+ if (-t STDOUT and defined $stty and my ($cols) = `$stty -a` =~ /\bcolumns\s+(\d+)/)
+ {
+ $fmt .= '<' x ($cols - length $fmt) if $cols > 80;
+ }
+ eval "format STAT = \n$fmt" . '
+$pcnt, $secs, $csecs, $ncalls, $percall, $cpercall, $name
+.';
+}
!NO!SUBS!
close OUT or die "Can't close $file: $!";