← Index
NYTProf Performance Profile   « block view • line view • sub view »
For -e
  Run on Wed Nov 17 21:42:38 2010
Reported on Wed Nov 17 22:05:45 2010

Filename/home/doy/perl5/perlbrew/perls/perl-5.10.1/lib/site_perl/5.10.1/B/Hooks/EndOfScope.pm
StatementsExecuted 388 statements in 8.82ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
1112.32ms4.14msB::Hooks::EndOfScope::::BEGIN@14B::Hooks::EndOfScope::BEGIN@14
46112.21ms4.28msB::Hooks::EndOfScope::::on_scope_endB::Hooks::EndOfScope::on_scope_end
4646462.10ms270msB::Hooks::EndOfScope::::__ANON__[:26]B::Hooks::EndOfScope::__ANON__[:26]
4611510µs510µsB::Hooks::EndOfScope::::__ANON__[:25]B::Hooks::EndOfScope::__ANON__[:25]
11180µs99µsnamespace::clean::::BEGIN@1 namespace::clean::BEGIN@1
11174µs2.87msB::Hooks::EndOfScope::::BEGIN@16B::Hooks::EndOfScope::BEGIN@16
11173µs73µsB::Hooks::EndOfScope::::BEGIN@13B::Hooks::EndOfScope::BEGIN@13
11142µs111µsnamespace::clean::::BEGIN@2.2 namespace::clean::BEGIN@2.2
11118µs18µsB::Hooks::EndOfScope::::BEGIN@5B::Hooks::EndOfScope::BEGIN@5
11116µs16µsB::Hooks::EndOfScope::::BEGIN@8B::Hooks::EndOfScope::BEGIN@8
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
13103µs2118µs
# spent 99µs (80+19) within namespace::clean::BEGIN@1 which was called: # once (80µs+19µs) by namespace::clean::BEGIN@17 at line 1
use strict;
# spent 99µs making 1 call to namespace::clean::BEGIN@1 # spent 19µs making 1 call to strict::import
23190µs2179µs
# spent 111µs (42+69) within namespace::clean::BEGIN@2.2 which was called: # once (42µs+69µs) by namespace::clean::BEGIN@17 at line 2
use warnings;
# spent 111µs making 1 call to namespace::clean::BEGIN@2.2 # spent 69µs making 1 call to warnings::import
3
4package B::Hooks::EndOfScope;
5
# spent 18µs within B::Hooks::EndOfScope::BEGIN@5 which was called: # once (18µs+0s) by namespace::clean::BEGIN@17 at line 7
BEGIN {
6120µs $B::Hooks::EndOfScope::AUTHORITY = 'cpan:FLORA';
7182µs118µs}
# spent 18µs making 1 call to B::Hooks::EndOfScope::BEGIN@5
8
# spent 16µs within B::Hooks::EndOfScope::BEGIN@8 which was called: # once (16µs+0s) by namespace::clean::BEGIN@17 at line 10
BEGIN {
9128µs $B::Hooks::EndOfScope::VERSION = '0.09';
101100µs116µs}
# spent 16µs making 1 call to B::Hooks::EndOfScope::BEGIN@8
11# ABSTRACT: Execute code after a scope finished compilation
12
133146µs173µs
# spent 73µs within B::Hooks::EndOfScope::BEGIN@13 which was called: # once (73µs+0s) by namespace::clean::BEGIN@17 at line 13
use 5.008000;
# spent 73µs making 1 call to B::Hooks::EndOfScope::BEGIN@13
143691µs34.31ms
# spent 4.14ms (2.32+1.82) within B::Hooks::EndOfScope::BEGIN@14 which was called: # once (2.32ms+1.82ms) by namespace::clean::BEGIN@17 at line 14
use Variable::Magic 0.34;
# spent 4.14ms making 1 call to B::Hooks::EndOfScope::BEGIN@14 # spent 113µs making 1 call to Exporter::import # spent 60µs making 1 call to UNIVERSAL::VERSION
15
1612.80ms
# spent 2.87ms (74µs+2.80) within B::Hooks::EndOfScope::BEGIN@16 which was called: # once (74µs+2.80ms) by namespace::clean::BEGIN@17 at line 19
use Sub::Exporter -setup => {
# spent 2.80ms making 1 call to Sub::Exporter::__ANON__[Sub/Exporter.pm:756]
17 exports => ['on_scope_end'],
18 groups => { default => ['on_scope_end'] },
193854µs12.87ms};
# spent 2.87ms making 1 call to B::Hooks::EndOfScope::BEGIN@16
20
- -
23{
2416µs my $wiz = Variable::Magic::wizard
2546729µs
# spent 510µs within B::Hooks::EndOfScope::__ANON__[/home/doy/perl5/perlbrew/perls/perl-5.10.1/lib/site_perl/5.10.1/B/Hooks/EndOfScope.pm:25] which was called 46 times, avg 11µs/call: # 46 times (510µs+0s) by Variable::Magic::cast at line 37, avg 11µs/call
data => sub { [$_[1]] },
261392.31ms47268ms
# spent 270ms (2.10+268) within B::Hooks::EndOfScope::__ANON__[/home/doy/perl5/perlbrew/perls/perl-5.10.1/lib/site_perl/5.10.1/B/Hooks/EndOfScope.pm:26] which was called 46 times, avg 5.87ms/call: # once (46µs+30.3ms) by KiokuDB::LiveObjects::BEGIN@14 at line 59 of KiokuDB/LiveObjects/TXNScope.pm # once (58µs+13.1ms) by KiokuDB::BEGIN@10 at line 61 of KiokuDB/Backend.pm # once (85µs+11.4ms) by KiokuDB::BEGIN@13 at line 535 of KiokuDB/LiveObjects.pm # once (49µs+9.79ms) by KiokuDB::Collapser::BEGIN@12 at line 308 of KiokuDB/Entry.pm # once (67µs+8.16ms) by KiokuDB::TypeMap::BEGIN@9 at line 12 of KiokuDB/TypeMap/Entry.pm # once (45µs+6.01ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 22 of KiokuDB/Role/UUIDs.pm # once (47µs+5.92ms) by main::BEGIN@0 at line 659 of KiokuDB.pm # once (47µs+5.86ms) by KiokuDB::BEGIN@11 at line 400 of KiokuDB/Collapser.pm # once (41µs+5.80ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 14 of KiokuDB/Role/UUIDs/LibUUID.pm # once (46µs+5.75ms) by KiokuDB::Collapser::BEGIN@18 at line 447 of Data/Visitor.pm # once (48µs+5.61ms) by KiokuDB::BEGIN@12 at line 385 of KiokuDB/Linker.pm # once (48µs+5.58ms) by KiokuDB::BEGIN@14 at line 175 of KiokuDB/TypeMap.pm # once (47µs+5.42ms) by KiokuDB::TypeMap::Resolver::BEGIN@9 at line 488 of KiokuDB/TypeMap/Entry/MOP.pm # once (41µs+5.18ms) by MooseX::Clone::BEGIN@13 at line 40 of MooseX/Clone/Meta/Attribute/Trait/Copy.pm # once (43µs+5.17ms) by MooseX::Clone::BEGIN@11 at line 27 of MooseX/Clone/Meta/Attribute/Trait/StorableClone.pm # once (44µs+5.16ms) by MooseX::Clone::BEGIN@10 at line 113 of MooseX/Clone/Meta/Attribute/Trait/Clone.pm # once (44µs+5.13ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 63 of MooseX/Clone.pm # once (43µs+4.98ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 14 of KiokuDB/TypeMap/Entry/Std/ID.pm # once (47µs+4.96ms) by KiokuDB::LiveObjects::BEGIN@1 at line 354 of Devel/PartialDump.pm # once (42µs+4.95ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 12 of KiokuDB/Role/TypeMap.pm # once (44µs+4.94ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 82 of Data/Stream/Bulk.pm # once (42µs+4.93ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 26 of MooseX/Clone/Meta/Attribute/Trait/Clone/Std.pm # once (44µs+4.92ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 58 of KiokuDB/TypeMap/Entry/Std/Intrinsic.pm # once (43µs+4.91ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 51 of KiokuDB/TypeMap/Entry/Std/Expand.pm # once (41µs+4.91ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 20 of KiokuDB/TypeMap/Entry/Std.pm # once (43µs+4.89ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 38 of KiokuDB/TypeMap/Entry/Std/Compile.pm # once (42µs+4.88ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 14 of KiokuDB/Error.pm # once (41µs+4.87ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 12 of MooseX/Clone/Meta/Attribute/Trait/Clone/Base.pm # once (45µs+4.85ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 53 of KiokuDB/Role/API.pm # once (42µs+4.86ms) by MooseX::Clone::BEGIN@12 at line 31 of MooseX/Clone/Meta/Attribute/Trait/NoClone.pm # once (46µs+4.61ms) by KiokuDB::Collapser::BEGIN@15 at line 235 of KiokuDB/Collapser/Buffer.pm # once (45µs+4.54ms) by KiokuDB::BEGIN@16 at line 121 of KiokuDB/TypeMap/Resolver.pm # once (42µs+4.32ms) by KiokuDB::TypeMap::BEGIN@10 at line 18 of KiokuDB/TypeMap/Entry/Alias.pm # once (43µs+4.30ms) by KiokuDB::LiveObjects::BEGIN@13 at line 64 of KiokuDB/LiveObjects/Scope.pm # once (43µs+4.30ms) by KiokuDB::BEGIN@17 at line 83 of KiokuDB/Stream/Objects.pm # once (46µs+4.29ms) by KiokuDB::Collapser::BEGIN@16 at line 31 of KiokuDB/Error/UnknownObjects.pm # once (43µs+4.28ms) by KiokuDB::BEGIN@15 at line 32 of KiokuDB/TypeMap/Shadow.pm # once (44µs+4.26ms) by KiokuDB::TypeMap::Entry::MOP::BEGIN@9 at line 55 of KiokuDB/Thunk.pm # once (44µs+4.21ms) by KiokuDB::Linker::BEGIN@18 at line 43 of KiokuDB/Error/MissingObjects.pm # once (45µs+4.21ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 40 of Data/Stream/Bulk/Nil.pm # once (43µs+4.20ms) by KiokuDB::TypeMap::Entry::Std::BEGIN@6 at line 30 of KiokuDB/TypeMap/Entry/Compiled.pm # once (44µs+4.17ms) by KiokuDB::Collapser::BEGIN@14 at line 43 of KiokuDB/Reference.pm # once (44µs+4.16ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 58 of Data/Stream/Bulk/Cat.pm # once (40µs+4.15ms) by Class::MOP::__ANON__[/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP.pm:118] at line 43 of Data/Stream/Bulk/Filter.pm # once (41µs+4.15ms) by KiokuDB::Collapser::BEGIN@13 at line 31 of KiokuDB/Entry/Skip.pm # once (40µs+509µs) by KiokuDB::LiveObjects::BEGIN@7 at line 35 of KiokuDB/LiveObjects/Guard.pm
free => sub { $_->() for @{ $_[1] }; () };
# spent 268ms making 46 calls to namespace::clean::__ANON__[namespace/clean.pm:117], avg 5.82ms/call # spent 222µs making 1 call to Variable::Magic::wizard
27
28
# spent 4.28ms (2.21+2.07) within B::Hooks::EndOfScope::on_scope_end which was called 46 times, avg 93µs/call: # 46 times (2.21ms+2.07ms) by namespace::clean::import at line 117 of namespace/clean.pm, avg 93µs/call
sub on_scope_end (&) {
291381.88ms my $cb = shift;
30
31 $^H |= 0x020000;
32
3346907µs46326µs if (my $stack = Variable::Magic::getdata %^H, $wiz) {
# spent 326µs making 46 calls to Variable::Magic::getdata, avg 7µs/call
34 push @{ $stack }, $cb;
35 }
36 else {
371746µs922.25ms Variable::Magic::cast %^H, $wiz, $cb;
# spent 1.74ms making 46 calls to Variable::Magic::cast, avg 38µs/call # spent 510µs making 46 calls to B::Hooks::EndOfScope::__ANON__[B/Hooks/EndOfScope.pm:25], avg 11µs/call
38 }
39 }
40}
41
42
43123µs1;
44
45__END__
Report produced by the NYTProf 4.04 Perl profiler, developed by Tim Bunce and Adam Kaplan.