Author: tim.bunce
Date: Mon Jan 19 06:04:11 2009
New Revision: 670
Modified:
trunk/NYTProf.xs
trunk/lib/Devel/NYTProf/SubInfo.pm
trunk/t/test10.rdt
trunk/t/test11.rdt
trunk/t/test22-strevala.rdt
trunk/t/test61-submerge.rdt
Log:
Rewrite all "(eval \d+)" to "(eval 0)" while reading the profile data.
Merge data for subs that now have the same name (e.g. __ANON__[(eval
0)[foo.pl:1]:1])
Adjust expected test results to match.
Modified: trunk/NYTProf.xs
==============================================================================
--- trunk/NYTProf.xs (original)
+++ trunk/NYTProf.xs Mon Jan 19 06:04:11 2009
@@ -2791,8 +2791,6 @@
char *src = start;
char *dst = start;
- return sv; /* XXX currently disabled */
-
if (len < 5)
return sv;
@@ -3274,18 +3272,28 @@
warn("Sub %s fid %u lines %u..%u\n",
subname_pv, fid, first_line, last_line);
av = lookup_subinfo_av(aTHX_ subname_sv, sub_subinfo_hv);
- if (SvOK(*av_fetch(av, NYTP_SIi_FID, 1)))
- warn("Sub %s already defined!", subname_pv);
- sv_setuv(*av_fetch(av, NYTP_SIi_FID, 1), fid);
- sv_setuv(*av_fetch(av, NYTP_SIi_FIRST_LINE, 1),
first_line);
- sv_setuv(*av_fetch(av, NYTP_SIi_LAST_LINE, 1), last_line);
- sv_setuv(*av_fetch(av, NYTP_SIi_CALL_COUNT, 1), 0); /*
call count */
- sv_setnv(*av_fetch(av, NYTP_SIi_INCL_RTIME, 1), 0.0); /*
incl_time */
- sv_setnv(*av_fetch(av, NYTP_SIi_EXCL_RTIME, 1), 0.0); /*
excl_time */
- sv_setsv(*av_fetch(av, NYTP_SIi_SUB_NAME, 1),
subname_sv);
- sv_setsv(*av_fetch(av, NYTP_SIi_PROFILE, 1),
&PL_sv_undef); /* ref to profile */
- sv_setuv(*av_fetch(av, NYTP_SIi_REC_DEPTH, 1), 0); /*
rec_depth */
- sv_setnv(*av_fetch(av, NYTP_SIi_RECI_RTIME, 1), 0.0); /*
reci_time */
+ if (SvOK(*av_fetch(av, NYTP_SIi_FID, 1))) {
+ /* should only happen for anon subs in string evals */
+ /* so we warn for other cases */
+ if (!instr(subname_pv, "__ANON__[(eval"))
+ warn("Sub %s already defined!", subname_pv);
+ /* XXX we simply discard fid etc here,
+ * though the fileinfo NYTP_FIDi_SUBS_DEFINED hash
does get
+ * an entry for the sub from each fid (ie eval) that
defines it
+ */
+ }
+ else {
+ sv_setuv(*av_fetch(av, NYTP_SIi_FID, 1), fid);
+ sv_setuv(*av_fetch(av, NYTP_SIi_FIRST_LINE, 1),
first_line);
+ sv_setuv(*av_fetch(av, NYTP_SIi_LAST_LINE, 1),
last_line);
+ sv_setuv(*av_fetch(av, NYTP_SIi_CALL_COUNT, 1), 0);
/* call count */
+ sv_setnv(*av_fetch(av, NYTP_SIi_INCL_RTIME, 1), 0.0);
/* incl_time */
+ sv_setnv(*av_fetch(av, NYTP_SIi_EXCL_RTIME, 1), 0.0);
/* excl_time */
+ sv_setsv(*av_fetch(av, NYTP_SIi_SUB_NAME, 1),
subname_sv);
+ sv_setsv(*av_fetch(av, NYTP_SIi_PROFILE, 1),
&PL_sv_undef); /* ref to profile */
+ sv_setuv(*av_fetch(av, NYTP_SIi_REC_DEPTH, 1), 0);
/* rec_depth */
+ sv_setnv(*av_fetch(av, NYTP_SIi_RECI_RTIME, 1), 0.0);
/* reci_time */
+ }
/* add sub to NYTP_FIDi_SUBS_DEFINED hash */
sv = SvRV(*av_fetch(fid_fileinfo_av, fid, 1));
@@ -3353,22 +3361,31 @@
if (fid) {
SV *fi;
+ AV *av;
len = sprintf(text, "%u", line);
sv = *hv_fetch((HV*)SvRV(sv), text, len, 1);
if (!SvROK(sv)) /* autoviv */
sv_setsv(sv, newRV_noinc((SV*)newAV()));
- else /* XXX the code below should accumulate instead
of set values */
- warn("sub caller info for %s %d:%d already
exists!",
+ else if
(!instr(SvPV_nolen(subname_sv), "__ANON__[(eval") || trace_level)
+ warn("Merging extra sub caller info for %s %d:%d",
SvPV_nolen(subname_sv), fid, line);
- sv = SvRV(sv);
- sv_setuv(*av_fetch((AV *)sv, NYTP_SCi_CALL_COUNT, 1),
count);
- sv_setnv(*av_fetch((AV *)sv, NYTP_SCi_INCL_RTIME, 1),
incl_time);
- sv_setnv(*av_fetch((AV *)sv, NYTP_SCi_EXCL_RTIME, 1),
excl_time);
- sv_setnv(*av_fetch((AV *)sv, NYTP_SCi_INCL_UTIME, 1),
ucpu_time);
- sv_setnv(*av_fetch((AV *)sv, NYTP_SCi_INCL_STIME, 1),
scpu_time);
- sv_setnv(*av_fetch((AV *)sv, NYTP_SCi_RECI_RTIME, 1),
reci_time);
- sv_setuv(*av_fetch((AV *)sv, NYTP_SCi_REC_DEPTH, 1),
rec_depth);
+ av = (AV *)SvRV(sv);
+ sv = *av_fetch(av, NYTP_SCi_CALL_COUNT, 1);
+ sv_setuv(sv, (SvOK(sv)) ? SvUV(sv) + count : count);
+ sv = *av_fetch(av, NYTP_SCi_INCL_RTIME, 1);
+ sv_setnv(sv, (SvOK(sv)) ? SvNV(sv) + incl_time :
incl_time);
+ sv = *av_fetch(av, NYTP_SCi_EXCL_RTIME, 1);
+ sv_setnv(sv, (SvOK(sv)) ? SvNV(sv) + excl_time :
excl_time);
+ sv = *av_fetch(av, NYTP_SCi_INCL_UTIME, 1);
+ sv_setnv(sv, (SvOK(sv)) ? SvNV(sv) + ucpu_time :
ucpu_time);
+ sv = *av_fetch(av, NYTP_SCi_INCL_STIME, 1);
+ sv_setnv(sv, (SvOK(sv)) ? SvNV(sv) + scpu_time :
scpu_time);
+ sv = *av_fetch(av, NYTP_SCi_RECI_RTIME, 1);
+ sv_setnv(sv, (SvOK(sv)) ? SvNV(sv) + scpu_time :
reci_time);
+ sv = *av_fetch(av, NYTP_SCi_REC_DEPTH, 1);
+ if (!SvOK(sv) || SvUV(sv) < rec_depth) /* max() */
+ sv_setuv(sv, rec_depth);
/* add sub call to NYTP_FIDi_SUBS_CALLED hash of fid
making the call */
/* => { line => { subname => [ ... ] } } */
@@ -3378,7 +3395,7 @@
if (!SvROK(fi)) /* autoviv */
sv_setsv(fi, newRV_noinc((SV*)newHV()));
fi = HeVAL(hv_fetch_ent((HV *)SvRV(fi), subname_sv, 1,
0));
- sv_setsv(fi, newRV(sv));
+ sv_setsv(fi, newRV((SV *)av));
}
else { /* is meta-data about
sub */
/* line == 0: is_xs - set line range to 0,0 as marker
*/
Modified: trunk/lib/Devel/NYTProf/SubInfo.pm
==============================================================================
--- trunk/lib/Devel/NYTProf/SubInfo.pm (original)
+++ trunk/lib/Devel/NYTProf/SubInfo.pm Mon Jan 19 06:04:11 2009
@@ -81,6 +81,8 @@
my $self = shift;
my $new = shift;
+ # see also "case NYTP_TAG_SUB_CALLERS:" in
load_profile_data_from_stream()
+
$self->[NYTP_SIi_FIRST_LINE] = min($self->[NYTP_SIi_FIRST_LINE],
$new->[NYTP_SIi_FIRST_LINE])
if defined $new->[NYTP_SIi_FIRST_LINE];
$self->[NYTP_SIi_LAST_LINE] = max($self->[NYTP_SIi_LAST_LINE],
$new->[NYTP_SIi_LAST_LINE])
@@ -91,8 +93,9 @@
$self->[NYTP_SIi_SUB_NAME] = [ $self->[NYTP_SIi_SUB_NAME] ]
if not ref $self->[NYTP_SIi_SUB_NAME];
push @{$self->[NYTP_SIi_SUB_NAME]}, $new->[NYTP_SIi_SUB_NAME];
- $self->[NYTP_SIi_REC_DEPTH] = max($self->[NYTP_SIi_REC_DEPTH],
$new->[NYTP_SIi_REC_DEPTH]);
- $self->[NYTP_SIi_RECI_RTIME] = max($self->[NYTP_SIi_RECI_RTIME],
$new->[NYTP_SIi_RECI_RTIME]); # ug, plausible
+ $self->[NYTP_SIi_REC_DEPTH] = max($self->[NYTP_SIi_REC_DEPTH],
$new->[NYTP_SIi_REC_DEPTH]);
+ # adding reci_rtime is correct only if one sub doesn't call the other
+ $self->[NYTP_SIi_RECI_RTIME] += $new->[NYTP_SIi_RECI_RTIME]; # XXX
# { fid => { line => [ count, incl_time ] } }
my $dst_called_by = $self->[NYTP_SIi_CALLED_BY] ||= {};
Modified: trunk/t/test10.rdt
==============================================================================
--- trunk/t/test10.rdt (original)
+++ trunk/t/test10.rdt Mon Jan 19 06:04:11 2009
@@ -18,7 +18,7 @@
fid_block_time 1 1 2 2 [ 0 1 ]
fid_block_time 1 2 [ 0 1 ]
fid_fileinfo 1 [ test10.p 1 2 0 0 ]
-fid_fileinfo 1 call 2 main::__ANON__[(eval 1)[test10.p:1]:1]
[ 1 0 0 0 0 0
0 ]
+fid_fileinfo 1 call 2 main::__ANON__[(eval 0)[test10.p:1]:1]
[ 1 0 0 0 0 0
0 ]
fid_fileinfo 1 eval 1 [ 1 0 ]
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
Modified: trunk/t/test11.rdt
==============================================================================
--- trunk/t/test11.rdt (original)
+++ trunk/t/test11.rdt Mon Jan 19 06:04:11 2009
@@ -19,8 +19,8 @@
fid_block_time 1 6 [ 0 1 ]
fid_fileinfo 1 [ test11.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 2-4
-fid_fileinfo 1 call 5 main::__ANON__[(eval 1)[test11.p:3]:1]
[ 1 0 0 0 0 0
0 ]
-fid_fileinfo 1 call 6 main::__ANON__[(eval 1)[test11.p:3]:1]
[ 1 0 0 0 0 0
0 ]
+fid_fileinfo 1 call 5 main::__ANON__[(eval 0)[test11.p:3]:1]
[ 1 0 0 0 0 0
0 ]
+fid_fileinfo 1 call 6 main::__ANON__[(eval 0)[test11.p:3]:1]
[ 1 0 0 0 0 0
0 ]
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
Modified: trunk/t/test22-strevala.rdt
==============================================================================
--- trunk/t/test22-strevala.rdt (original)
+++ trunk/t/test22-strevala.rdt Mon Jan 19 06:04:11 2009
@@ -26,26 +26,24 @@
fid_block_time 1 12 2 1 [ 0 2 ]
fid_block_time 1 12 2 2 [ 0 4 ]
fid_fileinfo 1 [ test22-strevala.p 1 2 0 0 ]
-fid_fileinfo 1 call 6 main::__ANON__[(eval
1)[test22-strevala.p:6]:1] [ 1
0 0 0 0 0 0 ]
-fid_fileinfo 1 call 9 main::__ANON__[(eval
2)[test22-strevala.p:9]:1] [ 1
0 0 0 0 0 0 ]
-fid_fileinfo 1 call 9 main::__ANON__[(eval
3)[test22-strevala.p:9]:1] [ 1
0 0 0 0 0 0 ]
+fid_fileinfo 1 call 6 main::__ANON__[(eval
0)[test22-strevala.p:6]:1] [ 1
0 0 0 0 0 0 ]
+fid_fileinfo 1 call 9 main::__ANON__[(eval
0)[test22-strevala.p:9]:1] [ 2
0 0 0 0 0 0 ]
fid_fileinfo 1 eval 6 [ 1 0 ]
fid_fileinfo 1 eval 9 [ 2 0 ]
fid_fileinfo 1 eval 12 [ 1 2 ]
fid_fileinfo 2 [ (eval 0)[test22-strevala.p:6] 1 6 2 2 0 0 ]
fid_fileinfo 2 sub main::__ANON__[(eval 0)[test22-strevala.p:6]:1]
1-1
fid_fileinfo 3 [ (eval 0)[test22-strevala.p:9] 1 9 3 2 0 0 ]
-fid_fileinfo 3 sub main::__ANON__[(eval 0)[test22-strevala.p:9]:1]
and
main::__ANON__[(eval 3)[test22-strevala.p:9]:1] 1-1
+fid_fileinfo 3 sub main::__ANON__[(eval 0)[test22-strevala.p:9]:1]
1-1
fid_fileinfo 4 [ (eval 0)[test22-strevala.p:9] 1 9 4 2 0 0 ]
-fid_fileinfo 4 sub main::__ANON__[(eval 3)[test22-strevala.p:9]:1]
1-1
+fid_fileinfo 4 sub main::__ANON__[(eval 0)[test22-strevala.p:9]:1]
1-1
fid_fileinfo 5 [ (eval 0)[test22-strevala.p:12] 1 12 5 2 0 0 ]
-fid_fileinfo 5 call 2 main::__ANON__[(eval 5)[(eval
4)[test22-strevala.p:12]:2]:1] [ 1 0 0 0 0 0 0 ]
-fid_fileinfo 5 call 2 main::__ANON__[(eval 6)[(eval
4)[test22-strevala.p:12]:2]:1] [ 1 0 0 0 0 0 0 ]
+fid_fileinfo 5 call 2 main::__ANON__[(eval 0)[(eval
0)[test22-strevala.p:12]:2]:1] [ 2 0 0 0 0 0 0 ]
fid_fileinfo 5 eval 2 [ 2 0 ]
fid_fileinfo 6 [ (eval 0)[(eval 0)[test22-strevala.p:12]:2] 5 2 6 2 0
0 ]
-fid_fileinfo 6 sub main::__ANON__[(eval 5)[(eval
4)[test22-strevala.p:12]:2]:1] 1-1
+fid_fileinfo 6 sub main::__ANON__[(eval 0)[(eval
0)[test22-strevala.p:12]:2]:1] 1-1
fid_fileinfo 7 [ (eval 0)[(eval 0)[test22-strevala.p:12]:2] 5 2 7 2 0
0 ]
-fid_fileinfo 7 sub main::__ANON__[(eval 0)[(eval
4)[test22-strevala.p:12]:2]:1] 1-1
+fid_fileinfo 7 sub main::__ANON__[(eval 0)[(eval
0)[test22-strevala.p:12]:2]:1] 1-1
fid_line_time 1 3 [ 0 1 ]
fid_line_time 1 6 0 0
fid_line_time 1 6 1 1
@@ -76,8 +74,8 @@
profile_modes fid_line_time line
profile_modes fid_sub_time sub
sub_subinfo main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1]
[
7 1 1 2 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1]
called_by 5 2 [ 1 0 0 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1]
called_by 5 2 [ 2 0 0 0 0 0 0 ]
sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:6]:1] [ 2 1 1 1 0 0
0 0 ]
sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:6]:1] called_by
1 6
[ 1 0 0 0 0 0 0 ]
sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:9]:1] [ 3 1 1 2 0 0
0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:9]:1] called_by
1 9
[ 1 0 0 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:9]:1] called_by
1 9
[ 2 0 0 0 0 0 0 ]
Modified: trunk/t/test61-submerge.rdt
==============================================================================
--- trunk/t/test61-submerge.rdt (original)
+++ trunk/t/test61-submerge.rdt Mon Jan 19 06:04:11 2009
@@ -20,18 +20,16 @@
fid_block_time 1 8 2 2 [ 0 3 ]
fid_fileinfo 1 [ test61-submerge.p 1 2 0 0 ]
fid_fileinfo 1 sub main::foo 4-4
-fid_fileinfo 1 call 8 main::__ANON__[(eval
1)[test61-submerge.p:8]:1] [ 1
0 0 0 0 0 0 ]
-fid_fileinfo 1 call 8 main::__ANON__[(eval
2)[test61-submerge.p:8]:1] [ 1
0 0 0 0 0 0 ]
-fid_fileinfo 1 call 8 main::__ANON__[(eval
3)[test61-submerge.p:8]:1] [ 1
0 0 0 0 0 0 ]
+fid_fileinfo 1 call 8 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] [ 3
0 0 0 0 0 0 ]
fid_fileinfo 1 eval 8 [ 3 0 ]
fid_fileinfo 2 [ (eval 0)[test61-submerge.p:8] 1 8 2 2 0 0 ]
-fid_fileinfo 2 sub main::__ANON__[(eval 1)[test61-submerge.p:8]:1]
1-1
+fid_fileinfo 2 sub main::__ANON__[(eval 0)[test61-submerge.p:8]:1]
1-1
fid_fileinfo 2 call 1 main::foo [ 1 0 0 0 0 0 0 ]
fid_fileinfo 3 [ (eval 0)[test61-submerge.p:8] 1 8 3 2 0 0 ]
-fid_fileinfo 3 sub main::__ANON__[(eval 0)[test61-submerge.p:8]:1]
and
main::__ANON__[(eval 1)[test61-submerge.p:8]:1] and main::__ANON__[(eval
3)[test61-submerge.p:8]:1] 1-1
+fid_fileinfo 3 sub main::__ANON__[(eval 0)[test61-submerge.p:8]:1]
1-1
fid_fileinfo 3 call 1 main::foo [ 1 0 0 0 0 0 0 ]
fid_fileinfo 4 [ (eval 0)[test61-submerge.p:8] 1 8 4 2 0 0 ]
-fid_fileinfo 4 sub main::__ANON__[(eval 3)[test61-submerge.p:8]:1]
1-1
+fid_fileinfo 4 sub main::__ANON__[(eval 0)[test61-submerge.p:8]:1]
1-1
fid_fileinfo 4 call 1 main::foo [ 1 0 0 0 0 0 0 ]
fid_line_time 1 4 [ 0 3 ]
fid_line_time 1 6 [ 0 1 ]
@@ -49,7 +47,7 @@
profile_modes fid_line_time line
profile_modes fid_sub_time sub
sub_subinfo main::__ANON__[(eval 0)[test61-submerge.p:8]:1] [ 3 1 1 3 0 0
0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test61-submerge.p:8]:1] called_by
1 8
[ 1 0 0 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test61-submerge.p:8]:1] called_by
1 8
[ 3 0 0 0 0 0 0 ]
sub_subinfo main::foo [ 1 4 4 3 0 0 0 0 ]
sub_subinfo main::foo called_by 2 1 [ 1 0 0 0 0 0 0
]
sub_subinfo main::foo called_by 3 1 [ 1 0 0 0 0 0 0
]
--~--~---------~--~----~------------~-------~--~----~
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]
-~----------~----~----~----~------~----~------~--~---
