← 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:07:29 2010

Filename/home/doy/coding/src/Class-MOP/blib/lib//Class/MOP/Method.pm
StatementsExecuted 9359 statements in 123ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
4285541.1ms202msClass::MOP::Method::::wrapClass::MOP::Method::wrap
10281127.5ms34.1msClass::MOP::Method::::attach_to_classClass::MOP::Method::attach_to_class
3873324.5ms31.0msClass::MOP::Method::::cloneClass::MOP::Method::clone
93223.95ms44.7msClass::MOP::Method::::_newClass::MOP::Method::_new
11173µs92µsClass::MOP::Method::::BEGIN@4Class::MOP::Method::BEGIN@4
11156µs241µsClass::MOP::Method::::BEGIN@8Class::MOP::Method::BEGIN@8
11148µs201µsClass::MOP::Method::::BEGIN@19Class::MOP::Method::BEGIN@19
11143µs230µsClass::MOP::Method::::BEGIN@7Class::MOP::Method::BEGIN@7
11141µs3.04msClass::MOP::Method::::BEGIN@14Class::MOP::Method::BEGIN@14
11139µs106µsClass::MOP::Method::::BEGIN@5Class::MOP::Method::BEGIN@5
0000s0sClass::MOP::Method::::__ANON__[:19]Class::MOP::Method::__ANON__[:19]
0000s0sClass::MOP::Method::::detach_from_classClass::MOP::Method::detach_from_class
0000s0sClass::MOP::Method::::executeClass::MOP::Method::execute
0000s0sClass::MOP::Method::::fully_qualified_nameClass::MOP::Method::fully_qualified_name
0000s0sClass::MOP::Method::::original_fully_qualified_nameClass::MOP::Method::original_fully_qualified_name
0000s0sClass::MOP::Method::::original_nameClass::MOP::Method::original_name
0000s0sClass::MOP::Method::::original_package_nameClass::MOP::Method::original_package_name
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1
2package Class::MOP::Method;
3
4397µs2110µs
# spent 92µs (73+18) within Class::MOP::Method::BEGIN@4 which was called: # once (73µs+18µs) by base::import at line 4
use strict;
# spent 92µs making 1 call to Class::MOP::Method::BEGIN@4 # spent 18µs making 1 call to strict::import
5397µs2173µs
# spent 106µs (39+67) within Class::MOP::Method::BEGIN@5 which was called: # once (39µs+67µs) by base::import at line 5
use warnings;
# spent 106µs making 1 call to Class::MOP::Method::BEGIN@5 # spent 67µs making 1 call to warnings::import
6
73132µs2418µs
# spent 230µs (43+187) within Class::MOP::Method::BEGIN@7 which was called: # once (43µs+187µs) by base::import at line 7
use Carp 'confess';
# spent 230µs making 1 call to Class::MOP::Method::BEGIN@7 # spent 188µs making 1 call to Exporter::import
83228µs2426µs
# spent 241µs (56+185) within Class::MOP::Method::BEGIN@8 which was called: # once (56µs+185µs) by base::import at line 8
use Scalar::Util 'weaken', 'reftype', 'blessed';
# spent 241µs making 1 call to Class::MOP::Method::BEGIN@8 # spent 185µs making 1 call to Exporter::import
9
1014µsour $VERSION = '1.11';
11160µs$VERSION = eval $VERSION;
# spent 10µs executing statements in string eval
1214µsour $AUTHORITY = 'cpan:STEVAN';
13
143219µs23.04ms
# spent 3.04ms (41µs+3.00) within Class::MOP::Method::BEGIN@14 which was called: # once (41µs+3.00ms) by base::import at line 14
use base 'Class::MOP::Object';
# spent 3.04ms making 1 call to Class::MOP::Method::BEGIN@14 # spent 3.00ms making 1 call to base::import, recursion: max depth 1, sum of overlapping time 3.00ms
15
16# NOTE:
17# if poked in the right way,
18# they should act like CODE refs.
1931.96ms2354µs
# spent 201µs (48+153) within Class::MOP::Method::BEGIN@19 which was called: # once (48µs+153µs) by base::import at line 19
use overload '&{}' => sub { $_[0]->body }, fallback => 1;
# spent 201µs making 1 call to Class::MOP::Method::BEGIN@19 # spent 153µs making 1 call to overload::import
20
21# construction
22
23
# spent 202ms (41.1+161) within Class::MOP::Method::wrap which was called 428 times, avg 473µs/call: # 198 times (19.0ms+17.9ms) by Class::MOP::Mixin::HasMethods::wrap_method_body at line 43 of Class/MOP/Mixin/HasMethods.pm, avg 186µs/call # 92 times (9.53ms+130ms) by Class::MOP::Method::Meta::wrap at line 58 of Class/MOP/Method/Meta.pm, avg 1.51ms/call # 66 times (6.00ms+4.47ms) by Class::MOP::Method::Wrapped::wrap at line 92 of Class/MOP/Method/Wrapped.pm, avg 159µs/call # 57 times (5.32ms+7.34ms) by Class::MOP::Attribute::_process_accessors at line 371 of Class/MOP/Attribute.pm, avg 222µs/call # 15 times (1.31ms+2.05ms) by Moose::Meta::Method::Overridden::new at line 43 of Moose/Meta/Method/Overridden.pm, avg 224µs/call
sub wrap {
244284.70ms my ( $class, @args ) = @_;
25
264282.12ms unshift @args, 'body' if @args % 2 == 1;
27
284283.77ms my %params = @args;
294281.25ms my $code = $params{body};
30
3142814.4ms8564.62ms if (blessed($code) && $code->isa(__PACKAGE__)) {
# spent 2.33ms making 428 calls to Scalar::Util::blessed, avg 5µs/call # spent 2.29ms making 428 calls to Scalar::Util::reftype, avg 5µs/call
32 my $method = $code->clone;
33 delete $params{body};
34 Class::MOP::class_of($class)->rebless_instance($method, %params);
35 return $method;
36 }
37 elsif (!ref $code || 'CODE' ne reftype($code)) {
38 confess "You must supply a CODE reference to bless, not (" . ($code || 'undef') . ")";
39 }
40
414281.52ms ($params{package_name} && $params{name})
42 || confess "You must supply the package_name and name parameters";
43
444286.06ms428154ms my $self = $class->_new(\%params);
# spent 98.5ms making 113 calls to Moose::Meta::Method::_new, avg 872µs/call # spent 36.1ms making 91 calls to Class::MOP::Method::_new, avg 396µs/call # spent 7.35ms making 86 calls to Moose::Meta::Role::Method::_new, avg 86µs/call # spent 6.64ms making 57 calls to Class::MOP::Method::Accessor::_new, avg 116µs/call # spent 3.79ms making 66 calls to Class::MOP::Method::Wrapped::_new, avg 57µs/call # spent 1.90ms making 15 calls to Moose::Meta::Method::Overridden::_new, avg 126µs/call
45
464286.68ms2902.37ms weaken($self->{associated_metaclass}) if $self->{associated_metaclass};
# spent 2.37ms making 290 calls to Scalar::Util::weaken, avg 8µs/call
47
484287.26ms return $self;
49}
50
51
# spent 44.7ms (3.95+40.7) within Class::MOP::Method::_new which was called 93 times, avg 481µs/call: # 91 times (3.88ms+32.2ms) by Class::MOP::Method::wrap at line 44, avg 396µs/call # 2 times (74µs+8.57ms) by Class::MOP::Method::Accessor::new at line 33 of Class/MOP/Method/Accessor.pm, avg 4.32ms/call
sub _new {
5293330µs my $class = shift;
53
5493973µs5240.7ms return Class::MOP::Class->initialize($class)->new_object(@_)
# spent 32.2ms making 26 calls to Class::MOP::Class::new_object, avg 1.24ms/call # spent 8.52ms making 26 calls to Class::MOP::Class::initialize, avg 328µs/call
55 if $class ne __PACKAGE__;
56
5767209µs my $params = @_ == 1 ? $_[0] : {@_};
58
59672.54ms return bless {
60 'body' => $params->{body},
61 'associated_metaclass' => $params->{associated_metaclass},
62 'package_name' => $params->{package_name},
63 'name' => $params->{name},
64 'original_method' => $params->{original_method},
65 } => $class;
66}
67
68## accessors
69
701462.10mssub associated_metaclass { shift->{'associated_metaclass'} }
71
72
# spent 34.1ms (27.5+6.56) within Class::MOP::Method::attach_to_class which was called 1028 times, avg 33µs/call: # 1028 times (27.5ms+6.56ms) by Class::MOP::Mixin::HasMethods::add_method at line 66 of Class/MOP/Mixin/HasMethods.pm, avg 33µs/call
sub attach_to_class {
7310283.63ms my ( $self, $class ) = @_;
7410285.06ms $self->{associated_metaclass} = $class;
75102826.1ms10286.56ms weaken($self->{associated_metaclass});
# spent 6.56ms making 1028 calls to Scalar::Util::weaken, avg 6µs/call
76}
77
78sub detach_from_class {
79 my $self = shift;
80 delete $self->{associated_metaclass};
81}
82
83sub fully_qualified_name {
84 my $self = shift;
85 $self->package_name . '::' . $self->name;
86}
87
88sub original_method { (shift)->{'original_method'} }
89
903875.42mssub _set_original_method { $_[0]->{'original_method'} = $_[1] }
91
92# It's possible that this could cause a loop if there is a circular
93# reference in here. That shouldn't ever happen in normal
94# circumstances, since original method only gets set when clone is
95# called. We _could_ check for such a loop, but it'd involve some sort
96# of package-lexical variable, and wouldn't be terribly subclassable.
97sub original_package_name {
98 my $self = shift;
99
100 $self->original_method
101 ? $self->original_method->original_package_name
102 : $self->package_name;
103}
104
105sub original_name {
106 my $self = shift;
107
108 $self->original_method
109 ? $self->original_method->original_name
110 : $self->name;
111}
112
113sub original_fully_qualified_name {
114 my $self = shift;
115
116 $self->original_method
117 ? $self->original_method->original_fully_qualified_name
118 : $self->fully_qualified_name;
119}
120
121sub execute {
122 my $self = shift;
123 $self->body->(@_);
124}
125
126# We used to go through use Class::MOP::Class->clone_instance to do this, but
127# this was awfully slow. This method may be called a number of times when
128# classes are loaded (especially during Moose role application), so it is
129# worth optimizing. - DR
130
# spent 31.0ms (24.5+6.50) within Class::MOP::Method::clone which was called 387 times, avg 80µs/call: # 328 times (21.0ms+5.53ms) by Class::MOP::Mixin::HasMethods::add_method at line 59 of Class/MOP/Mixin/HasMethods.pm, avg 81µs/call # 49 times (2.68ms+778µs) by Moose::Meta::Role::Composite::add_method at line 83 of Moose/Meta/Role/Composite.pm, avg 71µs/call # 10 times (799µs+189µs) by Class::MOP::MiniTrait::apply at line 25 of Class/MOP/MiniTrait.pm, avg 99µs/call
sub clone {
1313871.05ms my $self = shift;
132
13338716.9ms3872.14ms my $clone = bless { %{$self}, @_ }, blessed($self);
# spent 2.14ms making 387 calls to Scalar::Util::blessed, avg 6µs/call
134
1353874.18ms3874.36ms $clone->_set_original_method($self);
# spent 4.36ms making 387 calls to Class::MOP::Method::_set_original_method, avg 11µs/call
136
1373874.31ms return $clone;
138}
139
140111µs1;
141
142__END__
Report produced by the NYTProf 4.04 Perl profiler, developed by Tim Bunce and Adam Kaplan.