← Index
NYTProf Performance Profile   « block view • line view • sub view »
For mentat.storage.mongo.pl
  Run on Tue Jun 24 10:04:38 2014
Reported on Tue Jun 24 10:05:09 2014

Filename/usr/share/perl/5.14/constant.pm
StatementsExecuted 2868 statements in 4.11ms
Subroutines
Calls P F Exclusive
Time
Inclusive
Time
Subroutine
107107212.40ms3.03msconstant::::importconstant::import
11311242µs242µsconstant::::CORE:matchconstant::CORE:match (opcode)
11641120µs120µsconstant::::CORE:regcompconstant::CORE:regcomp (opcode)
11118µs18µsconstant::::BEGIN@2constant::BEGIN@2
11111µs11µsconstant::::BEGIN@25constant::BEGIN@25
11110µs14µsconstant::::BEGIN@3constant::BEGIN@3
1117µs18µsconstant::::BEGIN@114constant::BEGIN@114
1117µs17µsconstant::::BEGIN@29constant::BEGIN@29
3316µs6µsconstant::::CORE:qrconstant::CORE:qr (opcode)
1116µs15µsconstant::::BEGIN@52constant::BEGIN@52
1116µs31µsconstant::::BEGIN@6constant::BEGIN@6
1116µs68µsconstant::::BEGIN@4constant::BEGIN@4
0000s0sconstant::::__ANON__[:136]constant::__ANON__[:136]
0000s0sconstant::::__ANON__[:140]constant::__ANON__[:140]
0000s0sconstant::::__ANON__[:142]constant::__ANON__[:142]
0000s0sconstant::::__ANON__[:31]constant::__ANON__[:31]
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments
Time
on line
Calls Time
in subs
Code
1package constant;
2246µs118µs
# spent 18µs within constant::BEGIN@2 which was called: # once (18µs+0s) by Time::Local::BEGIN@27 at line 2
use 5.005;
# spent 18µs making 1 call to constant::BEGIN@2
3220µs217µs
# spent 14µs (10+3) within constant::BEGIN@3 which was called: # once (10µs+3µs) by Time::Local::BEGIN@27 at line 3
use strict;
# spent 14µs making 1 call to constant::BEGIN@3 # spent 3µs making 1 call to strict::import
4225µs2130µs
# spent 68µs (6+62) within constant::BEGIN@4 which was called: # once (6µs+62µs) by Time::Local::BEGIN@27 at line 4
use warnings::register;
# spent 68µs making 1 call to constant::BEGIN@4 # spent 62µs making 1 call to warnings::register::import
5
62115µs257µs
# spent 31µs (6+26) within constant::BEGIN@6 which was called: # once (6µs+26µs) by Time::Local::BEGIN@27 at line 6
use vars qw($VERSION %declared);
# spent 31µs making 1 call to constant::BEGIN@6 # spent 25µs making 1 call to vars::import
71500ns$VERSION = '1.21';
8
9#=======================================================================
10
11# Some names are evil choices.
1216µsmy %keywords = map +($_, 1), qw{ BEGIN INIT CHECK END DESTROY AUTOLOAD };
1311µs$keywords{UNITCHECK}++ if $] > 5.009;
14
1514µsmy %forced_into_main = map +($_, 1),
16 qw{ STDIN STDOUT STDERR ARGV ARGVOUT ENV INC SIG };
17
1816µsmy %forbidden = (%keywords, %forced_into_main);
19
201700nsmy $str_end = $] >= 5.006 ? "\\z" : "\\Z";
21124µs216µsmy $normal_constant_name = qr/^_?[^\W_0-9]\w*$str_end/;
# spent 12µs making 1 call to constant::CORE:regcomp # spent 5µs making 1 call to constant::CORE:qr
2219µs25µsmy $tolerable = qr/^[A-Za-z_]\w*$str_end/;
# spent 4µs making 1 call to constant::CORE:regcomp # spent 1µs making 1 call to constant::CORE:qr
2318µs24µsmy $boolean = qr/^[01]?$str_end/;
# spent 4µs making 1 call to constant::CORE:regcomp # spent 700ns making 1 call to constant::CORE:qr
24
25
# spent 11µs within constant::BEGIN@25 which was called: # once (11µs+0s) by Time::Local::BEGIN@27 at line 32
BEGIN {
26 # We'd like to do use constant _CAN_PCS => $] > 5.009002
27 # but that's a bit tricky before we load the constant module :-)
28 # By doing this, we save 1 run time check for *every* call to import.
29251µs227µs
# spent 17µs (7+10) within constant::BEGIN@29 which was called: # once (7µs+10µs) by Time::Local::BEGIN@27 at line 29
no strict 'refs';
# spent 17µs making 1 call to constant::BEGIN@29 # spent 10µs making 1 call to strict::unimport
30211µs my $const = $] > 5.009002;
31 *_CAN_PCS = sub () {$const};
32159µs111µs}
# spent 11µs making 1 call to constant::BEGIN@25
33
34#=======================================================================
35# import() - import symbols into user's namespace
36#
37# What we actually do is define a function in the caller's namespace
38# which returns the value. The function we create will normally
39# be inlined as a constant, thereby avoiding further sub calling
40# overhead.
41#=======================================================================
42
# spent 3.03ms (2.40+627µs) within constant::import which was called 107 times, avg 28µs/call: # once (100µs+25µs) by MongoDB::BSON::Binary::BEGIN@28 at line 29 of MongoDB/BSON/Binary.pm # once (45µs+5µs) by Log::Core::Essentials::BEGIN@114 at line 114 of Log/Core/Essentials.pm # once (39µs+10µs) by Math::BigInt::Calc::BEGIN@1909 at line 1909 of Math/BigInt/Calc.pm # once (34µs+9µs) by Log::Core::Essentials::BEGIN@99 at line 99 of Log/Core/Essentials.pm # once (32µs+9µs) by Time::Local::BEGIN@27 at line 27 of Time/Local.pm # once (33µs+6µs) by Time::Local::BEGIN@28 at line 28 of Time/Local.pm # once (21µs+17µs) by Log::Core::Essentials::BEGIN@115 at line 115 of Log/Core/Essentials.pm # once (24µs+11µs) by Class::MOP::Method::Meta::BEGIN@16 at line 16 of Class/MOP/Method/Meta.pm # once (22µs+14µs) by DateTime::TimeZone::BEGIN@25 at line 25 of DateTime/TimeZone.pm # once (27µs+7µs) by Mentat::Storage::Mongo::BEGIN@178 at line 178 of Mentat/Storage/Mongo.pm # once (26µs+7µs) by Value::Convertor::BEGIN@73 at line 73 of Value/Convertor.pm # once (26µs+7µs) by Log::Writer::Email::BEGIN@101 at line 101 of Log/Writer/Email.pm # once (27µs+6µs) by Log::Filter::Set::BEGIN@108 at line 108 of Log/Filter/Set.pm # once (24µs+8µs) by DateTime::TimeZone::BEGIN@21 at line 21 of DateTime/TimeZone.pm # once (25µs+7µs) by JSON::Backend::XS::BEGIN@9 at line 9 of (eval 52)[JSON.pm:268] # once (26µs+7µs) by Log::Writer::Handle::BEGIN@143 at line 143 of Log/Writer/Handle.pm # once (25µs+7µs) by Try::Tiny::ScopeGuard::BEGIN@146 at line 146 of Try/Tiny.pm # once (24µs+7µs) by Log::Filter::Re::BEGIN@107 at line 107 of Log/Filter/Re.pm # once (24µs+6µs) by Log::Channel::Channel::BEGIN@96 at line 96 of Log/Channel/Channel.pm # once (26µs+5µs) by Log::Core::Essentials::BEGIN@105 at line 105 of Log/Core/Essentials.pm # once (24µs+6µs) by Log::Writer::Syslog::BEGIN@113 at line 113 of Log/Writer/Syslog.pm # once (23µs+7µs) by Eval::Closure::BEGIN@20 at line 20 of Eval/Closure.pm # once (24µs+6µs) by Log::Filter::Threshold::BEGIN@109 at line 109 of Log/Filter/Threshold.pm # once (21µs+9µs) by JSON::Backend::XS::BEGIN@11 at line 11 of (eval 52)[JSON.pm:268] # once (24µs+5µs) by Log::Filter::Threshold::BEGIN@110 at line 110 of Log/Filter/Threshold.pm # once (24µs+5µs) by Mentat::Storage::Mongo::BEGIN@181 at line 181 of Mentat/Storage/Mongo.pm # once (23µs+6µs) by Log::Filter::Set::BEGIN@105 at line 105 of Log/Filter/Set.pm # once (23µs+6µs) by DateTime::BEGIN@73 at line 73 of DateTime.pm # once (23µs+6µs) by DateTime::Duration::BEGIN@23 at line 23 of DateTime/Duration.pm # once (23µs+5µs) by Log::Core::Essentials::BEGIN@102 at line 102 of Log/Core/Essentials.pm # once (22µs+6µs) by Log::Filter::Module::BEGIN@98 at line 98 of Log/Filter/Module.pm # once (23µs+5µs) by Value::Convertor::BEGIN@103 at line 103 of Value/Convertor.pm # once (22µs+6µs) by Time::Local::BEGIN@29 at line 29 of Time/Local.pm # once (24µs+4µs) by DateTime::BEGIN@75 at line 75 of DateTime.pm # once (21µs+7µs) by DateTime::TimeZone::BEGIN@22 at line 22 of DateTime/TimeZone.pm # once (22µs+5µs) by Log::Filter::Threshold::BEGIN@116 at line 116 of Log/Filter/Threshold.pm # once (21µs+6µs) by Log::Writer::Handle::BEGIN@145 at line 145 of Log/Writer/Handle.pm # once (22µs+5µs) by Log::Core::Essentials::BEGIN@100 at line 100 of Log/Core/Essentials.pm # once (21µs+5µs) by Value::Convertor::BEGIN@137 at line 137 of Value/Convertor.pm # once (21µs+5µs) by Log::Writer::Handle::BEGIN@144 at line 144 of Log/Writer/Handle.pm # once (20µs+6µs) by DateTime::TimeZone::BEGIN@26 at line 26 of DateTime/TimeZone.pm # once (21µs+5µs) by Log::Filter::Module::BEGIN@99 at line 99 of Log/Filter/Module.pm # once (21µs+5µs) by Log::Writer::Email::BEGIN@102 at line 102 of Log/Writer/Email.pm # once (21µs+5µs) by Value::Convertor::BEGIN@74 at line 74 of Value/Convertor.pm # once (21µs+5µs) by Log::Writer::Syslog::BEGIN@114 at line 114 of Log/Writer/Syslog.pm # once (20µs+6µs) by DateTime::TimeZone::BEGIN@31 at line 31 of DateTime/TimeZone.pm # once (21µs+5µs) by Mentat::Storage::Mongo::BEGIN@183 at line 183 of Mentat/Storage/Mongo.pm # once (20µs+5µs) by Log::Filter::Re::BEGIN@110 at line 110 of Log/Filter/Re.pm # once (21µs+5µs) by Log::Core::Essentials::BEGIN@104 at line 104 of Log/Core/Essentials.pm # once (21µs+5µs) by Value::Convertor::BEGIN@88 at line 88 of Value/Convertor.pm # once (20µs+5µs) by Log::Channel::Channel::BEGIN@97 at line 97 of Log/Channel/Channel.pm # once (21µs+5µs) by JSON::Backend::XS::BEGIN@18 at line 18 of (eval 52)[JSON.pm:268] # once (21µs+5µs) by DateTime::BEGIN@81 at line 81 of DateTime.pm # once (20µs+6µs) by DateTime::TimeZone::BEGIN@30 at line 30 of DateTime/TimeZone.pm # once (19µs+6µs) by DateTime::TimeZone::BEGIN@27 at line 27 of DateTime/TimeZone.pm # once (20µs+5µs) by Log::Writer::Handle::BEGIN@146 at line 146 of Log/Writer/Handle.pm # once (21µs+5µs) by Value::Convertor::BEGIN@76 at line 76 of Value/Convertor.pm # once (19µs+6µs) by DateTime::TimeZone::BEGIN@29 at line 29 of DateTime/TimeZone.pm # once (20µs+5µs) by Log::Filter::Set::BEGIN@106 at line 106 of Log/Filter/Set.pm # once (20µs+5µs) by Log::Filter::Module::BEGIN@101 at line 101 of Log/Filter/Module.pm # once (19µs+6µs) by DateTime::TimeZone::BEGIN@28 at line 28 of DateTime/TimeZone.pm # once (20µs+5µs) by Log::Core::Essentials::BEGIN@110 at line 110 of Log/Core/Essentials.pm # once (20µs+5µs) by Log::Filter::Set::BEGIN@109 at line 109 of Log/Filter/Set.pm # once (20µs+5µs) by Log::Writer::Handle::BEGIN@148 at line 148 of Log/Writer/Handle.pm # once (20µs+5µs) by Log::Filter::Threshold::BEGIN@113 at line 113 of Log/Filter/Threshold.pm # once (20µs+5µs) by Log::Core::Essentials::BEGIN@111 at line 111 of Log/Core/Essentials.pm # once (20µs+5µs) by Log::Filter::Threshold::BEGIN@115 at line 115 of Log/Filter/Threshold.pm # once (20µs+5µs) by DateTime::BEGIN@79 at line 79 of DateTime.pm # once (20µs+5µs) by Log::Core::Essentials::BEGIN@101 at line 101 of Log/Core/Essentials.pm # once (20µs+5µs) by Value::Convertor::BEGIN@82 at line 82 of Value/Convertor.pm # once (19µs+5µs) by Log::Filter::Re::BEGIN@108 at line 108 of Log/Filter/Re.pm # once (20µs+5µs) by Log::Filter::Threshold::BEGIN@112 at line 112 of Log/Filter/Threshold.pm # once (20µs+5µs) by Log::Core::Essentials::BEGIN@106 at line 106 of Log/Core/Essentials.pm # once (20µs+5µs) by Log::Core::Essentials::BEGIN@112 at line 112 of Log/Core/Essentials.pm # once (21µs+3µs) by DateTime::BEGIN@76 at line 76 of DateTime.pm # once (20µs+5µs) by Value::Convertor::BEGIN@78 at line 78 of Value/Convertor.pm # once (19µs+5µs) by Log::Filter::Module::BEGIN@105 at line 105 of Log/Filter/Module.pm # once (20µs+5µs) by Value::Convertor::BEGIN@79 at line 79 of Value/Convertor.pm # once (20µs+5µs) by Log::Core::Essentials::BEGIN@116 at line 116 of Log/Core/Essentials.pm # once (21µs+3µs) by DateTime::BEGIN@77 at line 77 of DateTime.pm # once (20µs+5µs) by Value::Convertor::BEGIN@87 at line 87 of Value/Convertor.pm # once (19µs+6µs) by Value::Convertor::BEGIN@98 at line 98 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@94 at line 94 of Value/Convertor.pm # once (19µs+5µs) by Log::Filter::Set::BEGIN@112 at line 112 of Log/Filter/Set.pm # once (19µs+5µs) by Log::Filter::Re::BEGIN@111 at line 111 of Log/Filter/Re.pm # once (19µs+5µs) by Log::Filter::Module::BEGIN@102 at line 102 of Log/Filter/Module.pm # once (19µs+5µs) by Log::Filter::Set::BEGIN@111 at line 111 of Log/Filter/Set.pm # once (19µs+5µs) by Log::Core::Essentials::BEGIN@117 at line 117 of Log/Core/Essentials.pm # once (19µs+5µs) by Value::Convertor::BEGIN@101 at line 101 of Value/Convertor.pm # once (19µs+5µs) by Log::Core::Essentials::BEGIN@113 at line 113 of Log/Core/Essentials.pm # once (19µs+5µs) by Value::Convertor::BEGIN@99 at line 99 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@86 at line 86 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@83 at line 83 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@100 at line 100 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@96 at line 96 of Value/Convertor.pm # once (19µs+5µs) by Log::Core::Essentials::BEGIN@118 at line 118 of Log/Core/Essentials.pm # once (19µs+5µs) by Log::Filter::Re::BEGIN@113 at line 113 of Log/Filter/Re.pm # once (19µs+5µs) by Log::Core::Essentials::BEGIN@103 at line 103 of Log/Core/Essentials.pm # once (19µs+5µs) by Log::Filter::Module::BEGIN@104 at line 104 of Log/Filter/Module.pm # once (19µs+5µs) by Value::Convertor::BEGIN@91 at line 91 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@80 at line 80 of Value/Convertor.pm # once (19µs+5µs) by Log::Filter::Re::BEGIN@114 at line 114 of Log/Filter/Re.pm # once (19µs+5µs) by Log::Core::Essentials::BEGIN@107 at line 107 of Log/Core/Essentials.pm # once (19µs+5µs) by Value::Convertor::BEGIN@92 at line 92 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@95 at line 95 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@84 at line 84 of Value/Convertor.pm # once (19µs+5µs) by Value::Convertor::BEGIN@90 at line 90 of Value/Convertor.pm
sub import {
4311771.05ms my $class = shift;
44 return unless @_; # Ignore 'use constant;'
45 my $constants;
46 my $multiple = ref $_[0];
47 my $pkg = caller;
48 my $flush_mro;
49 my $symtab;
50
51107111µs if (_CAN_PCS) {
522271µs224µs
# spent 15µs (6+9) within constant::BEGIN@52 which was called: # once (6µs+9µs) by Time::Local::BEGIN@27 at line 52
no strict 'refs';
# spent 15µs making 1 call to constant::BEGIN@52 # spent 9µs making 1 call to strict::unimport
5310746µs $symtab = \%{$pkg . '::'};
54 };
55
56214136µs if ( $multiple ) {
57 if (ref $_[0] ne 'HASH') {
58 require Carp;
59 Carp::croak("Invalid reference type '".ref(shift)."' not 'HASH'");
60 }
61 $constants = shift;
62 } else {
63 unless (defined $_[0]) {
64 require Carp;
65 Carp::croak("Can't use undef as constant name");
66 }
67 $constants->{+shift} = undef;
68 }
69
70 foreach my $name ( keys %$constants ) {
71 # Normal constant name
72226876µs226343µs if ($name =~ $normal_constant_name and !$forbidden{$name}) {
# spent 242µs making 113 calls to constant::CORE:match, avg 2µs/call # spent 100µs making 113 calls to constant::CORE:regcomp, avg 888ns/call
73 # Everything is okay
74
75 # Name forced into main, but we're not in main. Fatal.
76 } elsif ($forced_into_main{$name} and $pkg ne 'main') {
77 require Carp;
78 Carp::croak("Constant name '$name' is forced into main::");
79
80 # Starts with double underscore. Fatal.
81 } elsif ($name =~ /^__/) {
82 require Carp;
83 Carp::croak("Constant name '$name' begins with '__'");
84
85 # Maybe the name is tolerable
86 } elsif ($name =~ $tolerable) {
87 # Then we'll warn only if you've asked for warnings
88 if (warnings::enabled()) {
89 if ($keywords{$name}) {
90 warnings::warn("Constant name '$name' is a Perl keyword");
91 } elsif ($forced_into_main{$name}) {
92 warnings::warn("Constant name '$name' is " .
93 "forced into package main::");
94 }
95 }
96
97 # Looks like a boolean
98 # use constant FRED == fred;
99 } elsif ($name =~ $boolean) {
100 require Carp;
101 if (@_) {
102 Carp::croak("Constant name '$name' is invalid");
103 } else {
104 Carp::croak("Constant name looks like boolean value");
105 }
106
107 } else {
108 # Must have bad characters
109 require Carp;
110 Carp::croak("Constant name '$name' has invalid characters");
111 }
112
113 {
1142222µs228µs
# spent 18µs (7+11) within constant::BEGIN@114 which was called: # once (7µs+11µs) by Time::Local::BEGIN@27 at line 114
no strict 'refs';
# spent 18µs making 1 call to constant::BEGIN@114 # spent 11µs making 1 call to strict::unimport
115339285µs my $full_name = "${pkg}::$name";
116 $declared{$full_name}++;
117339375µs if ($multiple || @_ == 1) {
118 my $scalar = $multiple ? $constants->{$name} : $_[0];
119
120 # Work around perl bug #xxxxx: Sub names (actually glob
121 # names in general) ignore the UTF8 flag. So we have to
122 # turn it off to get the "right" symbol table entry.
12311384µs utf8::is_utf8 $name and utf8::encode $name;
# spent 84µs making 113 calls to utf8::is_utf8, avg 740ns/call
124
125 # The constant serves to optimise this entire block out on
126 # 5.8 and earlier.
127333335µs if (_CAN_PCS && $symtab && !exists $symtab->{$name}) {
128 # No typeglob yet, so we can use a reference as space-
129 # efficient proxy for a constant subroutine
130 # The check in Perl_ck_rvconst knows that inlinable
131 # constants from cv_const_sv are read only. So we have to:
13211060µs Internals::SvREADONLY($scalar, 1);
# spent 60µs making 110 calls to Internals::SvREADONLY, avg 550ns/call
133 $symtab->{$name} = \$scalar;
134 ++$flush_mro;
135 } else {
136 *$full_name = sub () { $scalar };
137 }
138 } elsif (@_) {
139 my @list = @_;
140 *$full_name = sub () { @list };
141 } else {
142 *$full_name = sub () { };
143 }
144 }
145 }
146 # Flush the cache exactly once if we make any direct symbol table changes.
147104140µs mro::method_changed_in($pkg) if _CAN_PCS && $flush_mro;
# spent 140µs making 104 calls to mro::method_changed_in, avg 1µs/call
148}
149
150110µs1;
151
152__END__
 
# spent 242µs within constant::CORE:match which was called 113 times, avg 2µs/call: # 113 times (242µs+0s) by constant::import at line 72, avg 2µs/call
sub constant::CORE:match; # opcode
# spent 6µs within constant::CORE:qr which was called 3 times, avg 2µs/call: # once (5µs+0s) by Time::Local::BEGIN@27 at line 21 # once (1µs+0s) by Time::Local::BEGIN@27 at line 22 # once (700ns+0s) by Time::Local::BEGIN@27 at line 23
sub constant::CORE:qr; # opcode
# spent 120µs within constant::CORE:regcomp which was called 116 times, avg 1µs/call: # 113 times (100µs+0s) by constant::import at line 72, avg 888ns/call # once (12µs+0s) by Time::Local::BEGIN@27 at line 21 # once (4µs+0s) by Time::Local::BEGIN@27 at line 22 # once (4µs+0s) by Time::Local::BEGIN@27 at line 23
sub constant::CORE:regcomp; # opcode