← Index
NYTProf Performance Profile   « block view • line view • sub view »
For script/nytprof.pl
  Run on Thu May 31 16:49:15 2012
Reported on Thu May 31 16:50:49 2012

Filename/Users/edenc/perl5/lib/perl5/KiokuDB/TypeMap.pm
StatementsExecuted 503 statements in 4.16ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
2311826µs2.64msKiokuDB::TypeMap::::resolveKiokuDB::TypeMap::resolve
111523µs8.80msKiokuDB::TypeMap::::BEGIN@9KiokuDB::TypeMap::BEGIN@9
111476µs20.0msKiokuDB::TypeMap::::BEGIN@10KiokuDB::TypeMap::BEGIN@10
911310µs310µsKiokuDB::TypeMap::::__ANON__[:56]KiokuDB::TypeMap::__ANON__[:56]
1021234µs207msKiokuDB::TypeMap::::BUILDKiokuDB::TypeMap::BUILD (recurses: max depth 1, inclusive time 339µs)
311122µs162µsKiokuDB::TypeMap::::CORE:sortKiokuDB::TypeMap::CORE:sort (opcode)
101196µs143µsKiokuDB::TypeMap::::_build_all_entriesKiokuDB::TypeMap::_build_all_entries
101194µs137µsKiokuDB::TypeMap::::_build_all_isa_entriesKiokuDB::TypeMap::_build_all_isa_entries
91148µs48µsKiokuDB::TypeMap::::CORE:substKiokuDB::TypeMap::CORE:subst (opcode)
21133µs33µsKiokuDB::TypeMap::::CORE:regcompKiokuDB::TypeMap::CORE:regcomp (opcode)
41128µs43µsKiokuDB::TypeMap::::resolve_entryKiokuDB::TypeMap::resolve_entry
21126µs62µsKiokuDB::TypeMap::::__ANON__[:58]KiokuDB::TypeMap::__ANON__[:58]
31125µs192µsKiokuDB::TypeMap::::_build_all_isa_entry_classesKiokuDB::TypeMap::_build_all_isa_entry_classes
11121µs6.38msKiokuDB::TypeMap::::BEGIN@4KiokuDB::TypeMap::BEGIN@4
11120µs73µsKiokuDB::TypeMap::::BEGIN@7KiokuDB::TypeMap::BEGIN@7
11118µs79µsKiokuDB::TypeMap::::BEGIN@6KiokuDB::TypeMap::BEGIN@6
11116µs622µsKiokuDB::TypeMap::::BEGIN@12KiokuDB::TypeMap::BEGIN@12
91112µs12µsKiokuDB::TypeMap::::_build_includesKiokuDB::TypeMap::_build_includes
71111µs11µsKiokuDB::TypeMap::::_build_entriesKiokuDB::TypeMap::_build_entries
2113µs3µsKiokuDB::TypeMap::::CORE:matchKiokuDB::TypeMap::CORE:match (opcode)
1112µs2µsKiokuDB::TypeMap::::_build_isa_entriesKiokuDB::TypeMap::_build_isa_entries
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1#!/usr/bin/perl
2
3package KiokuDB::TypeMap;
4284µs212.7ms
# spent 6.38ms (21µs+6.36) within KiokuDB::TypeMap::BEGIN@4 which was called: # once (21µs+6.36ms) by Text::Tradition::Directory::BEGIN@9 at line 4
use Moose;
# spent 6.38ms making 1 call to KiokuDB::TypeMap::BEGIN@4 # spent 6.36ms making 1 call to Moose::Exporter::__ANON__[Moose/Exporter.pm:492]
5
6248µs2140µs
# spent 79µs (18+61) within KiokuDB::TypeMap::BEGIN@6 which was called: # once (18µs+61µs) by Text::Tradition::Directory::BEGIN@9 at line 6
use Carp qw(croak);
# spent 79µs making 1 call to KiokuDB::TypeMap::BEGIN@6 # spent 61µs making 1 call to Exporter::import
7248µs2126µs
# spent 73µs (20+53) within KiokuDB::TypeMap::BEGIN@7 which was called: # once (20µs+53µs) by Text::Tradition::Directory::BEGIN@9 at line 7
use Try::Tiny;
# spent 73µs making 1 call to KiokuDB::TypeMap::BEGIN@7 # spent 53µs making 1 call to Exporter::import
8
92314µs28.80ms
# spent 8.80ms (523µs+8.27) within KiokuDB::TypeMap::BEGIN@9 which was called: # once (523µs+8.27ms) by Text::Tradition::Directory::BEGIN@9 at line 9
use KiokuDB::TypeMap::Entry;
# spent 8.80ms making 1 call to KiokuDB::TypeMap::BEGIN@9 # spent 7µs making 1 call to UNIVERSAL::import
102251µs220.0ms
# spent 20.0ms (476µs+19.5) within KiokuDB::TypeMap::BEGIN@10 which was called: # once (476µs+19.5ms) by Text::Tradition::Directory::BEGIN@9 at line 10
use KiokuDB::TypeMap::Entry::Alias;
# spent 20.0ms making 1 call to KiokuDB::TypeMap::BEGIN@10 # spent 3µs making 1 call to UNIVERSAL::import
11
1221.38ms21.23ms
# spent 622µs (16+606) within KiokuDB::TypeMap::BEGIN@12 which was called: # once (16µs+606µs) by Text::Tradition::Directory::BEGIN@9 at line 12
use namespace::clean -except => 'meta';
# spent 622µs making 1 call to KiokuDB::TypeMap::BEGIN@12 # spent 606µs making 1 call to namespace::clean::import
13
1415µs18.92mswith qw(KiokuDB::Role::TypeMap);
# spent 8.92ms making 1 call to Moose::with
15
1618µs114.0mshas [qw(entries isa_entries)] => (
# spent 14.0ms making 1 call to Moose::has
17 #isa => "HashRef[KiokuDB::TypeMap::Entry|KiokuDB::TypeMap::Entry::Alias]", # dog slow regex
18 is => "ro",
19 lazy_build => 1,
20);
21
22717µs
# spent 11µs within KiokuDB::TypeMap::_build_entries which was called 7 times, avg 2µs/call: # 7 times (11µs+0s) by KiokuDB::TypeMap::entries at line 10 of (eval 83)[Eval/Closure.pm:125], avg 2µs/call
sub _build_entries { +{} }
2313µs
# spent 2µs within KiokuDB::TypeMap::_build_isa_entries which was called: # once (2µs+0s) by KiokuDB::TypeMap::isa_entries at line 10 of (eval 83)[Eval/Closure.pm:125]
sub _build_isa_entries { +{} }
24
2517µs113.5mshas [qw(all_entries all_isa_entries)] => (
# spent 13.5ms making 1 call to Moose::has
26 #isa => "HashRef[KiokuDB::TypeMap::Entry|KiokuDB::TypeMap::Entry::Alias]", # dog slow regex
27 is => "ro",
28 lazy_build => 1,
29);
30
3115µs19.30mshas all_isa_entry_classes => (
# spent 9.30ms making 1 call to Moose::has
32 isa => "ArrayRef[Str]",
33 is => "ro",
34 lazy_build => 1,
35);
36
3714µs110.8mshas includes => (
# spent 10.8ms making 1 call to Moose::has
38 isa => "ArrayRef[KiokuDB::TypeMap]",
39 is => "ro",
40 lazy_build => 1,
41);
42
43919µs
# spent 12µs within KiokuDB::TypeMap::_build_includes which was called 9 times, avg 1µs/call: # 9 times (12µs+0s) by KiokuDB::TypeMap::includes at line 11 of (eval 83)[Eval/Closure.pm:125], avg 1µs/call
sub _build_includes { [] }
44
451600nsmy %loaded;
46
47
# spent 2.64ms (826µs+1.82) within KiokuDB::TypeMap::resolve which was called 23 times, avg 115µs/call: # 23 times (826µs+1.82ms) by KiokuDB::TypeMap::Shadow::resolve at line 20 of KiokuDB/TypeMap/Shadow.pm, avg 115µs/call
sub resolve {
48253927µs my ( $self, $class ) = @_;
49
50 # if we're linking the class might not be loaded yet
51 unless ( $loaded{$class}++ ) {
52948µs ( my $pmfile = $class . ".pm" ) =~ s{::}{/}g;
# spent 48µs making 9 calls to KiokuDB::TypeMap::CORE:subst, avg 5µs/call
53
54
# spent 310µs within KiokuDB::TypeMap::__ANON__[/Users/edenc/perl5/lib/perl5/KiokuDB/TypeMap.pm:56] which was called 9 times, avg 34µs/call: # 9 times (310µs+0s) by Try::Tiny::try at line 76 of Try/Tiny.pm, avg 34µs/call
try {
559332µs require $pmfile;
56
# spent 62µs (26+36) within KiokuDB::TypeMap::__ANON__[/Users/edenc/perl5/lib/perl5/KiokuDB/TypeMap.pm:58] which was called 2 times, avg 31µs/call: # 2 times (26µs+36µs) by Try::Tiny::try at line 100 of Try/Tiny.pm, avg 31µs/call
} catch {
57264µs436µs croak $_ unless /Can't locate \Q$pmfile\E in \@INC/;
# spent 33µs making 2 calls to KiokuDB::TypeMap::CORE:regcomp, avg 16µs/call # spent 3µs making 2 calls to KiokuDB::TypeMap::CORE:match, avg 1µs/call
5818616µs };
# spent 558µs making 9 calls to Try::Tiny::try, avg 62µs/call # spent 58µs making 9 calls to Try::Tiny::catch, avg 6µs/call
59 }
60
61 # if this is an anonymous class, redo the lookup using a single named
62 # ancestor
632340µs if ( my $meta = Class::MOP::get_metaclass_by_name($class) ) {
# spent 40µs making 23 calls to Class::MOP::get_metaclass_by_name, avg 2µs/call
6416266µs if ( $meta->is_anon_class ) {
# spent 266µs making 16 calls to Class::MOP::Class::is_anon_class, avg 17µs/call
65 my $ancestor = $meta;
66
67 search: {
68 my @super = $ancestor->superclasses;
69
70 if ( @super == 1 ) {
71 $ancestor = Class::MOP::get_metaclass_by_name($super[0]);
72 if ( $ancestor->is_anon_class ) {
73 redo search;
74 }
75 } else {
76 croak "Cannot resolve anonymous class with multiple inheritence: $class";
77 }
78 }
79
80 return $self->resolve( $ancestor->name );
81 }
82 }
83
84
8548346µs if ( my $entry = $self->all_entries->{$class} || $self->all_isa_entries->{$class} ) {
# spent 159µs making 23 calls to KiokuDB::TypeMap::all_entries, avg 7µs/call # spent 144µs making 21 calls to KiokuDB::TypeMap::all_isa_entries, avg 7µs/call # spent 43µs making 4 calls to KiokuDB::TypeMap::resolve_entry, avg 11µs/call
86 return $self->resolve_entry( $entry );
87 } else {
8819320µs foreach my $superclass ( @{ $self->all_isa_entry_classes } ) {
# spent 320µs making 19 calls to KiokuDB::TypeMap::all_isa_entry_classes, avg 17µs/call
8989180µs if ( $class->isa($superclass) ) {
# spent 180µs making 89 calls to UNIVERSAL::isa, avg 2µs/call
90 return $self->resolve_entry( $self->all_isa_entries->{$superclass} );
91 }
92 }
93 }
94
95 return;
96}
97
98
# spent 43µs (28+15) within KiokuDB::TypeMap::resolve_entry which was called 4 times, avg 11µs/call: # 4 times (28µs+15µs) by KiokuDB::TypeMap::resolve at line 85, avg 11µs/call
sub resolve_entry {
991246µs my ( $self, $entry ) = @_;
100
101415µs if ( $entry->isa("KiokuDB::TypeMap::Entry::Alias") ) {
# spent 15µs making 4 calls to UNIVERSAL::isa, avg 4µs/call
102 return $self->resolve( $entry->to );
103 } else {
104 return $entry;
105 }
106}
107
108
# spent 207ms (234µs+207) within KiokuDB::TypeMap::BUILD which was called 10 times, avg 20.7ms/call: # 9 times (147µs+-18µs) by KiokuDB::TypeMap::new at line 66 of (eval 83)[Eval/Closure.pm:125], avg 14µs/call # once (87µs+207ms) by KiokuDB::TypeMap::Default::JSON::new at line 161 of (eval 83)[Eval/Closure.pm:125]
sub BUILD {
109111183µs my $self = shift;
110
111 # verify that there are no conflicting internal definitions
11210100µs my $reg = $self->entries;
# spent 100µs making 10 calls to KiokuDB::TypeMap::entries, avg 10µs/call
1131042µs foreach my $key ( keys %{ $self->isa_entries } ) {
# spent 42µs making 10 calls to KiokuDB::TypeMap::isa_entries, avg 4µs/call
114 if ( exists $reg->{$key} ) {
115 croak "isa entry $key already present in plain entries";
116 }
117 }
118
119 # Verify that there are no conflicts between the includesd type maps
120 my %seen;
12110207ms foreach my $map ( @{ $self->includes } ) {
# spent 207ms making 10 calls to KiokuDB::TypeMap::includes, avg 20.7ms/call, recursion: max depth 1, sum of overlapping time 154µs
1227127µs foreach my $key ( keys %{ $map->all_entries } ) {
# spent 127µs making 7 calls to KiokuDB::TypeMap::all_entries, avg 18µs/call
123 if ( $seen{$key} ) {
124 croak "entry $key found in $map conflicts with $seen{$key}";
125 }
126
127 $seen{$key} = $map;
128 }
129
1307121µs foreach my $key ( keys %{ $map->all_isa_entries } ) {
# spent 121µs making 7 calls to KiokuDB::TypeMap::all_isa_entries, avg 17µs/call
131 if ( $seen{$key} ) {
132 croak "isa entry $key found in $map conflicts with $seen{$key}";
133 }
134
135 $seen{$key} = $map;
136 }
137 }
138}
139
140
# spent 143µs (96+47) within KiokuDB::TypeMap::_build_all_entries which was called 10 times, avg 14µs/call: # 10 times (96µs+47µs) by KiokuDB::TypeMap::all_entries at line 10 of (eval 83)[Eval/Closure.pm:125], avg 14µs/call
sub _build_all_entries {
1412772µs my $self = shift;
142
143 return {
14470s map { %$_ } (
# spent 13µs making 7 calls to KiokuDB::TypeMap::all_entries, avg 2µs/call, recursion: max depth 1, sum of overlapping time 13µs
1452034µs ( map { $_->all_entries } @{ $self->includes } ),
# spent 17µs making 10 calls to KiokuDB::TypeMap::entries, avg 2µs/call # spent 16µs making 10 calls to KiokuDB::TypeMap::includes, avg 2µs/call
146 $self->entries,
147 ),
148 };
149}
150
151
# spent 137µs (94+44) within KiokuDB::TypeMap::_build_all_isa_entries which was called 10 times, avg 14µs/call: # 10 times (94µs+44µs) by KiokuDB::TypeMap::all_isa_entries at line 10 of (eval 83)[Eval/Closure.pm:125], avg 14µs/call
sub _build_all_isa_entries {
1522771µs my $self = shift;
153
154 return {
15570s map { %$_ } (
# spent 12µs making 7 calls to KiokuDB::TypeMap::all_isa_entries, avg 2µs/call, recursion: max depth 1, sum of overlapping time 12µs
1562031µs ( map { $_->all_isa_entries } @{ $self->includes } ),
# spent 18µs making 10 calls to KiokuDB::TypeMap::isa_entries, avg 2µs/call # spent 14µs making 10 calls to KiokuDB::TypeMap::includes, avg 1µs/call
157 $self->isa_entries,
158 ),
159 };
160}
161
162
# spent 192µs (25+167) within KiokuDB::TypeMap::_build_all_isa_entry_classes which was called 3 times, avg 64µs/call: # 3 times (25µs+167µs) by KiokuDB::TypeMap::all_isa_entry_classes at line 11 of (eval 83)[Eval/Closure.pm:125], avg 64µs/call
sub _build_all_isa_entry_classes {
16325184µs my $self = shift;
164
165 return [
1663840µs sort { !$a->isa($b) <=> !$b->isa($a) } # least derived first
# spent 40µs making 38 calls to UNIVERSAL::isa, avg 1µs/call
1676167µs keys %{ $self->all_isa_entries }
# spent 162µs making 3 calls to KiokuDB::TypeMap::CORE:sort, avg 54µs/call # spent 4µs making 3 calls to KiokuDB::TypeMap::all_isa_entries, avg 1µs/call
168 ];
169}
170
17118µs210.4ms__PACKAGE__->meta->make_immutable;
# spent 10.4ms making 1 call to Class::MOP::Class::make_immutable # spent 31µs making 1 call to KiokuDB::TypeMap::meta
172
173143µs__PACKAGE__
174
175128µs11.77ms__END__
# spent 1.77ms making 1 call to B::Hooks::EndOfScope::__ANON__[B/Hooks/EndOfScope.pm:26]
 
# spent 3µs within KiokuDB::TypeMap::CORE:match which was called 2 times, avg 1µs/call: # 2 times (3µs+0s) by KiokuDB::TypeMap::__ANON__[/Users/edenc/perl5/lib/perl5/KiokuDB/TypeMap.pm:58] at line 57, avg 1µs/call
sub KiokuDB::TypeMap::CORE:match; # opcode
# spent 33µs within KiokuDB::TypeMap::CORE:regcomp which was called 2 times, avg 16µs/call: # 2 times (33µs+0s) by KiokuDB::TypeMap::__ANON__[/Users/edenc/perl5/lib/perl5/KiokuDB/TypeMap.pm:58] at line 57, avg 16µs/call
sub KiokuDB::TypeMap::CORE:regcomp; # opcode
# spent 162µs (122+40) within KiokuDB::TypeMap::CORE:sort which was called 3 times, avg 54µs/call: # 3 times (122µs+40µs) by KiokuDB::TypeMap::_build_all_isa_entry_classes at line 167, avg 54µs/call
sub KiokuDB::TypeMap::CORE:sort; # opcode
# spent 48µs within KiokuDB::TypeMap::CORE:subst which was called 9 times, avg 5µs/call: # 9 times (48µs+0s) by KiokuDB::TypeMap::resolve at line 52, avg 5µs/call
sub KiokuDB::TypeMap::CORE:subst; # opcode
Report produced by the NYTProf 4.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.