← Index
NYTProf Performance Profile   « line view »
For svc/members/upsert
  Run on Tue Jan 13 11:50:22 2015
Reported on Tue Jan 13 12:09:47 2015

Filename/usr/share/perl/5.20/Exporter/Heavy.pm
StatementsExecuted 4189 statements in 10.4ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
61117.38ms8.43msExporter::Heavy::::heavy_exportExporter::Heavy::heavy_export
172161931µs931µsExporter::Heavy::::CORE:substExporter::Heavy::CORE:subst (opcode)
21189µs94µsExporter::Heavy::::_rebuild_cacheExporter::Heavy::_rebuild_cache
61158µs740µsExporter::Heavy::::heavy_export_to_levelExporter::Heavy::heavy_export_to_level
22147µs47µsExporter::Heavy::::_push_tagsExporter::Heavy::_push_tags
293126µs26µsExporter::Heavy::::CORE:matchExporter::Heavy::CORE:match (opcode)
11116µs33µsExporter::Heavy::::BEGIN@3Exporter::Heavy::BEGIN@3
1118µs18µsExporter::Heavy::::BEGIN@4Exporter::Heavy::BEGIN@4
1117µs17µsExporter::Heavy::::BEGIN@188Exporter::Heavy::BEGIN@188
1117µs38µsExporter::Heavy::::heavy_export_ok_tagsExporter::Heavy::heavy_export_ok_tags
1116µs23µsExporter::Heavy::::heavy_export_tagsExporter::Heavy::heavy_export_tags
0000s0sExporter::Heavy::::__ANON__[:43]Exporter::Heavy::__ANON__[:43]
0000s0sExporter::Heavy::::__ANON__[:49]Exporter::Heavy::__ANON__[:49]
0000s0sExporter::Heavy::::heavy_require_versionExporter::Heavy::heavy_require_version
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Exporter::Heavy;
2
3242µs249µs
# spent 33µs (16+16) within Exporter::Heavy::BEGIN@3 which was called: # once (16µs+16µs) by Exporter::as_heavy at line 3
use strict;
# spent 33µs making 1 call to Exporter::Heavy::BEGIN@3 # spent 16µs making 1 call to strict::import
421.19ms228µs
# spent 18µs (8+10) within Exporter::Heavy::BEGIN@4 which was called: # once (8µs+10µs) by Exporter::as_heavy at line 4
no strict 'refs';
# spent 18µs making 1 call to Exporter::Heavy::BEGIN@4 # spent 10µs making 1 call to strict::unimport
5
6# On one line so MakeMaker will see it.
722µsrequire Exporter; our $VERSION = $Exporter::VERSION;
8
9#
10# We go to a lot of trouble not to 'require Carp' at file scope,
11# because Carp requires Exporter, and something has to give.
12#
13
14
# spent 94µs (89+5) within Exporter::Heavy::_rebuild_cache which was called 2 times, avg 47µs/call: # 2 times (89µs+5µs) by Exporter::Heavy::heavy_export at line 58, avg 47µs/call
sub _rebuild_cache {
1521µs my ($pkg, $exports, $cache) = @_;
16246µs303µs s/^&// foreach @$exports;
# spent 3µs making 30 calls to Exporter::Heavy::CORE:subst, avg 103ns/call
17212µs @{$cache}{@$exports} = (1) x @$exports;
1825µs my $ok = \@{"${pkg}::EXPORT_OK"};
1926µs if (@$ok) {
20123µs241µs s/^&// foreach @$ok;
# spent 1µs making 24 calls to Exporter::Heavy::CORE:subst, avg 58ns/call
2114µs @{$cache}{@$ok} = (1) x @$ok;
22 }
23}
24
25
# spent 8.43ms (7.38+1.05) within Exporter::Heavy::heavy_export which was called 61 times, avg 138µs/call: # 61 times (7.38ms+1.05ms) by Exporter::Heavy::heavy_export_to_level or Exporter::import or FileHandle::import at line 25 of Exporter.pm, avg 138µs/call
sub heavy_export {
26
27 # Save the old __WARN__ handler in case it was defined
286149µs my $oldwarn = $SIG{__WARN__};
29
30 # First make import warnings look like they're coming from the "use".
31 local $SIG{__WARN__} = sub {
32 # restore it back so proper stacking occurs
33 local $SIG{__WARN__} = $oldwarn;
34 my $text = shift;
35 if ($text =~ s/ at \S*Exporter\S*.pm line \d+.*\n//) {
36 require Carp;
37 local $Carp::CarpLevel = 1; # ignore package calling us too.
38 Carp::carp($text);
39 }
40 else {
41 warn $text;
42 }
4361285µs };
44 local $SIG{__DIE__} = sub {
45 require Carp;
46 local $Carp::CarpLevel = 1; # ignore package calling us too.
47 Carp::croak("$_[0]Illegal null symbol in \@${1}::EXPORT")
48 if $_[0] =~ /^Unable to create sub named "(.*?)::"/;
4961183µs };
50
516149µs my($pkg, $callpkg, @imports) = @_;
526112µs my($type, $sym, $cache_is_current, $oops);
5361222µs my($exports, $export_cache) = (\@{"${pkg}::EXPORT"},
54 $Exporter::Cache{$pkg} ||= {});
55
566138µs if (@imports) {
571325µs if (!%$export_cache) {
5823µs294µs _rebuild_cache ($pkg, $exports, $export_cache);
# spent 94µs making 2 calls to Exporter::Heavy::_rebuild_cache, avg 47µs/call
5921µs $cache_is_current = 1;
60 }
61
621378µs1519µs if (grep m{^[/!:]}, @imports) {
# spent 19µs making 15 calls to Exporter::Heavy::CORE:match, avg 1µs/call
631221µs my $tagsref = \%{"${pkg}::EXPORT_TAGS"};
64123µs my $tagdata;
65 my %imports;
66 my($remove, $spec, @names, @allexports);
67 # negated first item implies starting with default set:
681226µs126µs unshift @imports, ':DEFAULT' if $imports[0] =~ m/^!/;
# spent 6µs making 12 calls to Exporter::Heavy::CORE:match, avg 517ns/call
69128µs foreach $spec (@imports){
701330µs134µs $remove = $spec =~ s/^!//;
# spent 4µs making 13 calls to Exporter::Heavy::CORE:subst, avg 338ns/call
71
721345µs1320µs if ($spec =~ s/^://){
# spent 20µs making 13 calls to Exporter::Heavy::CORE:subst, avg 2µs/call
731355µs if ($spec eq 'DEFAULT'){
74 @names = @$exports;
75 }
76 elsif ($tagdata = $tagsref->{$spec}) {
77 @names = @$tagdata;
78 }
79 else {
80 warn qq["$spec" is not defined in %${pkg}::EXPORT_TAGS];
81 ++$oops;
82 next;
83 }
84 }
85 elsif ($spec =~ m:^/(.*)/$:){
86 my $patn = $1;
87 @allexports = keys %$export_cache unless @allexports; # only do keys once
88 @names = grep(/$patn/, @allexports); # not anchored by default
89 }
90 else {
91 @names = ($spec); # is a normal symbol name
92 }
93
94133µs warn "Import ".($remove ? "del":"add").": @names "
95 if $Exporter::Verbose;
96
971319µs if ($remove) {
98 foreach $sym (@names) { delete $imports{$sym} }
99 }
100 else {
10113125µs @imports{@names} = (1) x @names;
102 }
103 }
1041272µs @imports = keys %imports;
105 }
106
107133µs my @carp;
108138µs foreach $sym (@imports) {
109311100µs if (!$export_cache->{$sym}) {
110211µs43µs if ($sym =~ m/^\d/) {
# spent 2µs making 2 calls to Exporter::Heavy::CORE:subst, avg 1µs/call # spent 1µs making 2 calls to Exporter::Heavy::CORE:match, avg 550ns/call
111 $pkg->VERSION($sym); # inherit from UNIVERSAL
112 # If the version number was the only thing specified
113 # then we should act as if nothing was specified:
114 if (@imports == 1) {
115 @imports = @$exports;
116 last;
117 }
118 # We need a way to emulate 'use Foo ()' but still
119 # allow an easy version check: "use Foo 1.23, ''";
120 if (@imports == 2 and !$imports[1]) {
121 @imports = ();
122 last;
123 }
124 } elsif ($sym !~ s/^&// || !$export_cache->{$sym}) {
125 # Last chance - see if they've updated EXPORT_OK since we
126 # cached it.
127
128 unless ($cache_is_current) {
129 %$export_cache = ();
130 _rebuild_cache ($pkg, $exports, $export_cache);
131 $cache_is_current = 1;
132 }
133
134 if (!$export_cache->{$sym}) {
135 # accumulate the non-exports
136 push @carp,
137 qq["$sym" is not exported by the $pkg module\n];
138 $oops++;
139 }
140 }
141 }
142 }
143135µs if ($oops) {
144 require Carp;
145 Carp::croak("@{carp}Can't continue after import errors");
146 }
147 }
148 else {
14948112µs @imports = @$exports;
150 }
151
15261193µs my($fail, $fail_cache) = (\@{"${pkg}::EXPORT_FAIL"},
153 $Exporter::FailCache{$pkg} ||= {});
154
1556125µs if (@$fail) {
156 if (!%$fail_cache) {
157 # Build cache of symbols. Optimise the lookup by adding
158 # barewords twice... both with and without a leading &.
159 # (Technique could be applied to $export_cache at cost of memory)
160 my @expanded = map { /^\w/ ? ($_, '&'.$_) : $_ } @$fail;
161 warn "${pkg}::EXPORT_FAIL cached: @expanded" if $Exporter::Verbose;
162 @{$fail_cache}{@expanded} = (1) x @expanded;
163 }
164 my @failed;
165 foreach $sym (@imports) { push(@failed, $sym) if $fail_cache->{$sym} }
166 if (@failed) {
167 @failed = $pkg->export_fail(@failed);
168 foreach $sym (@failed) {
169 require Carp;
170 Carp::carp(qq["$sym" is not implemented by the $pkg module ],
171 "on this architecture");
172 }
173 if (@failed) {
174 require Carp;
175 Carp::croak("Can't continue after import errors");
176 }
177 }
178 }
179
1806115µs warn "Importing into $callpkg from $pkg: ",
181 join(", ",sort @imports) if $Exporter::Verbose;
182
18361649µs foreach $sym (@imports) {
184 # shortcut for the common case of no type character
18516394.15ms1639900µs (*{"${callpkg}::$sym"} = \&{"${pkg}::$sym"}, next)
# spent 900µs making 1639 calls to Exporter::Heavy::CORE:subst, avg 549ns/call
186 unless $sym =~ s/^(\W)//;
187624242µs $type = $1;
1882521µs226µs
# spent 17µs (7+9) within Exporter::Heavy::BEGIN@188 which was called: # once (7µs+9µs) by Exporter::as_heavy at line 188
no warnings 'once';
# spent 17µs making 1 call to Exporter::Heavy::BEGIN@188 # spent 9µs making 1 call to warnings::unimport
189 *{"${callpkg}::$sym"} =
190 $type eq '&' ? \&{"${pkg}::$sym"} :
191 $type eq '$' ? \${"${pkg}::$sym"} :
192 $type eq '@' ? \@{"${pkg}::$sym"} :
193 $type eq '%' ? \%{"${pkg}::$sym"} :
194 $type eq '*' ? *{"${pkg}::$sym"} :
1956241.54ms do { require Carp; Carp::croak("Can't export symbol: $type$sym") };
196 }
197}
198
199sub heavy_export_to_level
200
# spent 740µs (58+682) within Exporter::Heavy::heavy_export_to_level which was called 6 times, avg 123µs/call: # 6 times (58µs+682µs) by JSON::import or XML::LibXML::import at line 81 of Exporter.pm, avg 123µs/call
{
20163µs my $pkg = shift;
20262µs my $level = shift;
20364µs (undef) = shift; # XXX redundant arg
20464µs my $callpkg = caller($level);
205633µs656µs $pkg->export($callpkg, @_);
# spent 56µs making 6 calls to Exporter::export, avg 9µs/call
206}
207
208# Utility functions
209
210
# spent 47µs within Exporter::Heavy::_push_tags which was called 2 times, avg 23µs/call: # once (31µs+0s) by Exporter::Heavy::heavy_export_ok_tags at line 236 # once (16µs+0s) by Exporter::Heavy::heavy_export_tags at line 232
sub _push_tags {
21122µs my($pkg, $var, $syms) = @_;
21221µs my @nontag = ();
21324µs my $export_tags = \%{"${pkg}::EXPORT_TAGS"};
214 push(@{"${pkg}::$var"},
215236µs map { $export_tags->{$_} ? @{$export_tags->{$_}}
216 : scalar(push(@nontag,$_),$_) }
217 (@$syms) ? @$syms : keys %$export_tags);
21829µs if (@nontag and $^W) {
219 # This may change to a die one day
220 require Carp;
221 Carp::carp(join(", ", @nontag)." are not tags of $pkg");
222 }
223}
224
225sub heavy_require_version {
226 my($self, $wanted) = @_;
227 my $pkg = ref $self || $self;
228 return ${pkg}->VERSION($wanted);
229}
230
231
# spent 23µs (6+16) within Exporter::Heavy::heavy_export_tags which was called: # once (6µs+16µs) by parent::import at line 85 of Exporter.pm
sub heavy_export_tags {
23217µs116µs _push_tags((caller)[0], "EXPORT", \@_);
# spent 16µs making 1 call to Exporter::Heavy::_push_tags
233}
234
235
# spent 38µs (7+31) within Exporter::Heavy::heavy_export_ok_tags which was called: # once (7µs+31µs) by DBI::BEGIN@173 at line 89 of Exporter.pm
sub heavy_export_ok_tags {
23616µs131µs _push_tags((caller)[0], "EXPORT_OK", \@_);
# spent 31µs making 1 call to Exporter::Heavy::_push_tags
237}
238
23914µs1;
 
# spent 26µs within Exporter::Heavy::CORE:match which was called 29 times, avg 900ns/call: # 15 times (19µs+0s) by Exporter::Heavy::heavy_export at line 62, avg 1µs/call # 12 times (6µs+0s) by Exporter::Heavy::heavy_export at line 68, avg 517ns/call # 2 times (1µs+0s) by Exporter::Heavy::heavy_export at line 110, avg 550ns/call
sub Exporter::Heavy::CORE:match; # opcode
# spent 931µs within Exporter::Heavy::CORE:subst which was called 1721 times, avg 541ns/call: # 1639 times (900µs+0s) by Exporter::Heavy::heavy_export at line 185, avg 549ns/call # 30 times (3µs+0s) by Exporter::Heavy::_rebuild_cache at line 16, avg 103ns/call # 24 times (1µs+0s) by Exporter::Heavy::_rebuild_cache at line 20, avg 58ns/call # 13 times (20µs+0s) by Exporter::Heavy::heavy_export at line 72, avg 2µs/call # 13 times (4µs+0s) by Exporter::Heavy::heavy_export at line 70, avg 338ns/call # 2 times (2µs+0s) by Exporter::Heavy::heavy_export at line 110, avg 1µs/call
sub Exporter::Heavy::CORE:subst; # opcode
Report produced by the NYTProf 5.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.