Revision: 1183
Author: [email protected]
Date: Mon Apr 5 16:22:16 2010
Log: More major work on string eval support. This is now working well in
the ideal
simple case (a modern perl version with NYTPROF_TEST_ONE=1).
Needs assorted polishing of rough edges/cases. For example, code that does
thousands of evals will generate many thousands of html files. Needs:
- Handle savesrc being off and/or old perl versions.
- Merge eval calls from a given line that have identical src
- Perhaps add option to merge evals that don't define subs.
The data model is simpler as it doesn't do any special handling of evals at
a low level now. They're just another file. This is reflected in the test
data
which now includes line details for evals.
Added the fid to the output filename to avoid clashes with duplicate evals.
(May end up removing the 'normalization' of "(eval 42)"->"(eval 0)".)
Slimmed down ::Reader some more.
http://code.google.com/p/perl-devel-nytprof/source/detail?r=1183
Modified:
/trunk/Changes
/trunk/HACKING
/trunk/NYTProf.xs
/trunk/bin/nytprofcsv
/trunk/bin/nytprofhtml
/trunk/lib/Devel/NYTProf/FileInfo.pm
/trunk/lib/Devel/NYTProf/Reader.pm
/trunk/lib/Devel/NYTProf/SubInfo.pm
/trunk/t/10-run.t
/trunk/t/lib/NYTProfTest.pm
/trunk/t/test08.rdt
/trunk/t/test09.rdt
/trunk/t/test10.rdt
/trunk/t/test11.rdt
/trunk/t/test11.x
/trunk/t/test13.rdt
/trunk/t/test14.rdt
/trunk/t/test20-streval.rdt
/trunk/t/test21-streval3.rdt
/trunk/t/test22-strevala.rdt
/trunk/t/test23-strevall.rdt
/trunk/t/test51-enable.rdt
/trunk/t/test61-submerge.rdt
=======================================
--- /trunk/Changes Wed Mar 31 14:52:53 2010
+++ /trunk/Changes Mon Apr 5 16:22:16 2010
@@ -17,13 +17,16 @@
XXX TODO
Refine and document handing of string evals
+Consider eval_pv from outside perl, e.g. plperl
+
+ Fixed off-by-1 error in number of Files an xsub/opcode was called from.
Enabled savesrc=1 by default.
Corrected typos in nytprofhtml docs thanks to [email protected]
- Sequences are blank lines are skipped in generated reports.
- Applies to savesrc mode in which perl doesn't store pod.
+ Sequences of blank lines are skipped in generated reports.
+ Relevant for savesrc mode in which perl doesn't store pod sections.
=head2 Changes in Devel::NYTProf 3.11 (svn 1171) 12th March 2010
=======================================
--- /trunk/HACKING Tue Mar 30 05:56:54 2010
+++ /trunk/HACKING Mon Apr 5 16:22:16 2010
@@ -392,7 +392,7 @@
- Add header with link to location of the invoking string eval
- fix sub caller info to not rollup over evals
- merge string evals which have identical src and invoking location
+- fix inconsistency in results of href_for_*() subs
+- Add eval information (evals and time) to file summary header
Make generation of call graph .dot files optional and/or optimize to make
faster
-
-The 'tainted' test should be renamed to 'modified' and be skipped if the
report is using saved src.
=======================================
--- /trunk/NYTProf.xs Tue Mar 30 05:56:54 2010
+++ /trunk/NYTProf.xs Mon Apr 5 16:22:16 2010
@@ -921,10 +921,10 @@
* then we'd like to save the src (NYTP_FIDf_HAS_SRC) if it's available
*/
if (found->eval_fid
+ || (profile_opts & NYTP_OPTf_SAVESRC)
|| (found->key_len > 10 && found->key[9] == 'x' &&
strnEQ(found->key, "/loader/0x", 10))
|| (found->key[0] == '-' && (found->key_len == 1 ||
- (found->key[1] == 'e' && found->key_len
== 2)))
- || (profile_opts & NYTP_OPTf_SAVESRC)
+ (found->key[1] == 'e' && found->key_len ==
2)))
) {
found->fid_flags |= NYTP_FIDf_SAVE_SRC;
}
@@ -2874,23 +2874,7 @@
if (!SvROK(line_time_rvav)) /* autoviv */
sv_setsv(line_time_rvav, newRV_noinc((SV*)newAV()));
- if (!eval_line_num) {
- store_profile_line_entry(aTHX_ line_time_rvav, line_num, time,
count, fid);
- }
- else {
- /* times for statements executed *within* a string eval are
accumulated
- * embedded nested within the line the eval is on but without
increasing
- * the time or count of the eval itself. Instead the time and
count is
- * accumulated for each line within the eval on an embedded array
reference.
- */
- AV *av = store_profile_line_entry(aTHX_ line_time_rvav,
eval_line_num, 0, 0, fid);
-
- SV *eval_line_time_rvav = *av_fetch(av, 2, 1);
- if (!SvROK(eval_line_time_rvav)) /* autoviv */
- sv_setsv(eval_line_time_rvav, newRV_noinc((SV*)newAV()));
-
- store_profile_line_entry(aTHX_ eval_line_time_rvav, line_num,
time, count, fid);
- }
+ store_profile_line_entry(aTHX_ line_time_rvav, line_num, time, count,
fid);
}
@@ -3593,17 +3577,7 @@
sv_setsv(fid_info_rvav, &PL_sv_no);
}
}
- else {
- if (!opt_evals)
- eval_outer_fid(aTHX_ state->fid_fileinfo_av, file_num, 1,
- &eval_file_num, &eval_line_num);
- }
-
- if (!opt_evals && eval_file_num) { /* fid is an eval */
- if (trace_level >= 3)
- sprintf(trace_note," (was string eval fid %u)", file_num);
- file_num = eval_file_num;
- }
+
if (trace_level >= 4) {
const char *new_file_name = "";
if (file_num != state->last_file_num && SvROK(fid_info_rvav))
@@ -3899,6 +3873,9 @@
if (!SvROK(sv)) /* autoviv */
sv_setsv(sv, newRV_noinc((SV*)newHV()));
+ /* XXX gets called with fid=0 to indicate is_xsub
+ * That's a hack that should be removed once we have per-sub flags
+ */
if (fid) {
SV *fi;
AV *av;
=======================================
--- /trunk/bin/nytprofcsv Tue Mar 9 02:35:10 2010
+++ /trunk/bin/nytprofcsv Mon Apr 5 16:22:16 2010
@@ -74,13 +74,19 @@
$reporter->output_dir($opt{out});
$reporter->set_param(mk_report_source_line => sub {
- my ($linenum, $line, $stats_for_line, $statistics, $subs_defined,
$makes_calls_to, $profile, $filestr) = @_;
+ my ($linenum, $line, $stats_for_line, $statistics, $profile, $filestr)
= @_;
$line =~ s/^\s*//; # trim leading spaces
my $delim = $opt{delim};
+
+ my $time = $stats_for_line->{'time'} || 0;
+ my $calls = $stats_for_line->{'calls'} || 0;
+ $time += $stats_for_line->{evalcall_stmts_time_nested} || 0;
+ #$calls ||= 1 if exists $stats_for_line->{evalcall_stmts_time_nested};
+
my $text = sprintf("%f%s%g%s%f%s%s\n",
- $stats_for_line->{'time'} || 0, $delim,
- $stats_for_line->{'calls'} || 0, $delim,
- $stats_for_line->{'time/call'} || 0, $delim,
+ $time, $delim,
+ $calls, $delim,
+ ($calls) ? $time/$calls : 0, $delim,
$line,
);
return $text unless $opt{annotated};
@@ -88,13 +94,6 @@
# srcline
$text = "srcline$delim$text";
- if (@$subs_defined) {
- # subdefn
- # callers
- }
- if (@$makes_calls_to) {
- # calling
- }
return $text;
});
=======================================
--- /trunk/bin/nytprofhtml Wed Mar 31 14:52:53 2010
+++ /trunk/bin/nytprofhtml Mon Apr 5 16:22:16 2010
@@ -120,11 +120,13 @@
title => "NYTProf Performance Profile",
subtitle => $subhead,
);
+ my $filename_escaped = _escape_html($fi->filename);
my $intro = sprintf qq{<table class="file_summary">%s</table>},
join "\n", map { sprintf q{<tr><td class="h">%s</td><td
align="left">%s</td></tr>}, @$_ }
- [ "Filename", sprintf q{<a href="file://%s">%s</a>},
- $fi->filename, _escape_html($fi->filename) ],
- [ "Statements Executed", sprintf "%d executed in %s",
+ [ "Filename", $fi->is_file
+ ? sprintf(q{<a href="file://%s">%s</a>},
$fi->filename, $filename_escaped)
+ : $filename_escaped ],
+ [ "Statements", sprintf "Executed %d statements in %s",
$fi->sum_of_stmts_count,
fmt_time($fi->sum_of_stmts_time) ];
return join "\n", $html_header, $page_header, q{<div
class="body_content"><br />}, $intro;
@@ -326,10 +328,10 @@
$reporter->set_param(mk_report_xsub_line => \&mk_report_xsub_line );
sub mk_report_source_line {
- my ($linenum, $line, $stats_for_line, $stats_for_file, $subs_defined,
$subs_called, $profile, $filestr, $evals_called) = @_;
+ my ($linenum, $line, $stats_for_line, $stats_for_file, $profile, $fi)
= @_;
my $l = sprintf(qq{<td class="h"><a name="%s"></a>%s</td>}, $linenum,
$linenum);
- my $s = report_src_line(undef, $linenum, $line, $profile,
$subs_defined, $subs_called, $filestr, $evals_called);
+ my $s = report_src_line(undef, $linenum, $line, $profile, $fi,
$stats_for_line);
return "<tr>$l<td></td><td></td><td></td><td></td>$s</tr>\n"
if not %$stats_for_line;
@@ -345,12 +347,12 @@
}
sub mk_report_xsub_line {
- my ($subname, $line, $stats_for_line, $stats_for_file, $subs_defined,
$subs_called, $profile, $filestr) = @_;
+ my ($subname, $line, $stats_for_line, $stats_for_file, $profile, $fi)
= @_;
(my $anchor = $subname) =~ s/\W/_/g;
return join "",
sprintf(qq{<tr><td class="h"><a name="%s"></a>%s</td>},
$anchor, ''),
"<td></td><td></td><td></td><td></td>",
- report_src_line(undef, undef, $line, $profile, $subs_defined,
$subs_called, $filestr, undef),
+ report_src_line(undef, undef, $line, $profile, $fi,
$stats_for_line),
"</tr>\n";
}
@@ -368,7 +370,7 @@
sub report_src_line {
- my ($value, undef, $linesrc, $profile, $subs, $subs_called, $thisfile,
$evals_called) = @_;
+ my ($value, undef, $linesrc, $profile, $fi, $stats_for_line) = @_;
$linesrc = _escape_html($linesrc);
@@ -377,7 +379,8 @@
my @prologue;
# for each of the subs defined on this line, who called them
- for my $sub_info (@$subs) {
+ my $subdef_info = $stats_for_line->{subdef_info} || [];
+ for my $sub_info (@$subdef_info) {
my $callers = $sub_info->caller_fid_line_places;
next unless $callers && %$callers;
@@ -395,8 +398,9 @@
? ""
: " $total_calls times, avg ${avg_per_call}/call:";
- # order by most frequent caller first
+ # order by most frequent caller first, then by time
@callers = sort { $b->[2] <=> $a->[2] || $b->[3] <=> $a->[3] }
@callers;
+
for my $caller (@callers) {
my ($fid, $line, $count, $incl_time, $excl_time, undef, undef,
undef, undef, $calling_subs) = @$caller;
@@ -416,20 +420,20 @@
my $filename = $fi->filename($fid);
my $line_desc = "line $line of $filename";
# chase string eval chain back to a real file
- while ( my ($outer_fileinfo, $outer_line) = $fi->outer ) {
+ while (0 and my ($outer_fileinfo, $outer_line) = $fi->outer ) {
($filename, $line) = ($outer_fileinfo->filename,
$outer_line);
$line_desc .= sprintf " at line %s of %s", $line,
$filename;
$fi = $outer_fileinfo;
}
- my $href = $reporter->href_for_file($fi) || 'unknown';
- $line_desc =~ s/ of \Q$filename\E$//g if $filename eq
$thisfile;
+ my $href = $reporter->href_for_file($fi, $line) || 'unknown';
+ $line_desc =~ s/ of \Q$filename\E$//g if $filename eq
$fi->filename;
# remove @INC prefix from paths
$line_desc =~ s/$inc_path_regex//g;
push @prologue,
- sprintf q{# %*s times%s%s at <a href="%s#%d">%s</a>%s},
- length($max_calls), $count, $times, $subname, $href, $line,
+ sprintf q{# %*s times%s%s at <a href="%s">%s</a>%s},
+ length($max_calls), $count, $times, $subname, $href,
$line_desc, $avg_time;
$prologue[-1] =~ s/^(# +)1 times/$1 once/; # better English
}
@@ -442,18 +446,19 @@
my $ws;
# give details of each of the subs called by this line
- if ($subs_called && %$subs_called) {
+ my $subcall_info = $stats_for_line->{subcall_info};
+ if ($subcall_info && %$subcall_info) {
my @calls_to = sort {
- $subs_called->{$b}[1] <=> $subs_called->{$a}[1] or #
incl_time
+ $subcall_info->{$b}[1] <=> $subcall_info->{$a}[1] or #
incl_time
$a cmp $b
- } keys %$subs_called;
- my $max_calls_to = max(map { $_->[0] } values %$subs_called);
+ } keys %$subcall_info;
+ my $max_calls_to = max(map { $_->[0] } values %$subcall_info);
$ws ||= ($linesrc =~ m/^((?: |\s)+)/) ? $1 : '';
my $subs_called_html = join "\n", map {
my $subname = $_;
- my ($count, $incl_time, $reci_time, $rec_depth) =
(@{$subs_called->{$subname}})[0,1,5,6];
+ my ($count, $incl_time, $reci_time, $rec_depth) =
(@{$subcall_info->{$subname}})[0,1,5,6];
my $html = sprintf qq{%s# spent %s making %*d call%s to }, $ws,
fmt_time($incl_time+$reci_time, 5), length($max_calls_to),
$count, $count == 1 ? "" : "s";
@@ -471,6 +476,7 @@
}
# give details of each of the string evals executed on this line
+ my $evals_called = $stats_for_line->{evalcall_info};
if ($evals_called && %$evals_called) {
$ws ||= ($linesrc =~ m/^((?: |\s)+)/) ? $1 : '';
@@ -488,12 +494,13 @@
if (@nested_evals) {
$nest_eval_time = sum map { $_->sum_of_stmts_time }
@nested_evals;
- $extra = sprintf " (%s in this eval and %s in nested
evals)",
- fmt_time($sum_of_stmts_time),
fmt_time($nest_eval_time)
+ $extra = sprintf " (%s in this eval plus %s in %d nested
evals)",
+ fmt_time($sum_of_stmts_time),
fmt_time($nest_eval_time),
+ scalar @nested_evals
if $nest_eval_time;
}
- my $href = $reporter->href_for_file($eval_fi);
+ my $href = $reporter->href_for_file($eval_fi, undef);
my $link = ($href)
? sprintf(q{<a href="%s">%s</a>}, $href, "string eval")
: "string eval";
@@ -1179,9 +1186,9 @@
push @t_stmt_time, $time;
my $rep_links = join ' • ', map {
- my $level_html_safe = $reporter->href_for_file($fi, $_);
- ($level_html_safe)
- ? sprintf(qq{<a href="%s">%s</a>}, $level_html_safe, $_)
+ my $href = $reporter->href_for_file($fi, undef, $_);
+ ($href)
+ ? sprintf(qq{<a href="%s">%s</a>}, $href, $_)
: ()
} qw(line block sub);
print $fh "<td>$rep_links</td>";
=======================================
--- /trunk/lib/Devel/NYTProf/FileInfo.pm Wed Mar 31 14:52:53 2010
+++ /trunk/lib/Devel/NYTProf/FileInfo.pm Mon Apr 5 16:22:16 2010
@@ -27,7 +27,6 @@
sub eval_fid { shift->[NYTP_FIDi_EVAL_FID()] }
sub eval_line { shift->[NYTP_FIDi_EVAL_LINE()] }
sub fid { shift->[NYTP_FIDi_FID()] }
-sub flags { shift->[NYTP_FIDi_FLAGS()] }
sub size { shift->[NYTP_FIDi_FILESIZE()] }
sub mtime { shift->[NYTP_FIDi_FILEMTIME()] }
sub profile { shift->[NYTP_FIDi_PROFILE()] }
@@ -35,11 +34,18 @@
# if an eval then return fileinfo obj for the fid that executed the eval
sub eval_fi { shift->[NYTP_FIDi_EVAL_FI()] }
sub is_eval { shift->[NYTP_FIDi_EVAL_FI()] ? 1 : 0 }
+
+sub flags { shift->[NYTP_FIDi_FLAGS()] }
+sub is_fake { shift->flags & NYTP_FIDf_IS_FAKE }
+sub is_file {
+ my $self = shift;
+ return not ($self->is_fake or $self->is_eval);
+}
# general purpose hash - mainly a hack to help kill of Reader.pm
sub meta { shift->[NYTP_FIDi_meta()] ||= {} }
-# ref to array of fileinfo's for each string eval in the file, else undef
+# array of fileinfo's for each string eval in the file, else undef
sub has_evals {
my ($self, $include_nested) = @_;
@@ -110,17 +116,17 @@
sub evals_by_line {
my ($self) = @_;
- # find all fids that have have this fid as an eval_fid
- # { line => { fid_of_eval_at_line => $fi, ... } }
-
- my %evals_by_line;
- my $fid = $self->fid;
+ # find all fids that have have this fid as an eval_fid
+ # { line => { fid_of_eval_at_line => $fi, ... } }
+
+ my %evals_by_line;
+ my $fid = $self->fid;
for my $fi ($self->profile->all_fileinfos) {
next unless (($fi->eval_fid || 0) == $fid);
- $evals_by_line{ $fi->eval_line }->{ $fi->fid } = $fi;
+ $evals_by_line{ $fi->eval_line }->{ $fi->fid } = $fi;
}
- return \%evals_by_line;
+ return \%evals_by_line;
}
@@ -289,9 +295,9 @@
sub summary {
- my ($fi) = @_;
+ my ($fi) = @_;
return sprintf "fid%d: %s",
- $fi->fid, $fi->filename_without_inc;
+ $fi->fid, $fi->filename_without_inc;
}
sub dump {
=======================================
--- /trunk/lib/Devel/NYTProf/Reader.pm Wed Mar 31 14:52:53 2010
+++ /trunk/lib/Devel/NYTProf/Reader.pm Mon Apr 5 16:22:16 2010
@@ -19,6 +19,7 @@
use Config;
use List::Util qw(sum max);
+use Data::Dumper;
use Devel::NYTProf::Data;
use Devel::NYTProf::Util qw(
@@ -35,6 +36,8 @@
use constant SEVERITY_BAD => 1.0;
use constant SEVERITY_GOOD => 0.5; # within this deviation, okay
+my $trace = 0;
+
# Static class variables
our $FLOAT_FORMAT = $Config{nvfformat};
$FLOAT_FORMAT =~ s/"//g;
@@ -78,42 +81,6 @@
}
-sub _map_new_to_old { # convert into old-style data structure
- my ($profile, $level) = @_;
- $level ||= 'line';
-
- my $dump = 0;
- require Data::Dumper if $dump;
- $profile->dump_profile_data({filehandle => \*STDERR, separator
=> "\t"}) if $dump;
- warn Data::Dumper::Dumper($profile) if $dump;
-
- my $oldstyle = {};
- for my $fi ($profile->all_fileinfos) {
-
- my $lines_array = $fi->line_time_data([$level]) || [];
- # convert any embedded eval line time arrays to hashes
- for (@$lines_array) {
- $_->[2] = _line_array_to_line_hash($_->[2]) if $_ && $_->[2];
- }
- my $lines_hash = _line_array_to_line_hash($lines_array);
-
- $oldstyle->{$fi->filename} = $lines_hash;
- $fi->meta->{lines_hash} = $lines_hash;
- }
- warn Data::Dumper::Dumper($oldstyle) if $dump;
- return $oldstyle;
-}
-
-sub _line_array_to_line_hash {
- my ($array) = @_;
- my $hash = {};
- for my $line (0 .. @$array) {
- $hash->{$line} = $array->[$line]
- if defined $array->[$line];
- }
- return $hash;
-}
-
##
sub set_param {
@@ -185,35 +152,42 @@
if $level_additional_sub;
}
}
+
+sub current_level {
+ my $self = shift;
+ $self->{current_level} = shift if @_;
+ return $self->{current_level} || 'line';
+}
##
sub _generate_report {
my $self = shift;
my ($profile, $LEVEL) = @_;
- my $data = _map_new_to_old($profile, $LEVEL);
-
- carp "Profile report data contains no files"
- unless keys %$data;
+ $self->current_level($LEVEL);
+
+ my @all_fileinfos = $profile->all_fileinfos
+ or carp "Profile report data contains no files";
#$profile->dump_profile_data({ filehandle => \*STDERR,
separator=>"\t", });
# pre-calculate some data so it can be cross-referenced
- foreach my $fi ($profile->all_fileinfos) {
+ foreach my $fi (@all_fileinfos) {
# discover file path
my $fname = html_safe_filename($fi->filename_without_inc);
+ $fname .= "-".$fi->fid;
$fname .= "-$LEVEL" if $LEVEL;
my $meta = $fi->meta;
$meta->{html_safe} = $fname;
$meta->{$LEVEL}->{html_safe} = $fname;
- $meta->{filename} = $fi->filename;
}
- foreach my $fi ($profile->all_fileinfos) {
+ foreach my $fi (@all_fileinfos) {
my $meta = $fi->meta;
- my $filestr = $meta->{filename};
+ my $filestr = $fi->filename;
+ warn "$filestr $LEVEL\n" if $trace;
my %stats_accum; # holds all line times. used to find
median
my %stats_by_line; # holds individual line stats
@@ -228,15 +202,23 @@
# { linenumber => { fid => $fileinfo } }
my $evals_at_line = { %{ $fi->evals_by_line } };
+ my $subs_defined_hash = $profile->subs_defined_in_file($filestr,
1);
+
# note that a file may have no source lines executed, so no keys
here
# (but is included because some xsubs in the package were executed)
- my $lines_hash = $meta->{lines_hash};
- foreach my $linenum (keys %$lines_hash) {
- my $a = $lines_hash->{$linenum};
+
+ my $lines_array = $fi->line_time_data([$LEVEL]) || [];
+
+ foreach my $linenum (1...@$lines_array) {
+
+ my $a = $lines_array->[$linenum];
+ next if !$a # no info for line
+ or !...@$a; # XXX happens for evals
+
+ warn "$linenum: [...@$a]\n" if $trace >= 2;
my $line_stats = $stats_by_line{$linenum} ||= {};
if (0 == $a->[1]) {
-
# The debugger cannot stop on BEGIN{...} lines. A line in
a begin
# may set a scalar reference to something that needs to be
eval'd later.
# as a result, if the variable is expanded outside of the
BEGIN, we'll
@@ -246,14 +228,6 @@
}
my $time = $a->[0];
- if (my $eval_lines = $a->[2]) {
- # line contains a string eval
- # $eval_lines is a hash of profile data for the lines in
the eval
- # sum up the times and add to $time
- # but we don't increment the statement count of the eval
- # as that would be inappropriate and misleading
- $time += $_->[0] for values %$eval_lines;
- }
push(@{$stats_accum{'time'}}, $time);
push(@{$stats_accum{'calls'}}, $a->[1]);
push(@{$stats_accum{'time/call'}}, $time / $a->[1]);
@@ -263,15 +237,33 @@
$line_stats->{'time/call'} =
$line_stats->{'time'} / $line_stats->{'calls'};
+ if (my $subdefs = $subs_defined_hash->{$linenum}) {
+ $line_stats->{'subdef_info'} = $subdefs;
+ }
+
if (my $subcalls = $subcalls_at_line->{$linenum}) {
+ $line_stats->{'subcall_info'} = $subcalls;
+
my $subcall_count = sum(map { $_->[0] } values %$subcalls);
my $subcall_time = sum(map { $_->[1] } values %$subcalls);
$line_stats->{'subcall_count'} = $subcall_count;
$line_stats->{'subcall_time'} = $subcall_time;
- $line_stats->{'subcall_info'} = $subcalls;
push @{$stats_accum{'subcall_count'}}, $subcall_count;
push @{$stats_accum{'subcall_time'}}, $subcall_time;
}
+
+ if (my $evalcalls = $evals_at_line->{$linenum}) {
+ # %$evals => { fid => $fileinfo } }
+ $line_stats->{'evalcall_info'} = $evalcalls;
+ $line_stats->{'evalcall_count'} = values %$evalcalls;
+
+ # get list of evals, including nested evals
+ my @eval_fis = map { ($_, $_->has_evals(1)) }
values %$evalcalls;
+ $line_stats->{'evalcall_count_nested'} = @eval_fis;
+
+ $line_stats->{'evalcall_stmts_time_nested'} = sum(
+ map { $_->sum_of_stmts_time } @eval_fis);
+ }
$runningTotalTime += $time;
$runningTotalCalls += $a->[1];
@@ -292,8 +284,6 @@
subcall_time =>
calculate_median_absolute_deviation($stats_accum{subcall_time}||[]),
);
- my $subs_defined_hash = $profile->subs_defined_in_file($filestr,
1);
-
# the output file name that will be open later. Not including
directory at this time.
# keep here so that the variable replacement subs can get at it.
my $fname = $meta->{html_safe} . $self->{suffix};
@@ -304,7 +294,7 @@
my $datastart = $self->get_param('datastart', [$profile, $fi]);
my $dataend = $self->get_param('dataend', [$profile, $fi]);
my $FILE = $filestr;
-
+#warn Dumper(\%stats_by_line);
# open output file
#warn "$self->{output_dir}/$fname";
open(OUT, ">", "$self->{output_dir}/$fname")
@@ -324,20 +314,35 @@
my $src_lines = $fi->srclines_array;
if (!$src_lines) { # no savesrc, and no file available
- # ignore synthetic file names that perl assigns when reading
- # code returned by a CODE ref in @INC
- next if $filestr =~ m{^/loader/0x[0-9a-zA-Z]+/};
-
- # the report will not be complete, but this doesn't need to be
fatal
- my $hint = '';
- $hint =
- " Try running $0 in the same directory as you ran
Devel::NYTProf, "
- . "or ensure \...@inc is correct."
- unless $filestr eq '-e'
- or our $_generate_report_inc_hint++;
- my $msg = "Unable to open '$filestr' for reading: $!.$hint\n";
- warn $msg
- unless our
$_generate_report_filestr_warn->{$filestr}++; # only once
+ my $msg;
+ if ($fi->is_eval) {
+ $msg = "No source code available for string eval
$filestr.\nSee savesrc option in documentation.",
+ }
+ elsif ($fi->is_fake) {
+ # eg the "/unknown-eval-invoker"
+ $msg = "No source code available for 'fake' file
$filestr.",
+ }
+ elsif ($filestr =~ m{^/loader/0x[0-9a-zA-Z]+/}) {
+ # a synthetic file name that perl assigns when reading
+ # code returned by a CODE ref in @INC
+ $msg = "No source code available for 'file' loaded via
CODE reference in \...@inc.\nsee savesrc option in documentation.",
+ }
+ else {
+
+ # the report will not be complete, but this doesn't need
to be fatal
+ my $hint = '';
+ $hint = " Try running $0 in the same directory as you ran
Devel::NYTProf, "
+ . "or ensure \...@inc is correct."
+ if $filestr ne '-e'
+ and $filestr !~ m:^/:
+ and not our
$_generate_report_inc_hint++; # only once
+
+ $msg = "Unable to open '$filestr' for reading: $!.$hint\n";
+ warn $msg
+ unless our
$_generate_report_filestr_warn->{$filestr}++; # only once per filestr
+
+ }
+
$src_lines = [ $msg ];
$LINE = 0;
}
@@ -363,7 +368,9 @@
chomp $line;
# detect a series of blank lines, e.g. a chunk of pod savesrc
didn't store
- my $skip_blanks = ($prev_line eq '' && $line eq '' &&
$src_lines->[0] =~ /^\s*$/);
+ my $skip_blanks = ($prev_line eq '' && $line eq '' &&
@$src_lines && $src_lines->[0] =~ /^\s*$/);
+
+ #warn "$LINE: ".join(" ", $prev_line eq '', $line eq '',
$src_lines->[0] =~ /^\s*$/)."\n";
if ($line =~ m/^\# \s* line \s+ (\d+) \b/x) {
# XXX we should be smarter about this - patches welcome!
@@ -377,19 +384,17 @@
($skip_blanks) ? "- -" : $LINE, $line,
$stats_by_line{$LINE} || {},
\%stats_for_file,
- $subs_defined_hash->{$LINE} || [],
- $subcalls_at_line->{$LINE},
$profile,
- $filestr,
- $evals_at_line->{$LINE},
+ $fi,
);
if ($skip_blanks) {
- while ($src_lines->[0] =~ /^\s*$/) {
+ while (@$src_lines and $src_lines->[0] =~ /^\s*$/) {
shift @$src_lines;
$LINE++;
}
- }
+ }
+ $prev_line = $line;
}
continue {
$LINE++;
@@ -416,11 +421,17 @@
sub href_for_file {
- my ($self, $file, $level) = @_;
- $level ||= 'line';
+ my ($self, $file, $anchor, $level) = @_;
+ $level ||= $self->current_level;
+
my $fi = $self->{profile}->fileinfo_of($file);
+ #return undef if $fi->is_eval;
+ return undef if $fi->is_fake;
+
my $href = $fi->meta->{$level}->{html_safe};
$href &&= $href.'.html';
+ $href .= "#$anchor" if defined $anchor;
+
return $href;
}
=======================================
--- /trunk/lib/Devel/NYTProf/SubInfo.pm Sat Feb 20 07:28:32 2010
+++ /trunk/lib/Devel/NYTProf/SubInfo.pm Mon Apr 5 16:22:16 2010
@@ -56,7 +56,10 @@
sub caller_fid_line_places {
my ($self, $merge_evals) = @_;
carp "caller_fid_line_places doesn't merge evals yet" if $merge_evals;
- return $self->[NYTP_SIi_CALLED_BY];
+ # shallow clone to remove fid 0 is_sub hack
+ my %tmp = %{ $self->[NYTP_SIi_CALLED_BY] || {} };
+ delete $tmp{0};
+ return \%tmp;
}
sub called_by_subnames {
=======================================
--- /trunk/t/10-run.t Thu Mar 11 03:02:29 2010
+++ /trunk/t/10-run.t Mon Apr 5 16:22:16 2010
@@ -5,22 +5,54 @@
use NYTProfTest;
# test run_test_group() with extra_test_code and profile_this()
-# also regression test for deflate bug
-# https://rt.cpan.org/Ticket/Display.html?id=50851
use Devel::NYTProf::Run qw(profile_this);
+my @src = (
+ "1+1;\n",
+ "2+2;\n",
+);
+
run_test_group( {
- extra_options => { stmts => 0 }, # RT#50851
- extra_test_count => 1,
+ extra_options => {
+ },
+ extra_test_count => 18,
extra_test_code => sub {
my ($profile, $env) = @_;
$profile = profile_this(
- src_code => "1+1",
+ # tiny amount of source code to exercise RT#50851
+ src_code => join('', @src),
out_file => $env->{file},
skip_sitecustomize => 1,
);
isa_ok $profile, 'Devel::NYTProf::Data';
+
+ my ($fi, @others) = $profile->all_fileinfos;
+ is @others, 0, 'should be one fileinfo';
+
+ is $fi->fid, 1;
+ is $fi->filename, '-'; # profile_this() does "| perl -"
+ is $fi->abs_filename, '-';
+ is $fi->filename_without_inc, '-';
+
+ is $fi->eval_fi, undef;
+ is $fi->eval_fid, ''; # PL_sv_no
+ is $fi->eval_line, ''; # PL_sv_no
+ is_deeply $fi->evals_by_line, {};
+
+ is $fi->profile, $profile;
+ ok not $fi->is_eval;
+ ok not $fi->is_fake;
+ ok not $fi->is_pmc;
+
+ my $line_time_data = $fi->line_time_data;
+ is ref $line_time_data, 'ARRAY';
+
+ is $fi->sum_of_stmts_count, 2;
+
+ # XXX these timings will probably cause test failures
+ cmp_ok $fi->sum_of_stmts_time, '>', 0;
+ cmp_ok $fi->sum_of_stmts_time, '<', 0.001; # should be tiny
},
});
=======================================
--- /trunk/t/lib/NYTProfTest.pm Sat Feb 20 07:28:32 2010
+++ /trunk/t/lib/NYTProfTest.pm Mon Apr 5 16:22:16 2010
@@ -434,7 +434,7 @@
$csvfile =~ s/\.x//;
$csvfile .= ".p" unless $csvfile =~ /\.p/;
$csvfile = html_safe_filename($csvfile);
- $csvfile = "$outdir/${csvfile}-line.csv";
+ $csvfile = "$outdir/${csvfile}-1-line.csv";
unlink $csvfile;
my $cmd = "$perl $nytprofcsv --file=$profile_datafile --out=$outdir";
=======================================
--- /trunk/t/test08.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test08.rdt Mon Apr 5 16:22:16 2010
@@ -13,22 +13,19 @@
attribute total_stmts_measured 0
attribute total_sub_calls 0
attribute xs_version 0
-fid_block_time 1 1 0 0
-fid_block_time 1 1 1 1
-fid_block_time 1 1 2 1 [ 0 1 ]
-fid_block_time 1 1 2 2 [ 0 1 ]
+fid_block_time 1 1 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
+fid_block_time 2 2 [ 0 1 ]
fid_fileinfo 1 [ test08.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 eval 1 [ 1 0 ]
fid_fileinfo 2 [ (eval 0)[test08.p:1] 1 1 2 2 0 0 ]
-fid_line_time 1 1 0 0
-fid_line_time 1 1 1 1
-fid_line_time 1 1 2 1 [ 0 1 ]
-fid_line_time 1 1 2 2 [ 0 1 ]
-fid_sub_time 1 1 0 0
-fid_sub_time 1 1 1 1
-fid_sub_time 1 1 2 1 [ 0 1 ]
-fid_sub_time 1 1 2 2 [ 0 1 ]
+fid_line_time 1 1 [ 0 1 ]
+fid_line_time 2 1 [ 0 1 ]
+fid_line_time 2 2 [ 0 1 ]
+fid_sub_time 1 1 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
+fid_sub_time 2 2 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test09.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test09.rdt Mon Apr 5 16:22:16 2010
@@ -13,17 +13,20 @@
attribute total_stmts_measured 0
attribute total_sub_calls 0
attribute xs_version 0
-fid_block_time 1 2 0 0
-fid_block_time 1 2 1 2
-fid_block_time 1 2 2 1 [ 0 2 ]
-fid_block_time 1 2 2 2 [ 0 2 ]
-fid_block_time 1 2 2 3 [ 0 2 ]
-fid_block_time 1 8 0 0
-fid_block_time 1 8 1 3
-fid_block_time 1 8 2 1 [ 0 3 ]
+fid_block_time 1 2 [ 0 2 ]
+fid_block_time 1 8 [ 0 3 ]
fid_block_time 1 11 [ 0 1 ]
fid_block_time 1 12 [ 0 1 ]
fid_block_time 1 13 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
+fid_block_time 2 2 [ 0 1 ]
+fid_block_time 2 3 [ 0 1 ]
+fid_block_time 3 1 [ 0 1 ]
+fid_block_time 4 1 [ 0 1 ]
+fid_block_time 4 2 [ 0 1 ]
+fid_block_time 4 3 [ 0 1 ]
+fid_block_time 5 1 [ 0 1 ]
+fid_block_time 6 1 [ 0 1 ]
fid_fileinfo 1 [ test09.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::RUNTIME 1-1
@@ -41,28 +44,34 @@
fid_fileinfo 4 call 3 main::bar [ 1 0 0 0 0 0 0
main::foo ]
fid_fileinfo 5 [ (eval 0)[test09.p:8] 1 8 5 2 0 0 ]
fid_fileinfo 6 [ (eval 0)[test09.p:8] 1 8 6 2 0 0 ]
-fid_line_time 1 2 0 0
-fid_line_time 1 2 1 2
-fid_line_time 1 2 2 1 [ 0 2 ]
-fid_line_time 1 2 2 2 [ 0 2 ]
-fid_line_time 1 2 2 3 [ 0 2 ]
-fid_line_time 1 8 0 0
-fid_line_time 1 8 1 3
-fid_line_time 1 8 2 1 [ 0 3 ]
+fid_line_time 1 2 [ 0 2 ]
+fid_line_time 1 8 [ 0 3 ]
fid_line_time 1 11 [ 0 1 ]
fid_line_time 1 12 [ 0 1 ]
fid_line_time 1 13 [ 0 1 ]
-fid_sub_time 1 2 0 0
-fid_sub_time 1 2 1 2
-fid_sub_time 1 2 2 1 [ 0 2 ]
-fid_sub_time 1 2 2 2 [ 0 2 ]
-fid_sub_time 1 2 2 3 [ 0 2 ]
-fid_sub_time 1 8 0 0
-fid_sub_time 1 8 1 3
-fid_sub_time 1 8 2 1 [ 0 3 ]
+fid_line_time 2 1 [ 0 1 ]
+fid_line_time 2 2 [ 0 1 ]
+fid_line_time 2 3 [ 0 1 ]
+fid_line_time 3 1 [ 0 1 ]
+fid_line_time 4 1 [ 0 1 ]
+fid_line_time 4 2 [ 0 1 ]
+fid_line_time 4 3 [ 0 1 ]
+fid_line_time 5 1 [ 0 1 ]
+fid_line_time 6 1 [ 0 1 ]
+fid_sub_time 1 2 [ 0 2 ]
+fid_sub_time 1 8 [ 0 3 ]
fid_sub_time 1 11 [ 0 1 ]
fid_sub_time 1 12 [ 0 1 ]
fid_sub_time 1 13 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
+fid_sub_time 2 2 [ 0 1 ]
+fid_sub_time 2 3 [ 0 1 ]
+fid_sub_time 3 1 [ 0 1 ]
+fid_sub_time 4 1 [ 0 1 ]
+fid_sub_time 4 2 [ 0 1 ]
+fid_sub_time 4 3 [ 0 1 ]
+fid_sub_time 5 1 [ 0 1 ]
+fid_sub_time 6 1 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test10.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test10.rdt Mon Apr 5 16:22:16 2010
@@ -13,11 +13,10 @@
attribute total_stmts_measured 0
attribute total_sub_calls 0
attribute xs_version 0
-fid_block_time 1 1 0 0
-fid_block_time 1 1 1 1
-fid_block_time 1 1 2 1 [ 0 1 ]
-fid_block_time 1 1 2 2 [ 0 1 ]
+fid_block_time 1 1 [ 0 1 ]
fid_block_time 1 2 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
+fid_block_time 2 2 [ 0 1 ]
fid_fileinfo 1 [ test10.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:sleep 0-0
@@ -27,16 +26,14 @@
fid_fileinfo 2 [ (eval 0)[test10.p:1] 1 1 2 2 0 0 ]
fid_fileinfo 2 sub main::__ANON__[(eval 0)[test10.p:1]:1] 1-1
fid_fileinfo 2 call 1 main::CORE:sleep [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test10.p:1]:1] ]
-fid_line_time 1 1 0 0
-fid_line_time 1 1 1 1
-fid_line_time 1 1 2 1 [ 0 1 ]
-fid_line_time 1 1 2 2 [ 0 1 ]
+fid_line_time 1 1 [ 0 1 ]
fid_line_time 1 2 [ 0 1 ]
-fid_sub_time 1 1 0 0
-fid_sub_time 1 1 1 1
-fid_sub_time 1 1 2 1 [ 0 1 ]
-fid_sub_time 1 1 2 2 [ 0 1 ]
+fid_line_time 2 1 [ 0 1 ]
+fid_line_time 2 2 [ 0 1 ]
+fid_sub_time 1 1 [ 0 1 ]
fid_sub_time 1 2 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
+fid_sub_time 2 2 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test11.rdt Thu Jan 21 02:29:41 2010
+++ /trunk/t/test11.rdt Mon Apr 5 16:22:16 2010
@@ -13,11 +13,9 @@
attribute total_stmts_measured 0
attribute total_sub_calls 0
attribute xs_version 0
-fid_block_time 1 3 0 0
-fid_block_time 1 3 1 0
-fid_block_time 1 3 2 1 [ 0 2 ]
fid_block_time 1 5 [ 0 1 ]
fid_block_time 1 6 [ 0 1 ]
+fid_block_time 2 1 [ 0 2 ]
fid_fileinfo 1 [ test11.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 2-4
fid_fileinfo 1 sub main::RUNTIME 1-1
@@ -26,16 +24,12 @@
fid_fileinfo 1 eval 3 [ 1 0 ]
fid_fileinfo 2 [ (eval 0)[test11.p:3] 1 3 2 2 0 0 ]
fid_fileinfo 2 sub main::__ANON__[(eval 0)[test11.p:3]:1] 1-1
-fid_line_time 1 3 0 0
-fid_line_time 1 3 1 0
-fid_line_time 1 3 2 1 [ 0 2 ]
fid_line_time 1 5 [ 0 1 ]
fid_line_time 1 6 [ 0 1 ]
-fid_sub_time 1 3 0 0
-fid_sub_time 1 3 1 0
-fid_sub_time 1 3 2 1 [ 0 2 ]
+fid_line_time 2 1 [ 0 2 ]
fid_sub_time 1 5 [ 0 1 ]
fid_sub_time 1 6 [ 0 1 ]
+fid_sub_time 2 1 [ 0 2 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test11.x Wed Jul 9 12:54:59 2008
+++ /trunk/t/test11.x Mon Apr 5 16:22:16 2010
@@ -3,7 +3,7 @@
# Format: time,calls,time/call,code
0,0,0,use vars qw/$b/;
0,0,0,BEGIN {
-0,1,0,$b = eval "sub {1}";
+0,0,0,$b = eval "sub {1}";
0,0,0,}
0,1,0,&$b;
0,1,0,&$b;
=======================================
--- /trunk/t/test13.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test13.rdt Mon Apr 5 16:22:16 2010
@@ -18,11 +18,10 @@
fid_block_time 1 12 [ 0 3 ]
fid_block_time 1 13 [ 0 2 ]
fid_block_time 1 15 [ 0 1 ]
-fid_block_time 1 19 0 0
-fid_block_time 1 19 1 1
-fid_block_time 1 19 2 1 [ 0 1 ]
+fid_block_time 1 19 [ 0 1 ]
fid_block_time 1 20 [ 0 2 ]
fid_block_time 1 21 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
fid_fileinfo 1 [ test13.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:print 0-0
@@ -47,19 +46,17 @@
fid_line_time 1 13 [ 0 2 ]
fid_line_time 1 14 [ 0 1 ]
fid_line_time 1 15 [ 0 2 ]
-fid_line_time 1 19 0 0
-fid_line_time 1 19 1 1
-fid_line_time 1 19 2 1 [ 0 1 ]
+fid_line_time 1 19 [ 0 1 ]
fid_line_time 1 20 [ 0 2 ]
fid_line_time 1 21 [ 0 1 ]
+fid_line_time 2 1 [ 0 1 ]
fid_sub_time 1 4 [ 0 3 ]
fid_sub_time 1 8 [ 0 1 ]
fid_sub_time 1 12 [ 0 6 ]
-fid_sub_time 1 19 0 0
-fid_sub_time 1 19 1 1
-fid_sub_time 1 19 2 1 [ 0 1 ]
+fid_sub_time 1 19 [ 0 1 ]
fid_sub_time 1 20 [ 0 2 ]
fid_sub_time 1 21 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test14.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test14.rdt Mon Apr 5 16:22:16 2010
@@ -18,10 +18,9 @@
fid_block_time 1 19 [ 0 1 ]
fid_block_time 2 8 [ 0 1 ]
fid_block_time 2 13 [ 0 1 ]
-fid_block_time 2 17 0 0
-fid_block_time 2 17 1 2
-fid_block_time 2 17 2 1 [ 0 1 ]
+fid_block_time 2 17 [ 0 2 ]
fid_block_time 2 20 [ 0 1 ]
+fid_block_time 4 1 [ 0 1 ]
fid_fileinfo 1 [ test14.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 16-16
fid_fileinfo 1 sub main::RUNTIME 1-1
@@ -41,19 +40,17 @@
fid_line_time 1 19 [ 0 1 ]
fid_line_time 2 8 [ 0 1 ]
fid_line_time 2 13 [ 0 1 ]
-fid_line_time 2 17 0 0
-fid_line_time 2 17 1 2
-fid_line_time 2 17 2 1 [ 0 1 ]
+fid_line_time 2 17 [ 0 2 ]
fid_line_time 2 20 [ 0 1 ]
+fid_line_time 4 1 [ 0 1 ]
fid_sub_time 1 17 [ 0 1 ]
fid_sub_time 1 18 [ 0 1 ]
fid_sub_time 1 19 [ 0 1 ]
fid_sub_time 2 8 [ 0 1 ]
fid_sub_time 2 13 [ 0 1 ]
-fid_sub_time 2 17 0 0
-fid_sub_time 2 17 1 2
-fid_sub_time 2 17 2 1 [ 0 1 ]
+fid_sub_time 2 17 [ 0 2 ]
fid_sub_time 2 20 [ 0 1 ]
+fid_sub_time 4 1 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
@@ -61,6 +58,8 @@
sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
sub_subinfo test14::BEGIN [ 2 2 2 0 0 0 0 0 ]
sub_subinfo test14::bar [ 2 16 18 1 0 0 0 0 ]
+sub_subinfo test14::bar called_by 3 51 [ 1 0 0 0 0 0 0
main::RUNTIME ]
sub_subinfo test14::foo [ 2 12 14 1 0 0 0 0 ]
+sub_subinfo test14::foo called_by 3 51 [ 1 0 0 0 0 0 0
main::RUNTIME ]
sub_subinfo test14::pre [ 2 8 8 1 0 0 0 0 ]
sub_subinfo test14::pre called_by 1 17 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test20-streval.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test20-streval.rdt Mon Apr 5 16:22:16 2010
@@ -15,15 +15,14 @@
attribute xs_version 0
fid_block_time 1 3 [ 0 4 ]
fid_block_time 1 5 [ 0 1 ]
-fid_block_time 1 8 0 0
-fid_block_time 1 8 1 1
-fid_block_time 1 8 2 1 [ 0 1 ]
-fid_block_time 1 11 0 0
-fid_block_time 1 11 1 2
-fid_block_time 1 11 2 1 [ 0 2 ]
-fid_block_time 1 14 0 0
-fid_block_time 1 14 1 1
-fid_block_time 1 14 2 1 [ 0 2 ]
+fid_block_time 1 8 [ 0 1 ]
+fid_block_time 1 11 [ 0 2 ]
+fid_block_time 1 14 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
+fid_block_time 3 1 [ 0 1 ]
+fid_block_time 4 1 [ 0 1 ]
+fid_block_time 5 1 [ 0 1 ]
+fid_block_time 6 1 [ 0 1 ]
fid_fileinfo 1 [ test20-streval.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:print 0-0
@@ -45,26 +44,24 @@
fid_fileinfo 6 call 1 main::foo [ 1 0 0 0 0 0 0
main::RUNTIME ]
fid_line_time 1 3 [ 0 4 ]
fid_line_time 1 5 [ 0 1 ]
-fid_line_time 1 8 0 0
-fid_line_time 1 8 1 1
-fid_line_time 1 8 2 1 [ 0 1 ]
-fid_line_time 1 11 0 0
-fid_line_time 1 11 1 2
-fid_line_time 1 11 2 1 [ 0 2 ]
-fid_line_time 1 14 0 0
-fid_line_time 1 14 1 1
-fid_line_time 1 14 2 1 [ 0 2 ]
+fid_line_time 1 8 [ 0 1 ]
+fid_line_time 1 11 [ 0 2 ]
+fid_line_time 1 14 [ 0 1 ]
+fid_line_time 2 1 [ 0 1 ]
+fid_line_time 3 1 [ 0 1 ]
+fid_line_time 4 1 [ 0 1 ]
+fid_line_time 5 1 [ 0 1 ]
+fid_line_time 6 1 [ 0 1 ]
fid_sub_time 1 3 [ 0 4 ]
fid_sub_time 1 5 [ 0 1 ]
-fid_sub_time 1 8 0 0
-fid_sub_time 1 8 1 1
-fid_sub_time 1 8 2 1 [ 0 1 ]
-fid_sub_time 1 11 0 0
-fid_sub_time 1 11 1 2
-fid_sub_time 1 11 2 1 [ 0 2 ]
-fid_sub_time 1 14 0 0
-fid_sub_time 1 14 1 1
-fid_sub_time 1 14 2 1 [ 0 2 ]
+fid_sub_time 1 8 [ 0 1 ]
+fid_sub_time 1 11 [ 0 2 ]
+fid_sub_time 1 14 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
+fid_sub_time 3 1 [ 0 1 ]
+fid_sub_time 4 1 [ 0 1 ]
+fid_sub_time 5 1 [ 0 1 ]
+fid_sub_time 6 1 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test21-streval3.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test21-streval3.rdt Mon Apr 5 16:22:16 2010
@@ -15,11 +15,15 @@
attribute xs_version 0
fid_block_time 1 4 [ 0 3 ]
fid_block_time 1 5 [ 0 1 ]
-fid_block_time 1 17 0 0
-fid_block_time 1 17 1 1
-fid_block_time 1 17 2 2 [ 0 3 ]
-fid_block_time 1 17 2 3 [ 0 3 ]
-fid_block_time 1 17 2 4 [ 0 2 ]
+fid_block_time 1 17 [ 0 1 ]
+fid_block_time 2 2 [ 0 1 ]
+fid_block_time 2 3 [ 0 1 ]
+fid_block_time 2 4 [ 0 1 ]
+fid_block_time 3 2 [ 0 1 ]
+fid_block_time 3 3 [ 0 1 ]
+fid_block_time 3 4 [ 0 1 ]
+fid_block_time 4 2 [ 0 1 ]
+fid_block_time 4 3 [ 0 1 ]
fid_fileinfo 1 [ test21-streval3.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:sselect 0-0
@@ -39,18 +43,26 @@
fid_fileinfo 4 call 3 main::foo [ 1 0 0 0 0 0 0
main::RUNTIME ]
fid_line_time 1 4 [ 0 3 ]
fid_line_time 1 5 [ 0 1 ]
-fid_line_time 1 17 0 0
-fid_line_time 1 17 1 1
-fid_line_time 1 17 2 2 [ 0 3 ]
-fid_line_time 1 17 2 3 [ 0 3 ]
-fid_line_time 1 17 2 4 [ 0 2 ]
+fid_line_time 1 17 [ 0 1 ]
+fid_line_time 2 2 [ 0 1 ]
+fid_line_time 2 3 [ 0 1 ]
+fid_line_time 2 4 [ 0 1 ]
+fid_line_time 3 2 [ 0 1 ]
+fid_line_time 3 3 [ 0 1 ]
+fid_line_time 3 4 [ 0 1 ]
+fid_line_time 4 2 [ 0 1 ]
+fid_line_time 4 3 [ 0 1 ]
fid_sub_time 1 4 [ 0 3 ]
fid_sub_time 1 5 [ 0 1 ]
-fid_sub_time 1 17 0 0
-fid_sub_time 1 17 1 1
-fid_sub_time 1 17 2 2 [ 0 3 ]
-fid_sub_time 1 17 2 3 [ 0 3 ]
-fid_sub_time 1 17 2 4 [ 0 2 ]
+fid_sub_time 1 17 [ 0 1 ]
+fid_sub_time 2 2 [ 0 1 ]
+fid_sub_time 2 3 [ 0 1 ]
+fid_sub_time 2 4 [ 0 1 ]
+fid_sub_time 3 2 [ 0 1 ]
+fid_sub_time 3 3 [ 0 1 ]
+fid_sub_time 3 4 [ 0 1 ]
+fid_sub_time 4 2 [ 0 1 ]
+fid_sub_time 4 3 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test22-strevala.rdt Thu Jan 21 02:29:41 2010
+++ /trunk/t/test22-strevala.rdt Mon Apr 5 16:22:16 2010
@@ -14,18 +14,20 @@
attribute total_sub_calls 0
attribute xs_version 0
fid_block_time 1 3 [ 0 1 ]
-fid_block_time 1 6 0 0
-fid_block_time 1 6 1 1
-fid_block_time 1 6 2 1 [ 0 1 ]
-fid_block_time 1 6 2 2 [ 0 1 ]
-fid_block_time 1 9 0 0
-fid_block_time 1 9 1 2
-fid_block_time 1 9 2 1 [ 0 2 ]
-fid_block_time 1 9 2 2 [ 0 2 ]
-fid_block_time 1 12 0 0
-fid_block_time 1 12 1 1
-fid_block_time 1 12 2 1 [ 0 2 ]
-fid_block_time 1 12 2 2 [ 0 4 ]
+fid_block_time 1 6 [ 0 1 ]
+fid_block_time 1 9 [ 0 2 ]
+fid_block_time 1 12 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
+fid_block_time 2 2 [ 0 1 ]
+fid_block_time 3 1 [ 0 1 ]
+fid_block_time 3 2 [ 0 1 ]
+fid_block_time 4 1 [ 0 1 ]
+fid_block_time 4 2 [ 0 1 ]
+fid_block_time 5 2 [ 0 2 ]
+fid_block_time 6 1 [ 0 1 ]
+fid_block_time 6 2 [ 0 1 ]
+fid_block_time 7 1 [ 0 1 ]
+fid_block_time 7 2 [ 0 1 ]
fid_fileinfo 1 [ test22-strevala.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:print 0-0
@@ -54,31 +56,35 @@
fid_fileinfo 7 sub main::__ANON__[(eval 0)[(eval
0)[test22-strevala.p:12]:2]:1] 1-1
fid_fileinfo 7 call 1 main::CORE:print [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] ]
fid_line_time 1 3 [ 0 1 ]
-fid_line_time 1 6 0 0
-fid_line_time 1 6 1 1
-fid_line_time 1 6 2 1 [ 0 1 ]
-fid_line_time 1 6 2 2 [ 0 1 ]
-fid_line_time 1 9 0 0
-fid_line_time 1 9 1 2
-fid_line_time 1 9 2 1 [ 0 2 ]
-fid_line_time 1 9 2 2 [ 0 2 ]
-fid_line_time 1 12 0 0
-fid_line_time 1 12 1 1
-fid_line_time 1 12 2 1 [ 0 2 ]
-fid_line_time 1 12 2 2 [ 0 4 ]
+fid_line_time 1 6 [ 0 1 ]
+fid_line_time 1 9 [ 0 2 ]
+fid_line_time 1 12 [ 0 1 ]
+fid_line_time 2 1 [ 0 1 ]
+fid_line_time 2 2 [ 0 1 ]
+fid_line_time 3 1 [ 0 1 ]
+fid_line_time 3 2 [ 0 1 ]
+fid_line_time 4 1 [ 0 1 ]
+fid_line_time 4 2 [ 0 1 ]
+fid_line_time 5 2 [ 0 2 ]
+fid_line_time 6 1 [ 0 1 ]
+fid_line_time 6 2 [ 0 1 ]
+fid_line_time 7 1 [ 0 1 ]
+fid_line_time 7 2 [ 0 1 ]
fid_sub_time 1 3 [ 0 1 ]
-fid_sub_time 1 6 0 0
-fid_sub_time 1 6 1 1
-fid_sub_time 1 6 2 1 [ 0 1 ]
-fid_sub_time 1 6 2 2 [ 0 1 ]
-fid_sub_time 1 9 0 0
-fid_sub_time 1 9 1 2
-fid_sub_time 1 9 2 1 [ 0 2 ]
-fid_sub_time 1 9 2 2 [ 0 2 ]
-fid_sub_time 1 12 0 0
-fid_sub_time 1 12 1 1
-fid_sub_time 1 12 2 1 [ 0 2 ]
-fid_sub_time 1 12 2 2 [ 0 4 ]
+fid_sub_time 1 6 [ 0 1 ]
+fid_sub_time 1 9 [ 0 2 ]
+fid_sub_time 1 12 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
+fid_sub_time 2 2 [ 0 1 ]
+fid_sub_time 3 1 [ 0 1 ]
+fid_sub_time 3 2 [ 0 1 ]
+fid_sub_time 4 1 [ 0 1 ]
+fid_sub_time 4 2 [ 0 1 ]
+fid_sub_time 5 2 [ 0 2 ]
+fid_sub_time 6 1 [ 0 1 ]
+fid_sub_time 6 2 [ 0 1 ]
+fid_sub_time 7 1 [ 0 1 ]
+fid_sub_time 7 2 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test23-strevall.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test23-strevall.rdt Mon Apr 5 16:22:16 2010
@@ -14,22 +14,16 @@
attribute total_sub_calls 0
attribute xs_version 0
fid_block_time 1 4 [ 0 1 ]
-fid_block_time 3 1 0 0
-fid_block_time 3 1 1 0
-fid_block_time 3 1 2 45 [ 0 1 ]
+fid_block_time 2 45 [ 0 1 ]
fid_fileinfo 1 [ test23-strevall.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 2 [ (eval 0) 3 1 2 2 0 0 ]
fid_fileinfo 3 [ /unknown-eval-invoker 3 130 0 0 ]
fid_fileinfo 3 eval 1 [ 1 0 ]
fid_line_time 1 4 [ 0 1 ]
-fid_line_time 3 1 0 0
-fid_line_time 3 1 1 0
-fid_line_time 3 1 2 45 [ 0 1 ]
+fid_line_time 2 45 [ 0 1 ]
fid_sub_time 1 4 [ 0 1 ]
-fid_sub_time 3 1 0 0
-fid_sub_time 3 1 1 0
-fid_sub_time 3 1 2 45 [ 0 1 ]
+fid_sub_time 2 45 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test51-enable.rdt Thu Jan 21 02:29:41 2010
+++ /trunk/t/test51-enable.rdt Mon Apr 5 16:22:16 2010
@@ -16,10 +16,9 @@
fid_block_time 1 3 [ 0 1 ]
fid_block_time 1 4 [ 0 1 ]
fid_block_time 1 5 [ 0 1 ]
-fid_block_time 1 7 0 0
-fid_block_time 1 7 1 2
-fid_block_time 1 7 2 1 [ 0 1 ]
+fid_block_time 1 7 [ 0 2 ]
fid_block_time 1 9 [ 0 1 ]
+fid_block_time 2 1 [ 0 1 ]
fid_fileinfo 1 [ test51-enable.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:unlink 0-0
@@ -33,17 +32,15 @@
fid_line_time 1 3 [ 0 1 ]
fid_line_time 1 4 [ 0 1 ]
fid_line_time 1 5 [ 0 1 ]
-fid_line_time 1 7 0 0
-fid_line_time 1 7 1 2
-fid_line_time 1 7 2 1 [ 0 1 ]
+fid_line_time 1 7 [ 0 2 ]
fid_line_time 1 9 [ 0 1 ]
+fid_line_time 2 1 [ 0 1 ]
fid_sub_time 1 3 [ 0 1 ]
fid_sub_time 1 4 [ 0 1 ]
fid_sub_time 1 5 [ 0 1 ]
-fid_sub_time 1 7 0 0
-fid_sub_time 1 7 1 2
-fid_sub_time 1 7 2 1 [ 0 1 ]
+fid_sub_time 1 7 [ 0 2 ]
fid_sub_time 1 9 [ 0 1 ]
+fid_sub_time 2 1 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
=======================================
--- /trunk/t/test61-submerge.rdt Thu Jan 21 02:29:41 2010
+++ /trunk/t/test61-submerge.rdt Mon Apr 5 16:22:16 2010
@@ -15,10 +15,13 @@
attribute xs_version 0
fid_block_time 1 4 [ 0 3 ]
fid_block_time 1 6 [ 0 1 ]
-fid_block_time 1 8 0 0
-fid_block_time 1 8 1 2
-fid_block_time 1 8 2 1 [ 0 3 ]
-fid_block_time 1 8 2 2 [ 0 3 ]
+fid_block_time 1 8 [ 0 2 ]
+fid_block_time 2 1 [ 0 1 ]
+fid_block_time 2 2 [ 0 1 ]
+fid_block_time 3 1 [ 0 1 ]
+fid_block_time 3 2 [ 0 1 ]
+fid_block_time 4 1 [ 0 1 ]
+fid_block_time 4 2 [ 0 1 ]
fid_fileinfo 1 [ test61-submerge.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 0-0
fid_fileinfo 1 sub main::CORE:print 0-0
@@ -38,16 +41,22 @@
fid_fileinfo 4 call 1 main::foo [ 1 0 0 0 0 0 0 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
fid_line_time 1 4 [ 0 3 ]
fid_line_time 1 6 [ 0 1 ]
-fid_line_time 1 8 0 0
-fid_line_time 1 8 1 2
-fid_line_time 1 8 2 1 [ 0 3 ]
-fid_line_time 1 8 2 2 [ 0 3 ]
+fid_line_time 1 8 [ 0 2 ]
+fid_line_time 2 1 [ 0 1 ]
+fid_line_time 2 2 [ 0 1 ]
+fid_line_time 3 1 [ 0 1 ]
+fid_line_time 3 2 [ 0 1 ]
+fid_line_time 4 1 [ 0 1 ]
+fid_line_time 4 2 [ 0 1 ]
fid_sub_time 1 4 [ 0 3 ]
fid_sub_time 1 6 [ 0 1 ]
-fid_sub_time 1 8 0 0
-fid_sub_time 1 8 1 2
-fid_sub_time 1 8 2 1 [ 0 3 ]
-fid_sub_time 1 8 2 2 [ 0 3 ]
+fid_sub_time 1 8 [ 0 2 ]
+fid_sub_time 2 1 [ 0 1 ]
+fid_sub_time 2 2 [ 0 1 ]
+fid_sub_time 3 1 [ 0 1 ]
+fid_sub_time 3 2 [ 0 1 ]
+fid_sub_time 4 1 [ 0 1 ]
+fid_sub_time 4 2 [ 0 1 ]
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
--
You've received this message because you are subscribed to
the Devel::NYTProf Development User group.
Group hosted at: http://groups.google.com/group/develnytprof-dev
Project hosted at: http://perl-devel-nytprof.googlecode.com
CPAN distribution: http://search.cpan.org/dist/Devel-NYTProf
To post, email: [email protected]
To unsubscribe, email: [email protected]
To unsubscribe, reply using "remove me" as the subject.
