Author: tim.bunce
Date: Mon Mar 23 05:06:40 2009
New Revision: 716
Modified:
trunk/HACKING
trunk/bin/nytprofhtml
trunk/t/lib/NYTProfTest.pm
trunk/t/test01.t
trunk/t/test14.p
trunk/t/test14.pm
trunk/t/test14.rdt
trunk/t/test14.x
Log:
Add docs for "Unable to open '... (autosplit into ...)'" warning.
Adjusted test14 so it tests new autosplit logic.
Extend test harness to enable per-test override of NYTPROF env values.
Modified: trunk/HACKING
==============================================================================
--- trunk/HACKING (original)
+++ trunk/HACKING Mon Mar 23 05:06:40 2009
@@ -361,3 +361,11 @@
Monitor and report when method cache is invalidated. Watch generation
number
and output a tag when it changes. Report locations of changes. Highlight
those
that happen after INIT phase.
+
+Fix testing of t/*.pm_x files which are currently being ignored.
+
+The autosplit handling doesn't address the naming of pseudo-fids from
string
+evals, like "(eval 0)[test14.pm (autosplit into auto/test14/bar.al):17]"
+The fidinfo struct for alias fid should probably have the name adjusted
+to be the name of the parent. That would make aliases more transparent.
+
Modified: trunk/bin/nytprofhtml
==============================================================================
--- trunk/bin/nytprofhtml (original)
+++ trunk/bin/nytprofhtml Mon Mar 23 05:06:40 2009
@@ -1318,6 +1318,26 @@
The report was generated by profiling L<perlcritic> 1.088 checking it's
own source code.
+=head1 DIAGNOSTICS
+
+=head2 "Unable to open '... (autosplit into ...)'"
+
+The profiled application executed code in a module that used L<AutoLoader>
to
+load the code from a separate .al file. NYTProf automatically recognises
this
+situation and tries to determine the 'parent' module file so it can
associate
+the profile data with it. In order to do that the parent module file must
+already be 'known' to NYTProf, typically by already having some code
profiled.
+
+You're only likely to see this warning if you're using the C<start> option
to
+start profiling after compile-time. The effect is that times spent in
+autoloaded subs won't be associated with the parent module file and you
won't
+get annotated reports for them.
+
+You can avoid this by using the default C<start=begin> option, or by
ensuring
+you execute some non-autoloaded code in the parent module, while the
profiler is
+running, before an autoloaded sub is called.
+
+
=head1 HISTORY
A bit of history and a shameless plug...
Modified: trunk/t/lib/NYTProfTest.pm
==============================================================================
--- trunk/t/lib/NYTProfTest.pm (original)
+++ trunk/t/lib/NYTProfTest.pm Mon Mar 23 05:06:40 2009
@@ -86,11 +86,10 @@
sub run_test_group {
- my ($test_count, $test_code) = @_;
-
- # no warnings "undefined value";
- $test_count ||= 0;
- $test_count = 0 unless $test_code;
+ my ($opts) = @_;
+ my $override_env = $opts->{override_env} || {};
+ my $extra_test_code = $opts->{extra_test_code};
+ my $extra_test_count = $opts->{extra_test_count} || 0;
# obtain group from file name
my $group;
@@ -109,7 +108,7 @@
print "nytprofcvs: $nytprofcsv\n";
}
- my $tests_per_env = number_of_tests(@tests) + $test_count;
+ my $tests_per_env = number_of_tests(@tests) + $extra_test_count;
plan tests => 1 + $tests_per_env * @env_combinations;
@@ -118,7 +117,7 @@
for my $env (@env_combinations) {
- my %env = (%$env, %NYTPROF_TEST);
+ my %env = (%$env, %$override_env, %NYTPROF_TEST);
local $ENV{NYTPROF} = join ":", map {"$_=$env{$_}"} sort keys %env;
my $context = "NYTPROF=$ENV{NYTPROF}\n";
($opts{v}) ? warn $context : print $context;
@@ -127,15 +126,15 @@
run_test($test);
}
- if ($test_code) {
+ if ($extra_test_code) {
my $profile = eval { Devel::NYTProf::Data->new({filename =>
$profile_datafile}) };
if ($@) {
diag($@);
- fail("extra tests group '$group'") foreach (1 ..
$test_count);
+ fail("extra tests group '$group'") foreach (1 ..
$extra_test_count);
return;
}
- $test_code->($profile, $env);
+ $extra_test_code->($profile, $env);
}
}
}
Modified: trunk/t/test01.t
==============================================================================
--- trunk/t/test01.t (original)
+++ trunk/t/test01.t Mon Mar 23 05:06:40 2009
@@ -3,7 +3,10 @@
use lib qw(t/lib);
use NYTProfTest;
-run_test_group(1 => sub {
- my ($profile, $env) = @_;
- isa_ok($profile, 'Devel::NYTProf::Data');
- });
+run_test_group({
+ extra_test_count => 1,
+ extra_test_code => sub {
+ my ($profile, $env) = @_;
+ isa_ok($profile, 'Devel::NYTProf::Data');
+ },
+});
Modified: trunk/t/test14.p
==============================================================================
--- trunk/t/test14.p (original)
+++ trunk/t/test14.p Mon Mar 23 05:06:40 2009
@@ -14,5 +14,6 @@
}
use test14;
+test14::pre();
test14::foo();
test14::bar();
Modified: trunk/t/test14.pm
==============================================================================
--- trunk/t/test14.pm (original)
+++ trunk/t/test14.pm Mon Mar 23 05:06:40 2009
@@ -1,6 +1,12 @@
package test14;
use AutoLoader 'AUTOLOAD';
+# The tests run with start=init so we need to arrange to execute some
+# profiled code before the first autosplit sub gets loaded in order to
+# test the handling of autosplit subs. We could use an INIT block for
+# that but calling a sub suits the tests better for obscure reasons.
+sub pre { 1 }
+
1;
__END__
sub foo {
Modified: trunk/t/test14.rdt
==============================================================================
--- trunk/t/test14.rdt (original)
+++ trunk/t/test14.rdt Mon Mar 23 05:06:40 2009
@@ -14,42 +14,50 @@
attribute xs_version 0
fid_block_time 1 17 [ 0 1 ]
fid_block_time 1 18 [ 0 1 ]
-fid_block_time 3 7 [ 0 1 ]
-fid_block_time 3 11 [ 0 1 ]
-fid_block_time 4 11 0 0
-fid_block_time 4 11 1 1
-fid_block_time 4 11 2 1 [ 0 1 ]
-fid_block_time 4 14 [ 0 1 ]
+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 20 [ 0 1 ]
fid_fileinfo 1 [ test14.p 1 2 0 0 ]
fid_fileinfo 1 sub main::BEGIN 16-16
-fid_fileinfo 1 call 17 AutoLoader::AUTOLOAD [ 1 0 0 0 0 0 0
]
+fid_fileinfo 1 call 17 test14::pre [ 1 0 0 0 0 0 0 ]
fid_fileinfo 1 call 18 AutoLoader::AUTOLOAD [ 1 0 0 0 0 0 0
]
-fid_fileinfo 2 [ AutoLoader.pm 2 2 0 0 ]
-fid_fileinfo 3 [ test14.pm (autosplit into auto/test14/foo.al) 3 10
0 0 ]
-fid_fileinfo 3 sub test14::foo 6-8
-fid_fileinfo 4 [ test14.pm (autosplit into auto/test14/bar.al) 4 10
0 0 ]
-fid_fileinfo 4 sub test14::bar 10-12
-fid_fileinfo 4 eval 11 [ 1 0 ]
-fid_fileinfo 5 [ (eval 0)[test14.pm (autosplit into
auto/test14/bar.al):11] 4 11 5 2 0 0 ]
+fid_fileinfo 1 call 19 AutoLoader::AUTOLOAD [ 1 0 0 0 0 0 0
]
+fid_fileinfo 2 [ test14.pm 2 2 0 0 ]
+fid_fileinfo 2 sub test14::BEGIN 2-2
+fid_fileinfo 2 sub test14::bar 16-18
+fid_fileinfo 2 sub test14::foo 12-14
+fid_fileinfo 2 sub test14::pre 8-8
+fid_fileinfo 2 eval 17 [ 1 0 ]
+fid_fileinfo 3 [ AutoLoader.pm 3 2 0 0 ]
+fid_fileinfo 4 [ (eval 0)[test14.pm (autosplit into
auto/test14/bar.al):17] 2 17 4 2 0 0 ]
fid_line_time 1 17 [ 0 1 ]
fid_line_time 1 18 [ 0 1 ]
-fid_line_time 3 7 [ 0 1 ]
-fid_line_time 3 11 [ 0 1 ]
-fid_line_time 4 11 0 0
-fid_line_time 4 11 1 1
-fid_line_time 4 11 2 1 [ 0 1 ]
-fid_line_time 4 14 [ 0 1 ]
+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 20 [ 0 1 ]
fid_sub_time 1 17 [ 0 1 ]
fid_sub_time 1 18 [ 0 1 ]
-fid_sub_time 3 7 [ 0 1 ]
-fid_sub_time 3 11 [ 0 1 ]
-fid_sub_time 4 11 0 0
-fid_sub_time 4 11 1 1
-fid_sub_time 4 11 2 1 [ 0 1 ]
-fid_sub_time 4 14 [ 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 20 [ 0 1 ]
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 test14::bar [ 4 10 12 0 0 0 0 0 ]
-sub_subinfo test14::foo [ 3 6 8 0 0 0 0 0 ]
+sub_subinfo test14::BEGIN [ 2 2 2 0 0 0 0 0 ]
+sub_subinfo test14::bar [ 2 16 18 0 0 0 0 0 ]
+sub_subinfo test14::foo [ 2 12 14 0 0 0 0 0 ]
+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
]
Modified: trunk/t/test14.x
==============================================================================
--- trunk/t/test14.x (original)
+++ trunk/t/test14.x Mon Mar 23 05:06:40 2009
@@ -17,5 +17,6 @@
0,0,0,}
0,0,0,
0,0,0,use test14;
+0,1,0,test14::pre();
0,1,0,test14::foo();
0,1,0,test14::bar();
--~--~---------~--~----~------------~-------~--~----~
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]
-~----------~----~----~----~------~----~------~--~---
