← Index
NYTProf Performance Profile   « block view • line view • sub view »
For -e
  Run on Wed Nov 17 22:00:36 2010
Reported on Wed Nov 17 22:13:38 2010

Filename/home/doy/coding/src/Moose/blib/lib//Moose/Meta/Role/Application/ToRole.pm
StatementsExecuted 5543 statements in 84.0ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
681147.5ms402msMoose::Meta::Role::Application::ToRole::::apply_methodsMoose::Meta::Role::Application::ToRole::apply_methods
204319.39ms27.7msMoose::Meta::Role::Application::ToRole::::apply_method_modifiersMoose::Meta::Role::Application::ToRole::apply_method_modifiers
68115.25ms28.4msMoose::Meta::Role::Application::ToRole::::apply_override_method_modifiersMoose::Meta::Role::Application::ToRole::apply_override_method_modifiers
68114.09ms10.3msMoose::Meta::Role::Application::ToRole::::check_role_exclusionsMoose::Meta::Role::Application::ToRole::check_role_exclusions
68113.77ms530msMoose::Meta::Role::Application::ToRole::::applyMoose::Meta::Role::Application::ToRole::apply
68113.60ms23.1msMoose::Meta::Role::Application::ToRole::::check_required_methodsMoose::Meta::Role::Application::ToRole::check_required_methods
68113.00ms13.3msMoose::Meta::Role::Application::ToRole::::apply_attributesMoose::Meta::Role::Application::ToRole::apply_attributes
6811496µs496µsMoose::Meta::Role::Application::ToRole::::check_required_attributesMoose::Meta::Role::Application::ToRole::check_required_attributes
11182µs100µsMoose::Meta::Role::Application::ToRole::::BEGIN@3Moose::Meta::Role::Application::ToRole::BEGIN@3
11145µs298µsMoose::Meta::Role::Application::ToRole::::BEGIN@13Moose::Meta::Role::Application::ToRole::BEGIN@13
11144µs280µsMoose::Meta::Role::Application::ToRole::::BEGIN@7Moose::Meta::Role::Application::ToRole::BEGIN@7
11139µs107µsMoose::Meta::Role::Application::ToRole::::BEGIN@4Moose::Meta::Role::Application::ToRole::BEGIN@4
11139µs2.71msMoose::Meta::Role::Application::ToRole::::BEGIN@5Moose::Meta::Role::Application::ToRole::BEGIN@5
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Moose::Meta::Role::Application::ToRole;
2
33105µs2119µs
# spent 100µs (82+18) within Moose::Meta::Role::Application::ToRole::BEGIN@3 which was called: # once (82µs+18µs) by Moose::BEGIN@32 at line 3
use strict;
# spent 100µs making 1 call to Moose::Meta::Role::Application::ToRole::BEGIN@3 # spent 19µs making 1 call to strict::import
4396µs2175µs
# spent 107µs (39+68) within Moose::Meta::Role::Application::ToRole::BEGIN@4 which was called: # once (39µs+68µs) by Moose::BEGIN@32 at line 4
use warnings;
# spent 107µs making 1 call to Moose::Meta::Role::Application::ToRole::BEGIN@4 # spent 68µs making 1 call to warnings::import
53142µs25.38ms
# spent 2.71ms (39µs+2.67) within Moose::Meta::Role::Application::ToRole::BEGIN@5 which was called: # once (39µs+2.67ms) by Moose::BEGIN@32 at line 5
use metaclass;
# spent 2.71ms making 1 call to Moose::Meta::Role::Application::ToRole::BEGIN@5 # spent 2.67ms making 1 call to metaclass::import
6
73252µs2516µs
# spent 280µs (44+236) within Moose::Meta::Role::Application::ToRole::BEGIN@7 which was called: # once (44µs+236µs) by Moose::BEGIN@32 at line 7
use Scalar::Util 'blessed';
# spent 280µs making 1 call to Moose::Meta::Role::Application::ToRole::BEGIN@7 # spent 236µs making 1 call to Exporter::import
8
916µsour $VERSION = '1.19';
10163µs$VERSION = eval $VERSION;
# spent 12µs executing statements in string eval
1113µsour $AUTHORITY = 'cpan:STEVAN';
12
1332.57ms2551µs
# spent 298µs (45+253) within Moose::Meta::Role::Application::ToRole::BEGIN@13 which was called: # once (45µs+253µs) by Moose::BEGIN@32 at line 13
use base 'Moose::Meta::Role::Application';
# spent 298µs making 1 call to Moose::Meta::Role::Application::ToRole::BEGIN@13 # spent 253µs making 1 call to base::import
14
15
# spent 530ms (3.77+526) within Moose::Meta::Role::Application::ToRole::apply which was called 68 times, avg 7.80ms/call: # 68 times (3.77ms+526ms) by Moose::Meta::Role::apply at line 483 of Moose/Meta/Role.pm, avg 7.80ms/call
sub apply {
1668321µs my ($self, $role1, $role2) = @_;
17681.89ms68519ms $self->SUPER::apply($role1, $role2);
# spent 519ms making 68 calls to Moose::Meta::Role::Application::apply, avg 7.64ms/call
18681.44ms687.10ms $role2->add_role($role1);
# spent 7.10ms making 68 calls to Moose::Meta::Role::add_role, avg 104µs/call
19}
20
21
# spent 10.3ms (4.09+6.18) within Moose::Meta::Role::Application::ToRole::check_role_exclusions which was called 68 times, avg 151µs/call: # 68 times (4.09ms+6.18ms) by Moose::Meta::Role::Application::apply at line 50 of Moose/Meta/Role/Application.pm, avg 151µs/call
sub check_role_exclusions {
2268273µs my ($self, $role1, $role2) = @_;
23682.27ms1363.48ms if ( $role2->excludes_role($role1->name) ) {
# spent 3.00ms making 68 calls to Moose::Meta::Role::excludes_role, avg 44µs/call # spent 433µs making 65 calls to Class::MOP::Package::name, avg 7µs/call # spent 45µs making 3 calls to Moose::Meta::Role::Composite::name, avg 15µs/call
24 require Moose;
25 Moose->throw_error("Conflict detected: " . $role2->name . " excludes role '" . $role1->name . "'");
26 }
27681.87ms682.70ms foreach my $excluded_role_name ($role1->get_excluded_roles_list) {
# spent 2.70ms making 68 calls to Moose::Meta::Role::get_excluded_roles_list, avg 40µs/call
28 if ( $role2->does_role($excluded_role_name) ) {
29 require Moose;
30 Moose->throw_error("The class " . $role2->name . " does the excluded role '$excluded_role_name'");
31 }
32 $role2->add_excluded_roles($excluded_role_name);
33 }
34}
35
36
# spent 23.1ms (3.60+19.5) within Moose::Meta::Role::Application::ToRole::check_required_methods which was called 68 times, avg 340µs/call: # 68 times (3.60ms+19.5ms) by Moose::Meta::Role::Application::apply at line 51 of Moose/Meta/Role/Application.pm, avg 340µs/call
sub check_required_methods {
3768234µs my ($self, $role1, $role2) = @_;
38681.67ms682.71ms foreach my $required_method ($role1->get_required_method_list) {
# spent 2.71ms making 68 calls to Moose::Meta::Role::get_required_method_list, avg 40µs/call
3930406µs30460µs my $required_method_name = $required_method->name;
# spent 460µs making 30 calls to Moose::Meta::Role::Method::Required::name, avg 15µs/call
40
4130331µs301.34ms next if $self->is_aliased_method($required_method_name);
# spent 1.34ms making 30 calls to Moose::Meta::Role::Application::is_aliased_method, avg 45µs/call
42
4330636µs3915.0ms $role2->add_required_methods($required_method)
# spent 14.2ms making 30 calls to Moose::Meta::Role::find_method_by_name, avg 472µs/call # spent 855µs making 9 calls to Moose::Meta::Role::add_required_methods, avg 95µs/call
44 unless $role2->find_method_by_name($required_method_name);
45 }
46}
47
4868792µs
# spent 496µs within Moose::Meta::Role::Application::ToRole::check_required_attributes which was called 68 times, avg 7µs/call: # 68 times (496µs+0s) by Moose::Meta::Role::Application::apply at line 52 of Moose/Meta/Role/Application.pm, avg 7µs/call
sub check_required_attributes {
49
50}
51
52
# spent 13.3ms (3.00+10.3) within Moose::Meta::Role::Application::ToRole::apply_attributes which was called 68 times, avg 195µs/call: # 68 times (3.00ms+10.3ms) by Moose::Meta::Role::Application::apply at line 54 of Moose/Meta/Role/Application.pm, avg 195µs/call
sub apply_attributes {
5368256µs my ($self, $role1, $role2) = @_;
54681.83ms682.32ms foreach my $attribute_name ($role1->get_attribute_list) {
# spent 2.32ms making 68 calls to Class::MOP::Mixin::HasAttributes::get_attribute_list, avg 34µs/call
55 # it if it has one already
5615310µs15457µs if ($role2->has_attribute($attribute_name) &&
# spent 457µs making 15 calls to Class::MOP::Mixin::HasAttributes::has_attribute, avg 30µs/call
57 # make sure we haven't seen this one already too
58 $role2->get_attribute($attribute_name) != $role1->get_attribute($attribute_name)) {
59
60 my $role2_name = $role2->name;
61
62 require Moose;
63 Moose->throw_error( "Role '"
64 . $role1->name
65 . "' has encountered an attribute conflict"
66 . " while being composed into '$role2_name'."
67 . " This is a fatal error and cannot be disambiguated."
68 . " The conflicting attribute is named '$attribute_name'." );
69 }
70 else {
7115463µs457.51ms $role2->add_attribute(
# spent 5.30ms making 15 calls to Moose::Meta::Role::add_attribute, avg 353µs/call # spent 1.74ms making 15 calls to Moose::Meta::Role::Attribute::clone, avg 116µs/call # spent 478µs making 15 calls to Class::MOP::Mixin::HasAttributes::get_attribute, avg 32µs/call
72 $role1->get_attribute($attribute_name)->clone
73 );
74 }
75 }
76}
77
78
# spent 402ms (47.5+354) within Moose::Meta::Role::Application::ToRole::apply_methods which was called 68 times, avg 5.91ms/call: # 68 times (47.5ms+354ms) by Moose::Meta::Role::Application::apply at line 55 of Moose/Meta/Role/Application.pm, avg 5.91ms/call
sub apply_methods {
7968242µs my ( $self, $role1, $role2 ) = @_;
80683.14ms6830.0ms foreach my $method ( $role1->_get_local_methods ) {
# spent 29.8ms making 65 calls to Class::MOP::Mixin::HasMethods::_get_local_methods, avg 459µs/call # spent 152µs making 3 calls to Moose::Meta::Role::Composite::_get_local_methods, avg 51µs/call
81
8252911.0ms5293.17ms my $method_name = $method->name;
# spent 3.17ms making 529 calls to Class::MOP::Method::name, avg 6µs/call
83
8452912.4ms5295.62ms next if $method->isa('Class::MOP::Method::Meta');
# spent 5.62ms making 529 calls to UNIVERSAL::isa, avg 11µs/call
85
864646.30ms46425.1ms unless ( $self->is_method_excluded($method_name) ) {
# spent 25.1ms making 464 calls to Moose::Meta::Role::Application::is_method_excluded, avg 54µs/call
87
884345.17ms43467.8ms my $role2_method = $role2->get_method($method_name);
# spent 67.8ms making 434 calls to Class::MOP::Mixin::HasMethods::get_method, avg 156µs/call
894342.01ms if ( $role2_method
90 && $role2_method->body != $method->body ) {
91
92 # method conflicts between roles result in the method becoming
93 # a requirement
94 $role2->add_conflicting_method(
95 name => $method_name,
96 roles => [ $role1->name, $role2->name ],
97 );
98 }
99 else {
1004345.17ms434203ms $role2->add_method(
# spent 203ms making 434 calls to Class::MOP::Mixin::HasMethods::add_method, avg 469µs/call
101 $method_name,
102 $method,
103 );
104 }
105 }
106
1074646.78ms46419.4ms next unless $self->is_method_aliased($method_name);
# spent 19.4ms making 464 calls to Moose::Meta::Role::Application::is_method_aliased, avg 42µs/call
108
109 my $aliased_method_name = $self->get_method_aliases->{$method_name};
110
111 my $role2_method = $role2->get_method($aliased_method_name);
112
113 if ( $role2_method
114 && $role2_method->body != $method->body ) {
115
116 require Moose;
117 Moose->throw_error(
118 "Cannot create a method alias if a local method of the same name exists"
119 );
120 }
121
122 $role2->add_method(
123 $aliased_method_name,
124 $role1->get_method($method_name)
125 );
126
127 if ( !$role2->has_method($method_name) ) {
128 $role2->add_required_methods($method_name)
129 unless $self->is_method_excluded($method_name);
130 }
131 }
132}
133
134
# spent 28.4ms (5.25+23.1) within Moose::Meta::Role::Application::ToRole::apply_override_method_modifiers which was called 68 times, avg 418µs/call: # 68 times (5.25ms+23.1ms) by Moose::Meta::Role::Application::apply at line 57 of Moose/Meta/Role/Application.pm, avg 418µs/call
sub apply_override_method_modifiers {
13568235µs my ($self, $role1, $role2) = @_;
136681.81ms683.27ms foreach my $method_name ($role1->get_method_modifier_list('override')) {
# spent 3.27ms making 68 calls to Moose::Meta::Role::get_method_modifier_list, avg 48µs/call
137 # it if it has one already then ...
13848881µs486.92ms if ($role2->has_method($method_name)) {
# spent 6.92ms making 48 calls to Class::MOP::Mixin::HasMethods::has_method, avg 144µs/call
139 # if it is being composed into another role
140 # we have a conflict here, because you cannot
141 # combine an overridden method with a locally
142 # defined one
143 require Moose;
144 Moose->throw_error("Role '" . $role1->name . "' has encountered an 'override' method conflict " .
145 "during composition (A local method of the same name as been found). This " .
146 "is fatal error.");
147 }
148 else {
149 # if we are a role, we need to make sure
150 # we dont have a conflict with the role
151 # we are composing into
15248654µs481.81ms if ($role2->has_override_method_modifier($method_name) &&
# spent 1.81ms making 48 calls to Moose::Meta::Role::has_override_method_modifier, avg 38µs/call
153 $role2->get_override_method_modifier($method_name) != $role2->get_override_method_modifier($method_name)) {
154
155 require Moose;
156 Moose->throw_error("Role '" . $role1->name . "' has encountered an 'override' method conflict " .
157 "during composition (Two 'override' methods of the same name encountered). " .
158 "This is fatal error.");
159 }
160 else {
161 # if there is no conflict,
162 # just add it to the role
16348955µs9611.1ms $role2->add_override_method_modifier(
# spent 9.40ms making 48 calls to Moose::Meta::Role::add_override_method_modifier, avg 196µs/call # spent 1.73ms making 48 calls to Moose::Meta::Role::get_override_method_modifier, avg 36µs/call
164 $method_name,
165 $role1->get_override_method_modifier($method_name)
166 );
167 }
168 }
169 }
170}
171
172
# spent 27.7ms (9.39+18.3) within Moose::Meta::Role::Application::ToRole::apply_method_modifiers which was called 204 times, avg 136µs/call: # 68 times (4.16ms+10.3ms) by Moose::Meta::Role::Application::apply_around_method_modifiers at line 74 of Moose/Meta/Role/Application.pm, avg 212µs/call # 68 times (2.90ms+4.36ms) by Moose::Meta::Role::Application::apply_before_method_modifiers at line 73 of Moose/Meta/Role/Application.pm, avg 107µs/call # 68 times (2.32ms+3.66ms) by Moose::Meta::Role::Application::apply_after_method_modifiers at line 75 of Moose/Meta/Role/Application.pm, avg 88µs/call
sub apply_method_modifiers {
173204764µs my ($self, $modifier_type, $role1, $role2) = @_;
174204764µs my $add = "add_${modifier_type}_method_modifier";
175204625µs my $get = "get_${modifier_type}_method_modifiers";
1762044.62ms2048.71ms foreach my $method_name ($role1->get_method_modifier_list($modifier_type)) {
# spent 8.71ms making 204 calls to Moose::Meta::Role::get_method_modifier_list, avg 43µs/call
177 $role2->$add(
178 $method_name,
179 $_
1801362.27ms1369.58ms ) foreach $role1->$get($method_name);
# spent 5.22ms making 53 calls to Moose::Meta::Role::add_around_method_modifier, avg 98µs/call # spent 2.15ms making 53 calls to Moose::Meta::Role::get_around_method_modifiers, avg 40µs/call # spent 987µs making 10 calls to Moose::Meta::Role::add_before_method_modifier, avg 99µs/call # spent 604µs making 5 calls to Moose::Meta::Role::add_after_method_modifier, avg 121µs/call # spent 413µs making 10 calls to Moose::Meta::Role::get_before_method_modifiers, avg 41µs/call # spent 206µs making 5 calls to Moose::Meta::Role::get_after_method_modifiers, avg 41µs/call
181 }
182}
183
184
185113µs1;
186
187__END__
Report produced by the NYTProf 4.04 Perl profiler, developed by Tim Bunce and Adam Kaplan.