← Index
NYTProf Performance Profile   « block view • line view • sub view »
For mongo_pain.pl
  Run on Fri Mar 25 17:00:29 2011
Reported on Fri Mar 25 17:07:09 2011

Filename/usr/local/lib/perl/5.10.1/Mouse.pm
StatementsExecuted 403 statements in 3.14ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
1116.54ms12.5msMouse::::BEGIN@4 Mouse::BEGIN@4
1113.40ms3.50msMouse::::BEGIN@14 Mouse::BEGIN@14
1113.26ms3.95msMouse::::BEGIN@18 Mouse::BEGIN@18
1112.32ms4.37msMouse::::BEGIN@16 Mouse::BEGIN@16
1111.01ms1.08msMouse::::BEGIN@15 Mouse::BEGIN@15
45458496µs9.74msMouse::::has Mouse::has
811258µs1.62msMouse::::init_meta Mouse::init_meta
111143µs215µsMouse::::BEGIN@17 Mouse::BEGIN@17
11126µs26µsMouse::::BEGIN@2 Mouse::BEGIN@2
11112µs12µsMouse::::BEGIN@13 Mouse::BEGIN@13
1118µs11µsMongoDB::Database::::meta MongoDB::Database::meta
1116µs9µsMongoDB::Cursor::::meta MongoDB::Cursor::meta
1116µs9µsMongoDB::Collection::::meta MongoDB::Collection::meta
1116µs9µsMongoDB::OID::::meta MongoDB::OID::meta
1116µs9µsMongoDB::Connection::::meta MongoDB::Connection::meta
1115µs5µsMouse::::BEGIN@8 Mouse::BEGIN@8
1115µs5µsMouse::::BEGIN@11 Mouse::BEGIN@11
1114µs4µsMouse::::BEGIN@9 Mouse::BEGIN@9
0000s0sMongoDB::GridFS::File::::metaMongoDB::GridFS::File::meta
0000s0sMongoDB::GridFS::::meta MongoDB::GridFS::meta
0000s0sMongoDB::Timestamp::::meta MongoDB::Timestamp::meta
0000s0sMouse::::__ANON__[:137] Mouse::__ANON__[:137]
0000s0sMouse::::after Mouse::after
0000s0sMouse::::around Mouse::around
0000s0sMouse::::augment Mouse::augment
0000s0sMouse::::before Mouse::before
0000s0sMouse::::extends Mouse::extends
0000s0sMouse::::inner Mouse::inner
0000s0sMouse::::override Mouse::override
0000s0sMouse::::super Mouse::super
0000s0sMouse::::with Mouse::with
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Mouse;
2350µs126µs
# spent 26µs within Mouse::BEGIN@2 which was called: # once (26µs+0s) by MongoDB::Cursor::BEGIN@21 at line 2
use 5.006_002;
# spent 26µs making 1 call to Mouse::BEGIN@2
3
43140µs212.5ms
# spent 12.5ms (6.54+5.93) within Mouse::BEGIN@4 which was called: # once (6.54ms+5.93ms) by MongoDB::Cursor::BEGIN@21 at line 4
use Mouse::Exporter; # enables strict and warnings
# spent 12.5ms making 1 call to Mouse::BEGIN@4 # spent 7µs making 1 call to Mouse::Exporter::import
5
61800nsour $VERSION = '0.91';
7
8336µs15µs
# spent 5µs within Mouse::BEGIN@8 which was called: # once (5µs+0s) by MongoDB::Cursor::BEGIN@21 at line 8
use Carp ();
# spent 5µs making 1 call to Mouse::BEGIN@8
9328µs14µs
# spent 4µs within Mouse::BEGIN@9 which was called: # once (4µs+0s) by MongoDB::Cursor::BEGIN@21 at line 9
use Scalar::Util ();
# spent 4µs making 1 call to Mouse::BEGIN@9
10
11330µs15µs
# spent 5µs within Mouse::BEGIN@11 which was called: # once (5µs+0s) by MongoDB::Cursor::BEGIN@21 at line 11
use Mouse::Util ();
# spent 5µs making 1 call to Mouse::BEGIN@11
12
13337µs112µs
# spent 12µs within Mouse::BEGIN@13 which was called: # once (12µs+0s) by MongoDB::Cursor::BEGIN@21 at line 13
use Mouse::Meta::Module;
# spent 12µs making 1 call to Mouse::BEGIN@13
143109µs13.50ms
# spent 3.50ms (3.40+97µs) within Mouse::BEGIN@14 which was called: # once (3.40ms+97µs) by MongoDB::Cursor::BEGIN@21 at line 14
use Mouse::Meta::Class;
# spent 3.50ms making 1 call to Mouse::BEGIN@14
153110µs11.08ms
# spent 1.08ms (1.01+72µs) within Mouse::BEGIN@15 which was called: # once (1.01ms+72µs) by MongoDB::Cursor::BEGIN@21 at line 15
use Mouse::Meta::Role;
# spent 1.08ms making 1 call to Mouse::BEGIN@15
163119µs14.37ms
# spent 4.37ms (2.32+2.05) within Mouse::BEGIN@16 which was called: # once (2.32ms+2.05ms) by MongoDB::Cursor::BEGIN@21 at line 16
use Mouse::Meta::Attribute;
# spent 4.37ms making 1 call to Mouse::BEGIN@16
173111µs1215µs
# spent 215µs (143+71) within Mouse::BEGIN@17 which was called: # once (143µs+71µs) by MongoDB::Cursor::BEGIN@21 at line 17
use Mouse::Object;
# spent 215µs making 1 call to Mouse::BEGIN@17
183914µs13.95ms
# spent 3.95ms (3.26+691µs) within Mouse::BEGIN@18 which was called: # once (3.26ms+691µs) by MongoDB::Cursor::BEGIN@21 at line 18
use Mouse::Util::TypeConstraints ();
# spent 3.95ms making 1 call to Mouse::BEGIN@18
19
2016µs1146µsMouse::Exporter->setup_import_methods(
# spent 146µs making 1 call to Mouse::Exporter::setup_import_methods
21 as_is => [qw(
22 extends with
23 has
24 before after around
25 override super
26 augment inner
27 ),
28 \&Scalar::Util::blessed,
29 \&Carp::confess,
30 ],
31);
32
33
34sub extends {
35 Mouse::Meta::Class->initialize(scalar caller)->superclasses(@_);
36 return;
37}
38
39sub with {
40 Mouse::Util::apply_all_roles(scalar(caller), @_);
41 return;
42}
43
44
# spent 9.74ms (496µs+9.25) within Mouse::has which was called 45 times, avg 216µs/call: # once (10µs+487µs) by MongoDB::Database::BEGIN@23 at line 84 of MongoDB/GridFS.pm # once (11µs+396µs) by MongoDB::Connection::BEGIN@23 at line 94 of MongoDB/Cursor.pm # once (22µs+346µs) by MongoDB::Connection::BEGIN@23 at line 87 of MongoDB/Cursor.pm # once (26µs+296µs) by MongoDB::Database::BEGIN@23 at line 59 of MongoDB/GridFS.pm # once (10µs+260µs) by MongoDB::Database::BEGIN@23 at line 105 of MongoDB/GridFS.pm # once (13µs+204µs) by MongoDB::GridFS::BEGIN@23 at line 39 of MongoDB/GridFS/File.pm # once (13µs+202µs) by MongoDB::BEGIN@26 at line 95 of MongoDB/Connection.pm # once (12µs+202µs) by MongoDB::Connection::BEGIN@2 at line 25 of MongoDB/Database.pm # once (12µs+201µs) by Mouse::Util::_try_load_one_class at line 51 of MongoDB/Collection.pm # once (12µs+197µs) by MongoDB::Connection::BEGIN@2.4 at line 65 of MongoDB/OID.pm # once (12µs+196µs) by MongoDB::Connection::BEGIN@2.5 at line 45 of MongoDB/Timestamp.pm # once (10µs+198µs) by MongoDB::Connection::BEGIN@23 at line 191 of MongoDB/Cursor.pm # once (10µs+195µs) by MongoDB::BEGIN@26 at line 200 of MongoDB/Connection.pm # once (10µs+194µs) by MongoDB::BEGIN@26 at line 345 of MongoDB/Connection.pm # once (10µs+191µs) by MongoDB::Connection::BEGIN@23 at line 100 of MongoDB/Cursor.pm # once (10µs+190µs) by MongoDB::Database::BEGIN@23 at line 71 of MongoDB/GridFS.pm # once (10µs+190µs) by MongoDB::Connection::BEGIN@23 at line 111 of MongoDB/Cursor.pm # once (10µs+190µs) by MongoDB::BEGIN@26 at line 269 of MongoDB/Connection.pm # once (10µs+190µs) by MongoDB::BEGIN@26 at line 187 of MongoDB/Connection.pm # once (10µs+189µs) by MongoDB::Connection::BEGIN@23 at line 197 of MongoDB/Cursor.pm # once (10µs+189µs) by MongoDB::BEGIN@26 at line 358 of MongoDB/Connection.pm # once (10µs+187µs) by MongoDB::Connection::BEGIN@2 at line 57 of MongoDB/Database.pm # once (11µs+186µs) by MongoDB::GridFS::BEGIN@23 at line 53 of MongoDB/GridFS/File.pm # once (10µs+186µs) by Mouse::Util::_try_load_one_class at line 65 of MongoDB/Collection.pm # once (10µs+186µs) by MongoDB::Connection::BEGIN@23 at line 117 of MongoDB/Cursor.pm # once (10µs+185µs) by MongoDB::BEGIN@26 at line 310 of MongoDB/Connection.pm # once (10µs+185µs) by Mouse::Util::_try_load_one_class at line 78 of MongoDB/Collection.pm # once (10µs+185µs) by MongoDB::BEGIN@26 at line 254 of MongoDB/Connection.pm # once (11µs+184µs) by MongoDB::BEGIN@26 at line 141 of MongoDB/Connection.pm # once (10µs+184µs) by MongoDB::Connection::BEGIN@2.5 at line 57 of MongoDB/Timestamp.pm # once (10µs+184µs) by MongoDB::BEGIN@26 at line 158 of MongoDB/Connection.pm # once (10µs+184µs) by MongoDB::BEGIN@26 at line 227 of MongoDB/Connection.pm # once (10µs+184µs) by MongoDB::BEGIN@26 at line 164 of MongoDB/Connection.pm # once (10µs+183µs) by MongoDB::BEGIN@26 at line 214 of MongoDB/Connection.pm # once (10µs+183µs) by MongoDB::Connection::BEGIN@23 at line 144 of MongoDB/Cursor.pm # once (10µs+183µs) by MongoDB::BEGIN@26 at line 241 of MongoDB/Connection.pm # once (10µs+183µs) by MongoDB::Connection::BEGIN@23 at line 124 of MongoDB/Cursor.pm # once (10µs+182µs) by MongoDB::Connection::BEGIN@23 at line 165 of MongoDB/Cursor.pm # once (10µs+182µs) by MongoDB::Connection::BEGIN@23 at line 182 of MongoDB/Cursor.pm # once (11µs+181µs) by MongoDB::BEGIN@26 at line 171 of MongoDB/Connection.pm # once (10µs+182µs) by MongoDB::BEGIN@26 at line 176 of MongoDB/Connection.pm # once (10µs+181µs) by MongoDB::BEGIN@26 at line 182 of MongoDB/Connection.pm # once (10µs+180µs) by MongoDB::BEGIN@26 at line 367 of MongoDB/Connection.pm # once (10µs+153µs) by MongoDB::Connection::BEGIN@23 at line 106 of MongoDB/Cursor.pm # once (10µs+151µs) by MongoDB::BEGIN@26 at line 361 of MongoDB/Connection.pm
sub has {
4545104µs45149µs my $meta = Mouse::Meta::Class->initialize(scalar caller);
# spent 149µs making 45 calls to Mouse::Meta::Module::initialize, avg 3µs/call
464524µs my $name = shift;
47
484526µs $meta->throw_error(q{Usage: has 'name' => ( key => value, ... )})
49 if @_ % 2; # odd number of arguments
50
514542µs for my $n(ref($name) ? @{$name} : $name){
5245140µs459.10ms $meta->add_attribute($n => @_);
# spent 9.10ms making 45 calls to Mouse::Meta::Class::add_attribute, avg 202µs/call
53 }
5445156µs return;
55}
56
57sub before {
58 my $meta = Mouse::Meta::Class->initialize(scalar caller);
59 my $code = pop;
60 for my $name($meta->_collect_methods(@_)) {
61 $meta->add_before_method_modifier($name => $code);
62 }
63 return;
6413µs}
651500ns
661576µs1570µssub after {
# spent 570µs making 1 call to XSLoader::load
6715µs165µs my $meta = Mouse::Meta::Class->initialize(scalar caller);
# spent 65µs making 1 call to Mouse::Exporter::do_import
6814µs142µs my $code = pop;
# spent 42µs making 1 call to Mouse::Exporter::do_import
6914µs145µs for my $name($meta->_collect_methods(@_)) {
# spent 45µs making 1 call to Mouse::Exporter::do_import
70110µs $meta->add_after_method_modifier($name => $code);
71 }
72 return;
73}
74
75sub around {
76 my $meta = Mouse::Meta::Class->initialize(scalar caller);
77 my $code = pop;
78 for my $name($meta->_collect_methods(@_)) {
79 $meta->add_around_method_modifier($name => $code);
80 }
81 return;
82}
83
841200nsour $SUPER_PACKAGE;
851100nsour $SUPER_BODY;
861300nsour @SUPER_ARGS;
87
88sub super {
89 # This check avoids a recursion loop - see
90 # t/100_bugs/020_super_recursion.t
91 return if defined $SUPER_PACKAGE && $SUPER_PACKAGE ne caller();
92 return if !defined $SUPER_BODY;
93 $SUPER_BODY->(@SUPER_ARGS);
94}
95
96sub override {
97 # my($name, $method) = @_;
98 Mouse::Meta::Class->initialize(scalar caller)->add_override_method_modifier(@_);
99}
100
1011200nsour %INNER_BODY;
1021100nsour %INNER_ARGS;
103
104sub inner {
105 my $pkg = caller();
106 if ( my $body = $INNER_BODY{$pkg} ) {
107 my $args = $INNER_ARGS{$pkg};
108 local $INNER_ARGS{$pkg};
109 local $INNER_BODY{$pkg};
110 return $body->(@{$args});
111 }
112 else {
113 return;
114 }
115}
116
117sub augment {
118 #my($name, $method) = @_;
119 Mouse::Meta::Class->initialize(scalar caller)->add_augment_method_modifier(@_);
120 return;
121}
122
123
# spent 1.62ms (258µs+1.36) within Mouse::init_meta which was called 8 times, avg 203µs/call: # 8 times (258µs+1.36ms) by Mouse::Exporter::do_import at line 180 of Mouse/Exporter.pm, avg 203µs/call
sub init_meta {
12482µs shift;
125815µs my %args = @_;
126
12786µs my $class = $args{for_class}
128 or confess("Cannot call init_meta without specifying a for_class");
129
13085µs my $base_class = $args{base_class} || 'Mouse::Object';
13185µs my $metaclass = $args{metaclass} || 'Mouse::Meta::Class';
132
133823µs8204µs my $meta = $metaclass->initialize($class);
# spent 204µs making 8 calls to Mouse::Meta::Module::initialize, avg 26µs/call
134
135
# spent 9µs (6+3) within MongoDB::Cursor::meta which was called: # once (6µs+3µs) by MongoDB::Connection::BEGIN@23 at line 488 of MongoDB/Cursor.pm # spent 9µs (6+3) within MongoDB::OID::meta which was called: # once (6µs+3µs) by MongoDB::Connection::BEGIN@2.4 at line 144 of MongoDB/OID.pm # spent 9µs (6+3) within MongoDB::Connection::meta which was called: # once (6µs+3µs) by MongoDB::BEGIN@26 at line 738 of MongoDB/Connection.pm # spent 11µs (8+3) within MongoDB::Database::meta which was called: # once (8µs+3µs) by MongoDB::Connection::BEGIN@2 at line 329 of MongoDB/Database.pm # spent 9µs (6+3) within MongoDB::Collection::meta which was called: # once (6µs+3µs) by Mouse::Util::_try_load_one_class at line 724 of MongoDB/Collection.pm
$meta->add_method(meta => sub{
136528µs517µs return $metaclass->initialize(ref($_[0]) || $_[0]);
# spent 17µs making 5 calls to Mouse::Meta::Module::initialize, avg 3µs/call
1378149µs877µs });
# spent 77µs making 8 calls to Mouse::Meta::Module::add_method, avg 10µs/call
138
139840µs16432µs $meta->superclasses($base_class)
# spent 432µs making 16 calls to Mouse::Meta::Class::superclasses, avg 27µs/call
140 unless $meta->superclasses;
141
142 # make a class type for each Mouse class
143846µs16651µs Mouse::Util::TypeConstraints::class_type($class)
# spent 551µs making 6 calls to Mouse::Util::TypeConstraints::class_type, avg 92µs/call # spent 96µs making 8 calls to Mouse::Util::TypeConstraints::find_type_constraint, avg 12µs/call # spent 5µs making 2 calls to Mouse::Meta::TypeConstraint::_identity, avg 2µs/call
144 unless Mouse::Util::TypeConstraints::find_type_constraint($class);
145
146825µs return $meta;
147}
148
14919µs1;
150__END__
Report produced by the NYTProf 4.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.