Revision: 1259
Author: [email protected]
Date: Tue Jun 1 04:28:28 2010
Log: Make subinfo dump (a little) easier to read
http://code.google.com/p/perl-devel-nytprof/source/detail?r=1259
Modified:
/trunk/lib/Devel/NYTProf/SubInfo.pm
/trunk/t/test01.rdt
/trunk/t/test02.rdt
/trunk/t/test03.rdt
/trunk/t/test05.rdt
/trunk/t/test06.rdt
/trunk/t/test07.rdt
/trunk/t/test08.rdt
/trunk/t/test09.rdt
/trunk/t/test10.rdt
/trunk/t/test11.rdt
/trunk/t/test12.rdt
/trunk/t/test13.rdt
/trunk/t/test14.rdt
/trunk/t/test16.rdt
/trunk/t/test17-goto.rdt
/trunk/t/test20-streval.rdt
/trunk/t/test21-streval3.rdt
/trunk/t/test22-strevala.rdt
/trunk/t/test23-strevall.rdt
/trunk/t/test24-strevalc.rdt
/trunk/t/test30-fork-0.rdt
/trunk/t/test40pmc.rdt
/trunk/t/test50-disable.rdt
/trunk/t/test51-enable.rdt
/trunk/t/test60-subname.rdt
/trunk/t/test61-submerge.rdt
/trunk/t/test62-subcaller1.rdt
/trunk/t/test80-recurs.rdt
=======================================
--- /trunk/lib/Devel/NYTProf/SubInfo.pm Sun May 30 01:17:44 2010
+++ /trunk/lib/Devel/NYTProf/SubInfo.pm Tue Jun 1 04:28:28 2010
@@ -328,24 +328,27 @@
sub dump {
my ($self, $separator, $fh, $path, $prefix) = @_;
+ my ($fid, $l1, $l2, $calls) = @{$self}[
+ NYTP_SIi_FID, NYTP_SIi_FIRST_LINE, NYTP_SIi_LAST_LINE,
NYTP_SIi_CALL_COUNT
+ ];
my @values = @{$self}[
- NYTP_SIi_FID, NYTP_SIi_FIRST_LINE, NYTP_SIi_LAST_LINE,
- NYTP_SIi_CALL_COUNT, NYTP_SIi_INCL_RTIME, NYTP_SIi_EXCL_RTIME,
+ NYTP_SIi_INCL_RTIME, NYTP_SIi_EXCL_RTIME,
NYTP_SIi_REC_DEPTH, NYTP_SIi_RECI_RTIME
];
- printf $fh "%s[ %s ]\n",
- $prefix, join(" ", map { defined($_) ? $_ : 'undef' } @values);
+ printf $fh "%s[ %s:%s-%s calls %s times %s ]\n",
+ $prefix,
+ map({ defined($_) ? $_ : 'undef' } $fid, $l1, $l2, $calls),
+ join(" ", map { defined($_) ? $_ : 'undef' } @values);
my @caller_places = $self->caller_places;
for my $cp (@caller_places) {
my ($fid, $line, $sc) = @$cp;
my @sc = @$sc;
$sc[NYTP_SCi_CALLING_SUB] = join "|", keys %{
$sc[NYTP_SCi_CALLING_SUB] };
- printf $fh "%s%s%s%d%s%d%s[ %s ]\n",
+ printf $fh "%s%s%s%d:%d%s[ %s ]\n",
$prefix,
'called_by', $separator,
- $fid, $separator,
- $line, $separator,
+ $fid, $line, $separator,
join(" ", map { defined($_) ? $_ : 'undef' } @sc);
}
}
=======================================
--- /trunk/t/test01.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test01.rdt Tue Jun 1 04:28:28 2010
@@ -53,18 +53,18 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 7 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 2 [ 2 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:print called_by 1 7 [ 4 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print called_by 1 11 [ 1 0 0
0 0 0 0 main::baz ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 6 8 4 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 3 [ 2 0 0 0 0 0 0
main::foo ]
-sub_subinfo main::bar called_by 1 12 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::bar called_by 1 16 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::baz [ 1 10 14 1 0 0 0 0 ]
-sub_subinfo main::baz called_by 1 17 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo [ 1 1 4 2 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 13 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::foo called_by 1 18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 7 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:2 [ 2 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:print called_by 1:7 [ 4 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print called_by 1:11 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:6-8 calls 4 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:3 [ 2 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::bar called_by 1:12 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::bar called_by 1:16 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::baz [ 1:10-14 calls 1 times 0 0 0 0 ]
+sub_subinfo main::baz called_by 1:17 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo [ 1:1-4 calls 2 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:13 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::foo called_by 1:18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test02.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test02.rdt Tue Jun 1 04:28:28 2010
@@ -61,21 +61,21 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 10 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 2 [ 2 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:print called_by 1 7 [ 7 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print called_by 1 11 [ 1 0 0
0 0 0 0 main::baz ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 6 8 7 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 3 [ 2 0 0 0 0 0 0
main::foo ]
-sub_subinfo main::bar called_by 1 12 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::bar called_by 1 13 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::bar called_by 1 14 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::bar called_by 1 18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::bar called_by 1 19 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::baz [ 1 10 16 1 0 0 0 0 ]
-sub_subinfo main::baz called_by 1 20 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo [ 1 1 4 2 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 15 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::foo called_by 1 21 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 10 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:2 [ 2 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:print called_by 1:7 [ 7 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print called_by 1:11 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:6-8 calls 7 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:3 [ 2 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::bar called_by 1:12 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::bar called_by 1:13 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::bar called_by 1:14 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::bar called_by 1:18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::bar called_by 1:19 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::baz [ 1:10-16 calls 1 times 0 0 0 0 ]
+sub_subinfo main::baz called_by 1:20 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo [ 1:1-4 calls 2 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:15 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::foo called_by 1:21 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test03.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test03.rdt Tue Jun 1 04:28:28 2010
@@ -48,16 +48,16 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 4 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 2 [ 1 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:print called_by 1 8 [ 2 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print called_by 1 12 [ 1 0 0
0 0 0 0 main::baz ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 7 9 2 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 13 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::bar called_by 1 17 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::baz [ 1 11 15 1 0 0 0 0 ]
-sub_subinfo main::baz called_by 1 18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo [ 1 1 5 1 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 14 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 4 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:2 [ 1 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:print called_by 1:8 [ 2 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print called_by 1:12 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:7-9 calls 2 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:13 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::bar called_by 1:17 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::baz [ 1:11-15 calls 1 times 0 0 0 0 ]
+sub_subinfo main::baz called_by 1:18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo [ 1:1-5 calls 1 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:14 [ 1 0 0 0 0 0 0
main::baz ]
=======================================
--- /trunk/t/test05.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test05.rdt Tue Jun 1 04:28:28 2010
@@ -54,19 +54,19 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 6 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 5 [ 1 0 0
0 0 0 0 main::foo1 ]
-sub_subinfo main::CORE:print called_by 1 9 [ 1 0 0
0 0 0 0 main::foo2 ]
-sub_subinfo main::CORE:print called_by 1 13 [ 2 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print called_by 1 19 [ 2 0 0
0 0 0 0 main::yeppers ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 12 17 2 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 6 [ 1 0 0 0 0 0 0
main::foo1 ]
-sub_subinfo main::bar called_by 1 10 [ 1 0 0 0 0 0 0
main::foo2 ]
-sub_subinfo main::foo1 [ 1 4 7 1 0 0 0 0 ]
-sub_subinfo main::foo1 called_by 1 22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo2 [ 1 8 11 1 0 0 0 0 ]
-sub_subinfo main::foo2 called_by 1 23 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::yeppers [ 1 18 20 2 0 0 0 0 ]
-sub_subinfo main::yeppers called_by 1 14 [ 2 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 6 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:5 [ 1 0 0 0 0 0 0
main::foo1 ]
+sub_subinfo main::CORE:print called_by 1:9 [ 1 0 0 0 0 0 0
main::foo2 ]
+sub_subinfo main::CORE:print called_by 1:13 [ 2 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print called_by 1:19 [ 2 0 0 0 0 0 0
main::yeppers ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:12-17 calls 2 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:6 [ 1 0 0 0 0 0 0
main::foo1 ]
+sub_subinfo main::bar called_by 1:10 [ 1 0 0 0 0 0 0
main::foo2 ]
+sub_subinfo main::foo1 [ 1:4-7 calls 1 times 0 0 0 0 ]
+sub_subinfo main::foo1 called_by 1:22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo2 [ 1:8-11 calls 1 times 0 0 0 0 ]
+sub_subinfo main::foo2 called_by 1:23 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::yeppers [ 1:18-20 calls 2 times 0 0 0 0 ]
+sub_subinfo main::yeppers called_by 1:14 [ 2 0 0 0 0 0 0
main::bar ]
=======================================
--- /trunk/t/test06.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test06.rdt Tue Jun 1 04:28:28 2010
@@ -80,21 +80,21 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 3 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 10 [ 1 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:print called_by 1 20 [ 1 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print called_by 1 31 [ 1 0 0
0 0 0 0 main::baz ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 19 28 1 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 43 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::baz [ 1 30 40 1 0 0 0 0 ]
-sub_subinfo main::baz called_by 1 44 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo [ 1 9 17 1 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 42 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::noop [ 1 5 7 410 0 0 0 0 ]
-sub_subinfo main::noop called_by 1 12 [ 10 0 0 0 0 0
0 main::foo ]
-sub_subinfo main::noop called_by 1 14 [ 100 0 0 0 0 0
0 main::foo ]
-sub_subinfo main::noop called_by 1 25 [ 100 0 0 0 0 0
0 main::bar ]
-sub_subinfo main::noop called_by 1 36 [ 100 0 0 0 0 0
0 main::baz ]
-sub_subinfo main::noop called_by 1 37 [ 100 0 0 0 0 0
0 main::baz ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 3 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:10 [ 1 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:print called_by 1:20 [ 1 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print called_by 1:31 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:19-28 calls 1 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:43 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::baz [ 1:30-40 calls 1 times 0 0 0 0 ]
+sub_subinfo main::baz called_by 1:44 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo [ 1:9-17 calls 1 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:42 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::noop [ 1:5-7 calls 410 times 0 0 0 0 ]
+sub_subinfo main::noop called_by 1:12 [ 10 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::noop called_by 1:14 [ 100 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::noop called_by 1:25 [ 100 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::noop called_by 1:36 [ 100 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::noop called_by 1:37 [ 100 0 0 0 0 0 0
main::baz ]
=======================================
--- /trunk/t/test07.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test07.rdt Tue Jun 1 04:28:28 2010
@@ -24,7 +24,7 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 1 [ 1 0 0
0 0 0 0 main::RUNTIME ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
=======================================
--- /trunk/t/test08.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test08.rdt Tue Jun 1 04:28:28 2010
@@ -29,4 +29,4 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
=======================================
--- /trunk/t/test09.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test09.rdt Tue Jun 1 04:28:28 2010
@@ -56,11 +56,11 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 7 9 3 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 13 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::bar called_by 2 3 [ 2 0 0 0 0 0 0
main::foo ]
-sub_subinfo main::foo [ 1 1 5 2 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 11 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo called_by 1 12 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:7-9 calls 3 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:13 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::bar called_by 2:3 [ 2 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::foo [ 1:1-5 calls 2 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:11 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo called_by 1:12 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test10.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test10.rdt Tue Jun 1 04:28:28 2010
@@ -37,9 +37,9 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:sleep [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:sleep called_by 2 1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test10.p:1]:1] ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test10.p:1]:1] [ 2 1 1 1 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test10.p:1]:1] called_by 1 2 [ 1 0 0 0
0 0 0 main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:sleep [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:sleep called_by 2:1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test10.p:1]:1] ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test10.p:1]:1] [ 2:1-1 calls 1 times 0
0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test10.p:1]:1] called_by 1:2 [ 1 0 0 0
0 0 0 main::RUNTIME ]
=======================================
--- /trunk/t/test11.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test11.rdt Tue Jun 1 04:28:28 2010
@@ -33,8 +33,8 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 2 4 0 0 0 0 0 ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test11.p:3]:1] [ 2 1 1 2 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test11.p:3]:1] called_by 1 5 [ 1 0 0 0
0 0 0 main::RUNTIME ]
-sub_subinfo main::__ANON__[(eval 0)[test11.p:3]:1] called_by 1 6 [ 1 0 0 0
0 0 0 main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:2-4 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test11.p:3]:1] [ 2:1-1 calls 2 times 0
0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test11.p:3]:1] called_by 1:5 [ 1 0 0 0
0 0 0 main::RUNTIME ]
+sub_subinfo main::__ANON__[(eval 0)[test11.p:3]:1] called_by 1:6 [ 1 0 0 0
0 0 0 main::RUNTIME ]
=======================================
--- /trunk/t/test12.rdt Thu Dec 10 04:39:24 2009
+++ /trunk/t/test12.rdt Tue Jun 1 04:28:28 2010
@@ -25,4 +25,4 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
=======================================
--- /trunk/t/test13.rdt Sun May 30 01:17:44 2010
+++ /trunk/t/test13.rdt Tue Jun 1 04:28:28 2010
@@ -60,19 +60,19 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 5 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 4 [ 3 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:print called_by 1 8 [ 1 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print called_by 1 12 [ 1 0 0
0 0 0 0 main::baz ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 7 9 1 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 20 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::baz [ 1 11 17 1 0 0 0 0 ]
-sub_subinfo main::baz called_by 1 21 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo [ 1 3 5 3 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 13 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::foo called_by 1 14 [ 1 0 0 0 0 0 0
main::baz ]
-sub_subinfo main::foo called_by 2 1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::x [ 1 undef undef 1 0 0 0 0 ]
-sub_subinfo main::x called_by 1 15 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 5 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:4 [ 3 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:print called_by 1:8 [ 1 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print called_by 1:12 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:7-9 calls 1 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:20 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::baz [ 1:11-17 calls 1 times 0 0 0 0 ]
+sub_subinfo main::baz called_by 1:21 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo [ 1:3-5 calls 3 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:13 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::foo called_by 1:14 [ 1 0 0 0 0 0 0
main::baz ]
+sub_subinfo main::foo called_by 2:1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::x [ 1:undef-undef calls 1 times 0 0 0 0 ]
+sub_subinfo main::x called_by 1:15 [ 1 0 0 0 0 0 0 main::baz ]
=======================================
--- /trunk/t/test14.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test14.rdt Tue Jun 1 04:28:28 2010
@@ -54,12 +54,12 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 16 16 0 0 0 0 0 ]
-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 1 [ 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 1 [ 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 ]
+sub_subinfo main::BEGIN [ 1:16-16 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo test14::BEGIN [ 2:2-2 calls 0 times 0 0 0 0 ]
+sub_subinfo test14::bar [ 2:16-18 calls 1 times 0 0 0 0 ]
+sub_subinfo test14::bar called_by 3:1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo test14::foo [ 2:12-14 calls 1 times 0 0 0 0 ]
+sub_subinfo test14::foo called_by 3:1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo test14::pre [ 2:8-8 calls 1 times 0 0 0 0 ]
+sub_subinfo test14::pre called_by 1:17 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test16.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test16.rdt Tue Jun 1 04:28:28 2010
@@ -57,20 +57,20 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 6 6 0 0 0 0 0 ]
-sub_subinfo main::CORE:match [ 1 0 0 6 0 0 0 0 ]
-sub_subinfo main::CORE:match called_by 1 11 [ 2 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:match called_by 1 14 [ 1 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::CORE:match called_by 1 22 [ 3 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:print [ 1 0 0 2 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 22 [ 2 0 0
0 0 0 0 main::bar ]
-sub_subinfo main::CORE:say [ 1 0 0 2 0 0 0 0 ]
-sub_subinfo main::CORE:say called_by 1 11 [ 1 0 0 0 0 0 0
main::foo ]
-sub_subinfo main::CORE:say called_by 1 14 [ 1 0 0 0 0 0 0
main::foo ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 20 27 2 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 32 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::bar called_by 1 33 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo [ 1 8 18 2 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 30 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo called_by 1 31 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:6-6 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:match [ 1:0-0 calls 6 times 0 0 0 0 ]
+sub_subinfo main::CORE:match called_by 1:11 [ 2 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:match called_by 1:14 [ 1 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:match called_by 1:22 [ 3 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 2 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:22 [ 2 0 0 0 0 0 0
main::bar ]
+sub_subinfo main::CORE:say [ 1:0-0 calls 2 times 0 0 0 0 ]
+sub_subinfo main::CORE:say called_by 1:11 [ 1 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::CORE:say called_by 1:14 [ 1 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:20-27 calls 2 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:32 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::bar called_by 1:33 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo [ 1:8-18 calls 2 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:30 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo called_by 1:31 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test17-goto.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test17-goto.rdt Tue Jun 1 04:28:28 2010
@@ -59,16 +59,16 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::bar [ 1 26 28 1 0 0 0 0 ]
-sub_subinfo main::bar called_by 1 31 [ 1 0 0 0 0 0 0
main::foo ]
-sub_subinfo main::destination [ 1 18 20 1 0 0 0 0 ]
-sub_subinfo main::destination called_by 1 15 [ 1 0 0 0 0 0 0 main::RUNTIME
]
-sub_subinfo main::foo [ 1 30 33 1 0 0 0 0 ]
-sub_subinfo main::foo called_by 1 35 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::origin [ 1 13 16 1 0 0 0 0 ]
-sub_subinfo main::origin called_by 1 22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::other [ 1 9 9 2 0 0 0 0 ]
-sub_subinfo main::other called_by 1 14 [ 1 0 0 0 0 0 0
main::origin ]
-sub_subinfo main::other called_by 1 19 [ 1 0 0 0 0 0 0
main::destination ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::bar [ 1:26-28 calls 1 times 0 0 0 0 ]
+sub_subinfo main::bar called_by 1:31 [ 1 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::destination [ 1:18-20 calls 1 times 0 0 0 0 ]
+sub_subinfo main::destination called_by 1:15 [ 1 0 0 0 0 0 0 main::RUNTIME
]
+sub_subinfo main::foo [ 1:30-33 calls 1 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 1:35 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::origin [ 1:13-16 calls 1 times 0 0 0 0 ]
+sub_subinfo main::origin called_by 1:22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::other [ 1:9-9 calls 2 times 0 0 0 0 ]
+sub_subinfo main::other called_by 1:14 [ 1 0 0 0 0 0 0
main::origin ]
+sub_subinfo main::other called_by 1:19 [ 1 0 0 0 0 0 0
main::destination ]
=======================================
--- /trunk/t/test20-streval.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test20-streval.rdt Tue Jun 1 04:28:28 2010
@@ -60,11 +60,11 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 4 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 3 [ 4 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::foo [ 1 3 3 4 0 0 0 0 ]
-sub_subinfo main::foo called_by 2 1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo called_by 3 1 [ 2 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo called_by 6 1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 4 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:3 [ 4 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::foo [ 1:3-3 calls 4 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 2:1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo called_by 3:1 [ 2 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo called_by 6:1 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test21-streval3.rdt Wed Apr 21 04:41:03 2010
+++ /trunk/t/test21-streval3.rdt Tue Jun 1 04:28:28 2010
@@ -66,13 +66,13 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:sselect [ 1 0 0 3 0 0 0 0 ]
-sub_subinfo main::CORE:sselect called_by 2 2 [ 1 0 0 0 0 0 0 main::RUNTIME
]
-sub_subinfo main::CORE:sselect called_by 3 2 [ 1 0 0 0 0 0 0 main::RUNTIME
]
-sub_subinfo main::CORE:sselect called_by 4 2 [ 1 0 0 0 0 0 0 main::RUNTIME
]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::foo [ 1 4 4 3 0 0 0 0 ]
-sub_subinfo main::foo called_by 2 3 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo called_by 3 3 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::foo called_by 4 3 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:sselect [ 1:0-0 calls 3 times 0 0 0 0 ]
+sub_subinfo main::CORE:sselect called_by 2:2 [ 1 0 0 0 0 0 0 main::RUNTIME
]
+sub_subinfo main::CORE:sselect called_by 3:2 [ 1 0 0 0 0 0 0 main::RUNTIME
]
+sub_subinfo main::CORE:sselect called_by 4:2 [ 1 0 0 0 0 0 0 main::RUNTIME
]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::foo [ 1:4-4 calls 3 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 2:3 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo called_by 3:3 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::foo called_by 4:3 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test22-strevala.rdt Tue Jun 1 03:44:01 2010
+++ /trunk/t/test22-strevala.rdt Tue Jun 1 04:28:28 2010
@@ -88,17 +88,17 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 5 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 2 1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test22-strevala.p:6]:1] ]
-sub_subinfo main::CORE:print called_by 3 1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test22-strevala.p:9]:1] ]
-sub_subinfo main::CORE:print called_by 4 1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test22-strevala.p:9]:1] ]
-sub_subinfo main::CORE:print called_by 6 1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] ]
-sub_subinfo main::CORE:print called_by 7 1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] [
6 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 [ 2 0 0 0 0 0 0 main::RUNTIME ]
-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 main::RUNTIME ]
-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
[ 2 0 0 0 0 0 0 main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 5 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 2:1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test22-strevala.p:6]:1] ]
+sub_subinfo main::CORE:print called_by 3:1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test22-strevala.p:9]:1] ]
+sub_subinfo main::CORE:print called_by 4:1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[test22-strevala.p:9]:1] ]
+sub_subinfo main::CORE:print called_by 6:1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] ]
+sub_subinfo main::CORE:print called_by 7:1 [ 1 0 0 0 0 0 0
main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[(eval 0)[test22-strevala.p:12]:2]:1] [
6:1-1 calls 2 times 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 main::RUNTIME ]
+sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:6]:1] [ 2:1-1 calls
1 times 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 main::RUNTIME ]
+sub_subinfo main::__ANON__[(eval 0)[test22-strevala.p:9]:1] [ 3:1-1 calls
2 times 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 main::RUNTIME ]
=======================================
--- /trunk/t/test23-strevall.rdt Wed May 26 15:36:48 2010
+++ /trunk/t/test23-strevall.rdt Tue Jun 1 04:28:28 2010
@@ -27,4 +27,4 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
=======================================
--- /trunk/t/test24-strevalc.rdt Tue Jun 1 03:44:01 2010
+++ /trunk/t/test24-strevalc.rdt Tue Jun 1 04:28:28 2010
@@ -63,8 +63,8 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test24-strevalc.p:8]:1] [ 8 1 1 2 0 0
0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test24-strevalc.p:8]:1] called_by 8 1
[ 1 0 0 0 0 0 0 main::RUNTIME ]
-sub_subinfo main::__ANON__[(eval 0)[test24-strevalc.p:8]:1] called_by 9 1
[ 1 0 0 0 0 0 0 main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test24-strevalc.p:8]:1] [ 8:1-1 calls
2 times 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test24-strevalc.p:8]:1] called_by 8:1
[ 1 0 0 0 0 0 0 main::RUNTIME ]
+sub_subinfo main::__ANON__[(eval 0)[test24-strevalc.p:8]:1] called_by 9:1
[ 1 0 0 0 0 0 0 main::RUNTIME ]
=======================================
--- /trunk/t/test30-fork-0.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test30-fork-0.rdt Tue Jun 1 04:28:28 2010
@@ -59,19 +59,19 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 5 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 2 [ 1 0 0
0 0 0 0 main::prefork ]
-sub_subinfo main::CORE:print called_by 1 7 [ 3 0 0
0 0 0 0 main::other ]
-sub_subinfo main::CORE:print called_by 1 11 [ 1 0 0 0 0 0 0 main::postfork
]
-sub_subinfo main::CORE:wait [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:wait called_by 1 22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::other [ 1 6 8 3 0 0 0 0 ]
-sub_subinfo main::other called_by 1 3 [ 1 0 0 0 0 0 0
main::prefork ]
-sub_subinfo main::other called_by 1 12 [ 1 0 0 0 0 0 0
main::postfork ]
-sub_subinfo main::other called_by 1 20 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::postfork [ 1 10 13 1 0 0 0 0 ]
-sub_subinfo main::postfork called_by 1 19 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::prefork [ 1 1 4 1 0 0 0 0 ]
-sub_subinfo main::prefork called_by 1 15 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 5 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:2 [ 1 0 0 0 0 0 0
main::prefork ]
+sub_subinfo main::CORE:print called_by 1:7 [ 3 0 0 0 0 0 0
main::other ]
+sub_subinfo main::CORE:print called_by 1:11 [ 1 0 0 0 0 0 0 main::postfork
]
+sub_subinfo main::CORE:wait [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:wait called_by 1:22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::other [ 1:6-8 calls 3 times 0 0 0 0 ]
+sub_subinfo main::other called_by 1:3 [ 1 0 0 0 0 0 0
main::prefork ]
+sub_subinfo main::other called_by 1:12 [ 1 0 0 0 0 0 0
main::postfork ]
+sub_subinfo main::other called_by 1:20 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::postfork [ 1:10-13 calls 1 times 0 0 0 0 ]
+sub_subinfo main::postfork called_by 1:19 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::prefork [ 1:1-4 calls 1 times 0 0 0 0 ]
+sub_subinfo main::prefork called_by 1:15 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test40pmc.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test40pmc.rdt Tue Jun 1 04:28:28 2010
@@ -28,7 +28,7 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 3 3 0 0 0 0 0 ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo test40pmc::foo [ 2 5 7 1 0 0 0 0 ]
-sub_subinfo test40pmc::foo called_by 1 4 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:3-3 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo test40pmc::foo [ 2:5-7 calls 1 times 0 0 0 0 ]
+sub_subinfo test40pmc::foo called_by 1:4 [ 1 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test50-disable.rdt Sun May 30 01:17:44 2010
+++ /trunk/t/test50-disable.rdt Tue Jun 1 04:28:28 2010
@@ -33,8 +33,8 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo DB::disable_profile [ 1 0 0 2 0 0 0 0 ]
-sub_subinfo DB::disable_profile called_by 1 2 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo DB::disable_profile called_by 1 6 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
+sub_subinfo DB::disable_profile [ 1:0-0 calls 2 times 0 0 0 0 ]
+sub_subinfo DB::disable_profile called_by 1:2 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo DB::disable_profile called_by 1:6 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
=======================================
--- /trunk/t/test51-enable.rdt Sun May 30 01:17:44 2010
+++ /trunk/t/test51-enable.rdt Tue Jun 1 04:28:28 2010
@@ -46,18 +46,18 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo DB::disable_profile [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo DB::disable_profile called_by 1 18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:unlink [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:unlink called_by 1 5 [ 1 0 0
0 0 0 0 main::RUNTIME ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::sub1 [ 1 7 7 1 0 0 0 0 ]
-sub_subinfo main::sub1 called_by 1 16 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::sub2 [ 1 8 8 0 0 0 0 0 ]
-sub_subinfo main::sub3 [ 1 9 9 0 0 0 0 0 ]
-sub_subinfo main::sub4 [ 1 10 10 0 0 0 0 0 ]
-sub_subinfo main::sub5 [ 1 11 11 0 0 0 0 0 ]
-sub_subinfo main::sub6 [ 1 12 12 0 0 0 0 0 ]
-sub_subinfo main::sub7 [ 1 13 13 0 0 0 0 0 ]
-sub_subinfo main::sub8 [ 1 14 14 0 0 0 0 0 ]
+sub_subinfo DB::disable_profile [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo DB::disable_profile called_by 1:18 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:unlink [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:unlink called_by 1:5 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub1 [ 1:7-7 calls 1 times 0 0 0 0 ]
+sub_subinfo main::sub1 called_by 1:16 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::sub2 [ 1:8-8 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub3 [ 1:9-9 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub4 [ 1:10-10 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub5 [ 1:11-11 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub6 [ 1:12-12 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub7 [ 1:13-13 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub8 [ 1:14-14 calls 0 times 0 0 0 0 ]
=======================================
--- /trunk/t/test60-subname.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test60-subname.rdt Tue Jun 1 04:28:28 2010
@@ -79,22 +79,22 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo Devel::NYTProf::Test::example_sub [ 2 13 13 0 0 0 0 0 ]
-sub_subinfo Devel::NYTProf::Test::example_xsub [ 2 0 0 7 0 0 0 0 ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 5 [ 1 0 0 0 0 0
0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 9 [ 1 0 0 0 0 0
0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 12 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 16 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 19 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 24 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 28 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo main::BEGIN [ 1 2 2 0 0 0 0 0 ]
-sub_subinfo main::CORE:open [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:open called_by 1 35 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::CORE:wait [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:wait called_by 1 32 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::launch [ 1 28 28 1 0 0 0 0 ]
-sub_subinfo main::launch called_by 1 29 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::will_die [ 1 23 23 1 0 0 0 0 ]
-sub_subinfo main::will_die called_by 1 24 [ 1 0 0 0 0 0 0
Devel::NYTProf::Test::example_xsub ]
+sub_subinfo Devel::NYTProf::Test::example_sub [ 2:13-13 calls 0 times 0 0
0 0 ]
+sub_subinfo Devel::NYTProf::Test::example_xsub [ 2:0-0 calls 7 times 0 0 0
0 ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:5 [ 1 0 0 0 0 0
0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:9 [ 1 0 0 0 0 0
0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:12 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:16 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:19 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:24 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:28 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:2-2 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:open [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:open called_by 1:35 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::CORE:wait [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:wait called_by 1:32 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::launch [ 1:28-28 calls 1 times 0 0 0 0 ]
+sub_subinfo main::launch called_by 1:29 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::will_die [ 1:23-23 calls 1 times 0 0 0 0 ]
+sub_subinfo main::will_die called_by 1:24 [ 1 0 0 0 0 0 0
Devel::NYTProf::Test::example_xsub ]
=======================================
--- /trunk/t/test61-submerge.rdt Tue Jun 1 03:44:01 2010
+++ /trunk/t/test61-submerge.rdt Tue Jun 1 04:28:28 2010
@@ -60,13 +60,13 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:print [ 1 0 0 3 0 0 0 0 ]
-sub_subinfo main::CORE:print called_by 1 4 [ 3 0 0
0 0 0 0 main::foo ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::__ANON__[(eval 0)[test61-submerge.p:8]:1] [ 2 1 1 3 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 main::RUNTIME ]
-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 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
-sub_subinfo main::foo called_by 3 1 [ 1 0 0 0 0 0 0 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
-sub_subinfo main::foo called_by 4 1 [ 1 0 0 0 0 0 0 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:print [ 1:0-0 calls 3 times 0 0 0 0 ]
+sub_subinfo main::CORE:print called_by 1:4 [ 3 0 0 0 0 0 0
main::foo ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::__ANON__[(eval 0)[test61-submerge.p:8]:1] [ 2:1-1 calls
3 times 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 main::RUNTIME ]
+sub_subinfo main::foo [ 1:4-4 calls 3 times 0 0 0 0 ]
+sub_subinfo main::foo called_by 2:1 [ 1 0 0 0 0 0 0 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
+sub_subinfo main::foo called_by 3:1 [ 1 0 0 0 0 0 0 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
+sub_subinfo main::foo called_by 4:1 [ 1 0 0 0 0 0 0 main::__ANON__[(eval
0)[test61-submerge.p:8]:1] ]
=======================================
--- /trunk/t/test62-subcaller1.rdt Sun May 30 01:17:44 2010
+++ /trunk/t/test62-subcaller1.rdt Tue Jun 1 04:28:28 2010
@@ -120,30 +120,30 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo Devel::NYTProf::Test::example_sub [ 2 13 13 0 0 0 0 0 ]
-sub_subinfo Devel::NYTProf::Test::example_xsub [ 1 undef undef 5 0 0 0
0 ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 17 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 22 [ 1 0 0 0 0
0 0 main::RUNTIME ]
-sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1 26 [ 3 0 0 0 0
0 0 main::CORE:sort ]
-sub_subinfo MyTie::FETCH [ 1 7 7 1 0 0 0 0 ]
-sub_subinfo MyTie::FETCH called_by 1 13 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo MyTie::STORE [ 1 8 8 1 0 0 0 0 ]
-sub_subinfo MyTie::STORE called_by 1 12 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo MyTie::TIESCALAR [ 1 6 6 1 0 0 0 0 ]
-sub_subinfo MyTie::TIESCALAR called_by 1 11 [ 1 0 0
0 0 0 0 main::RUNTIME ]
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:sort [ 1 0 0 2 0 0 0 0 ]
-sub_subinfo main::CORE:sort called_by 1 27 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::CORE:sort called_by 1 33 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::CORE:subst [ 1 0 0 1 0 0 0 0 ]
-sub_subinfo main::CORE:subst called_by 1 38 [ 1 0 0
0 0 0 0 main::RUNTIME ]
-sub_subinfo main::CORE:substcont [ 1 0 0 3 0 0 0 0 ]
-sub_subinfo main::CORE:substcont called_by 1 38 [ 3 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::sub1 [ 1 21 21 1 0 0 0 0 ]
-sub_subinfo main::sub1 called_by 1 22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
-sub_subinfo main::sub2 [ 1 25 25 6 0 0 0 0 ]
-sub_subinfo main::sub2 called_by 1 28 [ 6 0 0 0 0 0 0
main::CORE:sort ]
-sub_subinfo main::sub3 [ 1 32 32 0 0 0 0 0 ]
-sub_subinfo main::sub4 [ 1 36 36 2 0 0 0 0 ]
-sub_subinfo main::sub4 called_by 1 38 [ 2 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_sub [ 2:13-13 calls 0 times 0 0
0 0 ]
+sub_subinfo Devel::NYTProf::Test::example_xsub [ 1:undef-undef calls 5
times 0 0 0 0 ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:17 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:22 [ 1 0 0 0 0
0 0 main::RUNTIME ]
+sub_subinfo Devel::NYTProf::Test::example_xsub called_by 1:26 [ 3 0 0 0 0
0 0 main::CORE:sort ]
+sub_subinfo MyTie::FETCH [ 1:7-7 calls 1 times 0 0 0 0 ]
+sub_subinfo MyTie::FETCH called_by 1:13 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo MyTie::STORE [ 1:8-8 calls 1 times 0 0 0 0 ]
+sub_subinfo MyTie::STORE called_by 1:12 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo MyTie::TIESCALAR [ 1:6-6 calls 1 times 0 0 0 0 ]
+sub_subinfo MyTie::TIESCALAR called_by 1:11 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:sort [ 1:0-0 calls 2 times 0 0 0 0 ]
+sub_subinfo main::CORE:sort called_by 1:27 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::CORE:sort called_by 1:33 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::CORE:subst [ 1:0-0 calls 1 times 0 0 0 0 ]
+sub_subinfo main::CORE:subst called_by 1:38 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::CORE:substcont [ 1:0-0 calls 3 times 0 0 0 0 ]
+sub_subinfo main::CORE:substcont called_by 1:38 [ 3 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub1 [ 1:21-21 calls 1 times 0 0 0 0 ]
+sub_subinfo main::sub1 called_by 1:22 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::sub2 [ 1:25-25 calls 6 times 0 0 0 0 ]
+sub_subinfo main::sub2 called_by 1:28 [ 6 0 0 0 0 0 0
main::CORE:sort ]
+sub_subinfo main::sub3 [ 1:32-32 calls 0 times 0 0 0 0 ]
+sub_subinfo main::sub4 [ 1:36-36 calls 2 times 0 0 0 0 ]
+sub_subinfo main::sub4 called_by 1:38 [ 2 0 0 0 0 0 0
main::RUNTIME ]
=======================================
--- /trunk/t/test80-recurs.rdt Thu Dec 10 03:05:52 2009
+++ /trunk/t/test80-recurs.rdt Tue Jun 1 04:28:28 2010
@@ -32,10 +32,10 @@
profile_modes fid_block_time block
profile_modes fid_line_time line
profile_modes fid_sub_time sub
-sub_subinfo main::BEGIN [ 1 0 0 0 0 0 0 0 ]
-sub_subinfo main::CORE:sselect [ 1 0 0 3 0 0 0 0 ]
-sub_subinfo main::CORE:sselect called_by 1 3 [ 3 0 0
0 0 0 0 main::recurs ]
-sub_subinfo main::RUNTIME [ 1 1 1 0 0 0 0 0 ]
-sub_subinfo main::recurs [ 1 1 5 3 0 0 2 0 ]
-sub_subinfo main::recurs called_by 1 4 [ 2 0 0 0 0 0 2
main::recurs ]
-sub_subinfo main::recurs called_by 1 7 [ 1 0 0 0 0 0 0
main::RUNTIME ]
+sub_subinfo main::BEGIN [ 1:0-0 calls 0 times 0 0 0 0 ]
+sub_subinfo main::CORE:sselect [ 1:0-0 calls 3 times 0 0 0 0 ]
+sub_subinfo main::CORE:sselect called_by 1:3 [ 3 0 0 0 0 0 0
main::recurs ]
+sub_subinfo main::RUNTIME [ 1:1-1 calls 0 times 0 0 0 0 ]
+sub_subinfo main::recurs [ 1:1-5 calls 3 times 0 0 2 0 ]
+sub_subinfo main::recurs called_by 1:4 [ 2 0 0 0 0 0 2
main::recurs ]
+sub_subinfo main::recurs called_by 1:7 [ 1 0 0 0 0 0 0
main::RUNTIME ]
--
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]
