| Filename | /home/var/www/internal/mongodb/mongo_pain.pl |
| Statements | Executed 1000022 statements in 7.08s |
| Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
|---|---|---|---|---|---|
| 1 | 1 | 1 | 2.55ms | 2.59ms | main::BEGIN@6 |
| 26 | 1 | 1 | 1.36ms | 1.61ms | Mouse::Meta::Method::Accessor::XS::_generate_reader (xsub) |
| 19 | 1 | 1 | 1.01ms | 1.20ms | Mouse::Meta::Method::Accessor::XS::_generate_accessor (xsub) |
| 1 | 1 | 1 | 747µs | 828µs | main::BEGIN@3.1 |
| 1 | 1 | 1 | 436µs | 477µs | main::BEGIN@5 |
| 1 | 1 | 1 | 308µs | 51.6ms | main::BEGIN@8 |
| 1 | 1 | 1 | 99µs | 927µs | main::BEGIN@3 |
| 20 | 3 | 2 | 50µs | 50µs | UNIVERSAL::isa (xsub) |
| 2 | 2 | 1 | 49µs | 49µs | UNIVERSAL::VERSION (xsub) |
| 16 | 1 | 1 | 31µs | 31µs | Internals::SvREADONLY (xsub) |
| 13 | 4 | 3 | 30µs | 30µs | UNIVERSAL::can (xsub) |
| 2 | 1 | 1 | 17µs | 19µs | Mouse::Meta::Method::Accessor::XS::_generate_predicate (xsub) |
| 2 | 1 | 1 | 16µs | 18µs | Mouse::Meta::Method::Accessor::XS::_generate_clearer (xsub) |
| 1 | 1 | 1 | 8µs | 8µs | version::(cmp (xsub) |
| 1 | 1 | 1 | 8µs | 8µs | version::(bool (xsub) |
| 5 | 1 | 1 | 6µs | 6µs | Mouse::Meta::Method::Constructor::XS::_generate_constructor (xsub) |
| 3 | 1 | 1 | 3µs | 3µs | Mouse::Meta::Method::Destructor::XS::_generate_destructor (xsub) |
| 0 | 0 | 0 | 0s | 0s | main::RUNTIME |
| Line | State ments |
Time on line |
Calls | Time in subs |
Code |
|---|---|---|---|---|---|
| 0 | 4 | 40µs | Profile data that couldn't be associated with a specific line: # spent 29µs making 1 call to MongoDB::Connection::DESTROY
# spent 6µs making 2 calls to Mouse::Object::DESTROY, avg 3µs/call
# spent 6µs making 1 call to Mouse::Util::END | ||
| 1 | 1 | 12µs | #!/usr/bin/perl | ||
| 2 | |||||
| 3 | 6 | 824µs | 3 | 1.84ms | use 5.010; # spent 927µs making 1 call to main::BEGIN@3
# spent 828µs making 1 call to main::BEGIN@3.1
# spent 81µs making 1 call to feature::import |
| 4 | |||||
| 5 | 3 | 426µs | 2 | 482µs | # spent 477µs (436+40) within main::BEGIN@5 which was called:
# once (436µs+40µs) by main::RUNTIME at line 5 # spent 477µs making 1 call to main::BEGIN@5
# spent 5µs making 1 call to strict::import |
| 6 | 3 | 2.44ms | 2 | 2.61ms | # spent 2.59ms (2.55+37µs) within main::BEGIN@6 which was called:
# once (2.55ms+37µs) by main::RUNTIME at line 6 # spent 2.59ms making 1 call to main::BEGIN@6
# spent 17µs making 1 call to warnings::import |
| 7 | |||||
| 8 | 3 | 330µs | 1 | 51.6ms | # spent 51.6ms (308µs+51.3) within main::BEGIN@8 which was called:
# once (308µs+51.3ms) by main::RUNTIME at line 8 # spent 51.6ms making 1 call to main::BEGIN@8 |
| 9 | |||||
| 10 | 1 | 900ns | my $MONGO_HOST = 'localhost'; | ||
| 11 | 1 | 400ns | my $MONGO_PORT = 27017; | ||
| 12 | |||||
| 13 | 1 | 334µs | 34 | 332ms | my $mongo = MongoDB::Connection->new(host => $MONGO_HOST, port => $MONGO_PORT); # spent 166ms making 1 call to Mouse::Object::new
# spent 166ms making 1 call to MongoDB::Connection::BUILD
# spent 194µs making 1 call to Mouse::Meta::Class::_calculate_all_attributes
# spent 12µs making 14 calls to Mouse::Meta::TypeConstraint::_compiled_type_constraint, avg 864ns/call
# spent 9µs making 12 calls to Mouse::Meta::Attribute::default, avg 742ns/call
# spent 2µs making 1 call to Mouse::Meta::Class::strict_constructor
# spent 2µs making 1 call to MongoDB::Connection::__ANON__[MongoDB/Connection.pm:309]
# spent 1µs making 1 call to MongoDB::Connection::__ANON__[MongoDB/Connection.pm:357]
# spent 1µs making 1 call to Mouse::Meta::Class::is_anon_class
# spent 1µs making 1 call to Mouse::Meta::Class::is_immutable |
| 14 | |||||
| 15 | 1 | 13µs | 1 | 4.23ms | my $mongo_database = $mongo->db_bench; # spent 4.23ms making 1 call to MongoDB::Connection::AUTOLOAD |
| 16 | 1 | 8µs | 1 | 127µs | my $mongo_collection = $mongo_database->tprl; # spent 127µs making 1 call to MongoDB::Database::AUTOLOAD |
| 17 | |||||
| 18 | 1 | 800ns | my $num = 1_000_000; | ||
| 19 | 1 | 74µs | while ($num-- > 0) | ||
| 20 | { | ||||
| 21 | 1000000 | 7.08s | 2000000 | 69.3s | $mongo_collection->insert( # spent 65.7s making 1000000 calls to MongoDB::Collection::insert, avg 66µs/call
# spent 3.66s making 1000000 calls to Mouse::Object::DESTROY, avg 4µs/call |
| 22 | { | ||||
| 23 | idfox => $num, | ||||
| 24 | idxxxxxx => 'outchagaloup', | ||||
| 25 | idxxxxxxref => 0, | ||||
| 26 | value => 'no_rice_without_price', | ||||
| 27 | datetime => 'newDate()', | ||||
| 28 | date => '2011-03-20', | ||||
| 29 | time => '17:00:00', | ||||
| 30 | }); | ||||
| 31 | } | ||||
# spent 31µs within Internals::SvREADONLY which was called 16 times, avg 2µs/call:
# 16 times (31µs+0s) by constant::import at line 111 of constant.pm, avg 2µs/call | |||||
# spent 1.20ms (1.01+189µs) within Mouse::Meta::Method::Accessor::XS::_generate_accessor which was called 19 times, avg 63µs/call:
# 19 times (1.01ms+189µs) by Mouse::Meta::Attribute::install_accessors at line 257 of Mouse/Meta/Attribute.pm, avg 63µs/call | |||||
# spent 18µs (16+1) within Mouse::Meta::Method::Accessor::XS::_generate_clearer which was called 2 times, avg 9µs/call:
# 2 times (16µs+1µs) by Mouse::Meta::Attribute::install_accessors at line 257 of Mouse/Meta/Attribute.pm, avg 9µs/call | |||||
# spent 19µs (17+2) within Mouse::Meta::Method::Accessor::XS::_generate_predicate which was called 2 times, avg 9µs/call:
# 2 times (17µs+2µs) by Mouse::Meta::Attribute::install_accessors at line 257 of Mouse/Meta/Attribute.pm, avg 9µs/call | |||||
# spent 1.61ms (1.36+248µs) within Mouse::Meta::Method::Accessor::XS::_generate_reader which was called 26 times, avg 62µs/call:
# 26 times (1.36ms+248µs) by Mouse::Meta::Attribute::install_accessors at line 257 of Mouse/Meta/Attribute.pm, avg 62µs/call | |||||
# spent 6µs within Mouse::Meta::Method::Constructor::XS::_generate_constructor which was called 5 times, avg 1µs/call:
# 5 times (6µs+0s) by Mouse::Meta::Class::make_immutable at line 292 of Mouse/Meta/Class.pm, avg 1µs/call | |||||
# spent 3µs within Mouse::Meta::Method::Destructor::XS::_generate_destructor which was called 3 times, avg 1µs/call:
# 3 times (3µs+0s) by Mouse::Meta::Class::make_immutable at line 298 of Mouse/Meta/Class.pm, avg 1µs/call | |||||
# spent 49µs within UNIVERSAL::VERSION which was called 2 times, avg 25µs/call:
# once (25µs+0s) by DateTime::BEGIN@46 at line 46 of DateTime.pm
# once (24µs+0s) by DateTime::BEGIN@45 at line 45 of DateTime.pm | |||||
# spent 30µs within UNIVERSAL::can which was called 13 times, avg 2µs/call:
# 8 times (16µs+0s) by Mouse::Meta::Class::verify_superclass at line 82 of Mouse/Meta/Class.pm, avg 2µs/call
# 3 times (10µs+0s) by Mouse::Exporter::build_import_methods at line 108 of Mouse/Exporter.pm, avg 3µs/call
# once (2µs+0s) by DateTime::Locale::_load_class_from_id at line 292 of DateTime/Locale.pm
# once (2µs+0s) by DateTime::Locale::_load_class_from_id at line 279 of DateTime/Locale.pm | |||||
# spent 50µs within UNIVERSAL::isa which was called 20 times, avg 2µs/call:
# 8 times (24µs+0s) by base::import at line 80 of base.pm, avg 3µs/call
# 6 times (18µs+0s) by Any::Moose::_backer_of at line 105 of Any/Moose.pm, avg 3µs/call
# 6 times (7µs+0s) by Any::Moose::_backer_of at line 106 of Any/Moose.pm, avg 1µs/call | |||||
# spent 8µs within version::(bool which was called:
# once (8µs+0s) by DynaLoader::BEGIN@24 at line 47 of Config.pm | |||||
# spent 8µs within version::(cmp which was called:
# once (8µs+0s) by DynaLoader::BEGIN@24 at line 50 of Config.pm |