Filename | /root/mek/mentat.storage.mongo.pl |
Statements | Executed 21 statements in 3.84ms |
Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
---|---|---|---|---|---|
1 | 1 | 1 | 8.55ms | 208ms | BEGIN@7 | main::
1 | 1 | 1 | 3.00ms | 582ms | BEGIN@8 | main::
252 | 1 | 1 | 2.92ms | 102ms | try {...} | Class::MOP::Attribute::
1 | 1 | 1 | 2.74ms | 6.17ms | BEGIN@6 | main::
2184 | 27 | 20 | 2.23ms | 2.23ms | isa (xsub) | UNIVERSAL::
1 | 1 | 1 | 1.83ms | 1.86ms | BEGIN@4 | main::
981 | 1 | 1 | 1.82ms | 17.9ms | around | Class::MOP::Class:::
1800 | 36 | 19 | 1.79ms | 1.79ms | can (xsub) | UNIVERSAL::
158 | 1 | 1 | 1.23ms | 66.0ms | try {...} | Class::MOP::Method::Accessor::
181 | 1 | 1 | 967µs | 115ms | try {...} | Class::MOP::Class::
1 | 1 | 1 | 335µs | 366µs | BEGIN@3 | main::
64 | 1 | 1 | 334µs | 20.7ms | try {...} | Moose::Meta::Method::Accessor::
20 | 20 | 15 | 244µs | 244µs | VERSION (xsub) | UNIVERSAL::
35 | 1 | 1 | 109µs | 25.8ms | try {...} | Class::MOP::Method::Constructor::
110 | 1 | 1 | 60µs | 60µs | SvREADONLY (xsub) | Internals::
4 | 2 | 1 | 42µs | 5.88ms | try {...} | Class::Load::
5 | 1 | 1 | 32µs | 78µs | try {...} | Moose::Object::
2 | 2 | 1 | 27µs | 27µs | encode_json | JSON::XS::
1 | 1 | 1 | 24µs | 43µs | __ANON__ | Moose::Meta::TypeConstraint::
3 | 1 | 1 | 15µs | 482µs | try {...} | Moose::Meta::Method::Destructor::
3 | 1 | 1 | 15µs | 1.52ms | try {...} | Module::Implementation::
1 | 1 | 1 | 6µs | 71µs | try {...} | DateTime::
1 | 1 | 1 | 6µs | 6µs | (bool (xsub) | version::
1 | 1 | 1 | 5µs | 5µs | (cmp (xsub) | version::
1 | 1 | 1 | 4µs | 15µs | catch {...} | Class::Load::
1 | 1 | 1 | 4µs | 4µs | CORE:print (opcode) | main::
0 | 0 | 0 | 0s | 0s | RUNTIME | main::
Line | State ments |
Time on line |
Calls | Time in subs |
Code |
---|---|---|---|---|---|
0 | 34 | 325µs | Profile data that couldn't be associated with a specific line: # spent 151µs making 1 call to Mentat::Storage::Mongo::DESTROY
# spent 80µs making 2 calls to Moose::Object::DESTROY, avg 40µs/call
# spent 22µs making 1 call to MongoDB::Cursor::DESTROY
# spent 16µs making 4 calls to MongoDB::OID::DESTROY, avg 4µs/call
# spent 8µs making 2 calls to MongoDB::Cursor::_client, avg 4µs/call
# spent 3µs making 1 call to Mentat::Storage::Mongo::END
# spent 3µs making 1 call to Log::Channel::Channel::END
# spent 2µs making 1 call to Log::Writer::Email::END
# spent 2µs making 1 call to Log::Writer::Handle::END
# spent 2µs making 1 call to Log::Filter::Severity::END
# spent 2µs making 1 call to Log::Filter::Threshold::END
# spent 2µs making 1 call to Log::Writer::Std::END
# spent 2µs making 1 call to Mentat::Storage::END
# spent 2µs making 1 call to Log::Filter::All::END
# spent 2µs making 1 call to Log::Writer::Syslog::END
# spent 2µs making 1 call to Value::Convertor::END
# spent 2µs making 1 call to Log::Loger::END
# spent 2µs making 1 call to Log::Filter::Source::END
# spent 2µs making 1 call to Log::Filter::Re::END
# spent 2µs making 1 call to Log::Writer::File::END
# spent 2µs making 1 call to Mutex::Flock::END
# spent 2µs making 1 call to Log::Filter::None::END
# spent 2µs making 1 call to Log::Writer::Module::END
# spent 2µs making 1 call to Log::Core::Essentials::END
# spent 2µs making 1 call to Log::Filter::Message::END
# spent 2µs making 1 call to Log::Channel::Module::END
# spent 2µs making 1 call to Log::Filter::Set::END
# spent 2µs making 1 call to Log::Filter::Module::END
# spent 1µs making 1 call to MongoDB::Cursor::_request_id | ||
1 | 1 | 145µs | #!/usr/bin/perl -T | ||
2 | |||||
3 | 2 | 305µs | 2 | 370µs | # spent 366µs (335+31) within main::BEGIN@3 which was called:
# once (335µs+31µs) by main::RUNTIME at line 3 # spent 366µs making 1 call to main::BEGIN@3
# spent 4µs making 1 call to strict::import |
4 | 2 | 1.75ms | 2 | 1.87ms | # spent 1.86ms (1.83+27µs) within main::BEGIN@4 which was called:
# once (1.83ms+27µs) by main::RUNTIME at line 4 # spent 1.86ms making 1 call to main::BEGIN@4
# spent 11µs making 1 call to warnings::import |
5 | |||||
6 | 2 | 120µs | 2 | 7.80ms | # spent 6.17ms (2.74+3.43) within main::BEGIN@6 which was called:
# once (2.74ms+3.43ms) by main::RUNTIME at line 6 # spent 6.17ms making 1 call to main::BEGIN@6
# spent 1.63ms making 1 call to Time::HiRes::import |
7 | 2 | 119µs | 1 | 208ms | # spent 208ms (8.55+200) within main::BEGIN@7 which was called:
# once (8.55ms+200ms) by main::RUNTIME at line 7 # spent 208ms making 1 call to main::BEGIN@7 |
8 | 2 | 1.28ms | 1 | 582ms | # spent 582ms (3.00+579) within main::BEGIN@8 which was called:
# once (3.00ms+579ms) by main::RUNTIME at line 8 # spent 582ms making 1 call to main::BEGIN@8 |
9 | |||||
10 | 1 | 7µs | 1 | 87µs | my ($min, $max) = Value::Convertor->ipv4cidr_to_bins("158.196.158.0", 24); # spent 87µs making 1 call to Value::Convertor::ipv4cidr_to_bins |
11 | 1 | 8µs | 1 | 446µs | $min = MongoDB::BSON::Binary->new(data => $min, subtype => 0); # spent 446µs making 1 call to Moose::Object::new |
12 | 1 | 2µs | 1 | 269µs | $max = MongoDB::BSON::Binary->new(data => $max, subtype => 0); # spent 269µs making 1 call to Moose::Object::new |
13 | |||||
14 | 1 | 4µs | my $filter = { | ||
15 | 'Alert.Source.Node.Address.ipv4.min' => { | ||||
16 | '$gte' => $min, | ||||
17 | }, | ||||
18 | 'Alert.Source.Node.Address.ipv4.max' => { | ||||
19 | '$lte' => $max, | ||||
20 | }, | ||||
21 | 'Alert.Classification.@text' => 'Webattack', | ||||
22 | }; | ||||
23 | |||||
24 | 1 | 4µs | 1 | 9.74ms | my $storage = Mentat::Storage::Mongo->new(database => 'mentat', collection => 'alerts'); # spent 9.74ms making 1 call to Mentat::Storage::new |
25 | 1 | 400ns | my ($results, $count); | ||
26 | |||||
27 | 1 | 10µs | 1 | 6µs | my $start = time; # spent 6µs making 1 call to Time::HiRes::time |
28 | |||||
29 | ################################################################################ | ||||
30 | # OPTION A | ||||
31 | ################################################################################ | ||||
32 | |||||
33 | #($results, $count) = $storage->find($filter); | ||||
34 | |||||
35 | ################################################################################ | ||||
36 | # OPTION B | ||||
37 | ################################################################################ | ||||
38 | |||||
39 | 1 | 3µs | 1 | 11.1s | my ($cursor, $cnta) = $storage->find_i($filter); # spent 11.1s making 1 call to Mentat::Storage::Mongo::find_i |
40 | 1 | 19µs | 3 | 4.61s | while (my $doc = $cursor->next) { # spent 2.31s making 1 call to MongoDB::Cursor::next
# spent 2.31s making 1 call to MongoDB::Cursor::_do_query
# spent 3µs making 1 call to MongoDB::Cursor::_limit |
41 | push(@$results, $doc); $count++;; | ||||
42 | } | ||||
43 | |||||
44 | ################################################################################ | ||||
45 | 1 | 7µs | 1 | 3µs | my $end = time; # spent 3µs making 1 call to Time::HiRes::time |
46 | 1 | 68µs | 1 | 4µs | print STDERR "DURATION: ".($end-$start).", COUNT: $count\n"; # spent 4µs making 1 call to main::CORE:print |
47 | |||||
# spent 60µs within Internals::SvREADONLY which was called 110 times, avg 550ns/call:
# 110 times (60µs+0s) by constant::import at line 132 of constant.pm, avg 550ns/call | |||||
# spent 244µs within UNIVERSAL::VERSION which was called 20 times, avg 12µs/call:
# once (17µs+0s) by Module::Implementation::BEGIN@12 at line 12 of Module/Implementation.pm
# once (17µs+0s) by DateTime::BEGIN@45 at line 45 of DateTime.pm
# once (14µs+0s) by DateTime::TimeZone::Europe::Prague::BEGIN@20 at line 20 of DateTime/TimeZone/Europe/Prague.pm
# once (14µs+0s) by Moose::Deprecated::BEGIN@12 at line 19 of Moose/Deprecated.pm
# once (13µs+0s) by Moose::Util::BEGIN@12 at line 12 of Moose/Util.pm
# once (13µs+0s) by Data::OptList::BEGIN@11 at line 11 of Data/OptList.pm
# once (13µs+0s) by DateTime::BEGIN@46 at line 46 of DateTime.pm
# once (12µs+0s) by Moose::Exporter::BEGIN@17 at line 17 of Moose/Exporter.pm
# once (12µs+0s) by DateTime::TimeZone::BEGIN@19 at line 19 of DateTime/TimeZone.pm
# once (12µs+0s) by Class::Load::BEGIN@9 at line 9 of Class/Load.pm
# once (12µs+0s) by DateTime::TimeZone::Local::Unix::BEGIN@12 at line 12 of DateTime/TimeZone/Local/Unix.pm
# once (12µs+0s) by JSON::BEGIN@2 at line 2 of (eval 51)[JSON.pm:252]
# once (11µs+0s) by Class::MOP::BEGIN@18 at line 18 of Class/MOP.pm
# once (11µs+0s) by Sub::Exporter::BEGIN@11 at line 11 of Sub/Exporter.pm
# once (11µs+0s) by Class::Load::XS::BEGIN@9 at line 9 of Class/Load/XS.pm
# once (11µs+0s) by Package::Stash::BEGIN@15 at line 15 of Package/Stash.pm
# once (10µs+0s) by Sub::Exporter::BEGIN@12 at line 12 of Sub/Exporter.pm
# once (10µs+0s) by Class::Load::BEGIN@10 at line 15 of Class/Load.pm
# once (10µs+0s) by DateTime::BEGIN@47 at line 48 of DateTime.pm
# once (9µs+0s) by Sub::Exporter::BEGIN@13 at line 13 of Sub/Exporter.pm | |||||
# spent 1.79ms within UNIVERSAL::can which was called 1800 times, avg 993ns/call:
# 396 times (331µs+0s) by Math::BigInt::import at line 2785 of Math/BigInt.pm, avg 836ns/call
# 347 times (261µs+0s) by Class::MOP::Class::_single_metaclass_can_be_made_compatible at line 354 of Class/MOP/Class.pm, avg 752ns/call
# 196 times (238µs+0s) by Class::MOP::Method::Generated::_compile_code at line 59 of Class/MOP/Method/Generated.pm, avg 1µs/call
# 181 times (174µs+0s) by Class::MOP::Mixin::HasAttributes::add_attribute at line 44 of Class/MOP/Mixin/HasAttributes.pm, avg 962ns/call
# 134 times (140µs+0s) by Moose::Meta::Attribute::_inline_throw_error at line 71 of Moose/Meta/Attribute.pm, avg 1µs/call
# 77 times (58µs+0s) by Class::MOP::Class::_single_metaclass_is_compatible at line 287 of Class/MOP/Class.pm, avg 749ns/call
# 58 times (77µs+0s) by Moose::Meta::Class::add_attribute at line 583 of Moose/Meta/Class.pm, avg 1µs/call
# 44 times (113µs+0s) by Moose::Meta::Attribute::install_delegation at line 1121 of Moose/Meta/Attribute.pm, avg 3µs/call
# 41 times (40µs+0s) by Moose::Meta::Class::_eval_environment at line 507 of Moose/Meta/Class.pm, avg 980ns/call
# 41 times (40µs+0s) by Moose::Meta::Class::_inline_init_attr_from_default at line 429 of Moose/Meta/Class.pm, avg 978ns/call
# 41 times (36µs+0s) by Moose::Meta::Class::_inline_check_required_attr at line 387 of Moose/Meta/Class.pm, avg 876ns/call
# 41 times (31µs+0s) by Moose::Meta::Class::_inline_triggers at line 471 of Moose/Meta/Class.pm, avg 761ns/call
# 41 times (28µs+0s) by Moose::Meta::Class::_eval_environment at line 521 of Moose/Meta/Class.pm, avg 680ns/call
# 35 times (36µs+0s) by Class::MOP::Mixin::HasMethods::_add_meta_method at line 28 of Class/MOP/Mixin/HasMethods.pm, avg 1µs/call
# 30 times (34µs+0s) by Moose::Meta::Method::_inline_throw_error at line 39 of Moose/Meta/Method.pm, avg 1µs/call
# 27 times (34µs+0s) by Math::BigInt::import at line 2846 of Math/BigInt.pm, avg 1µs/call
# 14 times (26µs+0s) by Moose::Exporter::__ANON__[/usr/local/lib/perl/5.14.2/Moose/Exporter.pm:519] at line 468 of Moose/Exporter.pm, avg 2µs/call
# 9 times (18µs+0s) by Math::BigInt::import at line 2769 of Math/BigInt.pm, avg 2µs/call
# 5 times (10µs+0s) by Moose::Object::DEMOLISHALL at line 70 of Moose/Object.pm, avg 2µs/call
# 5 times (9µs+0s) by Class::MOP::Method::Inlined::can_be_inlined at line 70 of Class/MOP/Method/Inlined.pm, avg 2µs/call
# 5 times (6µs+0s) by Class::MOP::Method::Inlined::can_be_inlined at line 58 of Class/MOP/Method/Inlined.pm, avg 1µs/call
# 5 times (5µs+0s) by Moose::Meta::Class::_call_all_triggers at line 298 of Moose/Meta/Class.pm, avg 1µs/call
# 4 times (4µs+0s) by DateTime::TimeZone::_init at line 133 of DateTime/TimeZone.pm, avg 875ns/call
# 3 times (7µs+0s) by Moose::Meta::Class::new_object at line 288 of Moose/Meta/Class.pm, avg 2µs/call
# 3 times (6µs+0s) by Sub::Exporter::default_generator at line 411 of Sub/Exporter.pm, avg 2µs/call
# 3 times (5µs+0s) by Moose::Object::BUILDALL at line 56 of Moose/Object.pm, avg 2µs/call
# 3 times (3µs+0s) by MongoDB::Collection::full_name at line 11 of (eval 62)[Eval/Closure.pm:144], avg 1µs/call
# 2 times (5µs+0s) by Moose::Util::add_method_modifier at line 239 of Moose/Util.pm, avg 3µs/call
# 2 times (3µs+0s) by if::work at line 14 of if.pm, avg 1µs/call
# once (4µs+0s) by attributes::import at line 50 of attributes.pm
# once (1µs+0s) by Sub::Install::__ANON__[/usr/local/share/perl/5.14.2/Sub/Install.pm:57] at line 45 of Sub/Install.pm
# once (1µs+0s) by Moose::Object::BEGIN@108 at line 109 of Moose/Object.pm
# once (1µs+0s) by DateTime::Locale::_load_class_from_id at line 292 of DateTime/Locale.pm
# once (1µs+0s) by DateTime::TimeZone::new at line 75 of DateTime/TimeZone.pm
# once (1µs+0s) by DateTime::Locale::_load_class_from_id at line 279 of DateTime/Locale.pm
# once (800ns+0s) by DateTime::TimeZone::new at line 100 of DateTime/TimeZone.pm | |||||
# spent 2.23ms within UNIVERSAL::isa which was called 2184 times, avg 1µs/call:
# 478 times (396µs+0s) by Class::MOP::Mixin::HasMethods::add_method at line 62 of Class/MOP/Mixin/HasMethods.pm, avg 828ns/call
# 446 times (483µs+0s) by Class::MOP::Object::_is_compatible_with at line 52 of Class/MOP/Object.pm, avg 1µs/call
# 252 times (207µs+0s) by Class::MOP::Method::Accessor::new at line 29 of Class/MOP/Method/Accessor.pm, avg 823ns/call
# 181 times (189µs+0s) by Class::MOP::Mixin::HasAttributes::add_attribute at line 23 of Class/MOP/Mixin/HasAttributes.pm, avg 1µs/call
# 181 times (118µs+0s) by Class::MOP::Attribute::attach_to_class at line 240 of Class/MOP/Attribute.pm, avg 653ns/call
# 133 times (103µs+0s) by Class::MOP::Mixin::HasMethods::get_method at line 122 of Class/MOP/Mixin/HasMethods.pm, avg 776ns/call
# 106 times (232µs+0s) by Class::MOP::Class::new_object at line 496 of Class/MOP/Class.pm, avg 2µs/call
# 90 times (159µs+0s) by base::import at line 80 of base.pm, avg 2µs/call
# 47 times (52µs+0s) by Moose::Meta::Attribute::install_delegation at line 1121 of Moose/Meta/Attribute.pm, avg 1µs/call
# 46 times (27µs+0s) by Class::MOP::Method::Wrapped::wrap at line 76 of Class/MOP/Method/Wrapped.pm, avg 583ns/call
# 36 times (70µs+0s) by Class::MOP::Method::Inlined::can_be_inlined at line 43 of Class/MOP/Method/Inlined.pm, avg 2µs/call
# 36 times (23µs+0s) by Moose::Meta::Method::Delegation::new at line 27 of Moose/Meta/Method/Delegation.pm, avg 639ns/call
# 35 times (34µs+0s) by Moose::Meta::TypeConstraint::Registry::add_type_constraint at line 51 of Moose/Meta/TypeConstraint/Registry.pm, avg 974ns/call
# 30 times (25µs+0s) by Class::MOP::Method::Constructor::new at line 23 of Class/MOP/Method/Constructor.pm, avg 823ns/call
# 20 times (39µs+0s) by metaclass::import at line 35 of metaclass.pm, avg 2µs/call
# 13 times (14µs+0s) by Moose::Exporter::_apply_metaroles at line 575 of Moose/Exporter.pm, avg 1µs/call
# 13 times (14µs+0s) by Class::MOP::Class::superclasses at line 949 of Class/MOP/Class.pm, avg 1µs/call
# 11 times (19µs+0s) by Moose::Meta::Class::superclasses at line 566 of Moose/Meta/Class.pm, avg 2µs/call
# 11 times (12µs+0s) by Moose::init_meta at line 161 of Moose.pm, avg 1µs/call
# 9 times (8µs+0s) by MongoDB::Collection::new or MongoDB::Cursor::new or MongoDB::Database::new at line 41 of (eval 62)[Eval/Closure.pm:144], avg 844ns/call
# 3 times (3µs+0s) by Moose::Meta::Method::Destructor::is_needed at line 61 of Moose/Meta/Method/Destructor.pm, avg 867ns/call
# 2 times (3µs+0s) by Class::MOP::Mixin::HasMethods::_add_meta_method at line 31 of Class/MOP/Mixin/HasMethods.pm, avg 1µs/call
# once (1µs+0s) by Eval::Closure::Sandbox_154::__ANON__[(eval 220)[/usr/local/share/perl/5.14.2/Eval/Closure.pm:144]:3] at line 3 of (eval 62)[Eval/Closure.pm:144]
# once (1µs+0s) by Moose::Meta::Attribute::_process_isa_option at line 361 of Moose/Meta/Attribute.pm
# once (900ns+0s) by DateTime::TimeZone::offset_as_seconds at line 441 of DateTime/TimeZone.pm
# once (700ns+0s) by Moose::Meta::Attribute::_process_accessors at line 1045 of Moose/Meta/Attribute.pm
# once (600ns+0s) by Moose::Meta::Attribute::_process_accessors at line 1057 of Moose/Meta/Attribute.pm | |||||
# spent 4µs within main::CORE:print which was called:
# once (4µs+0s) by main::RUNTIME at line 46 | |||||
# spent 6µs within version::(bool which was called:
# once (6µs+0s) by DynaLoader::BEGIN@21 at line 57 of Config.pm | |||||
# spent 5µs within version::(cmp which was called:
# once (5µs+0s) by DynaLoader::BEGIN@21 at line 60 of Config.pm |