← Index
NYTProf Performance Profile   « line view »
For ../prof.pl
  Run on Wed Dec 14 15:57:08 2022
Reported on Wed Dec 14 16:00:34 2022

Filename/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm
StatementsExecuted 2274 statements in 6.95ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
1011826µs971µsSub::Defer::::undefer_packageSub::Defer::undefer_package
10922816µs2.03msSub::Defer::::_install_coderefSub::Defer::_install_coderef
3722701µs1.03msSub::Defer::::defer_subSub::Defer::defer_sub
6862598µs11.3msSub::Defer::::__ANON__[:178]Sub::Defer::__ANON__[:178]
10911443µs933µsSub::Defer::::_name_coderefSub::Defer::_name_coderef
3822426µs42.2msSub::Defer::::undefer_subSub::Defer::undefer_sub
12531329µs329µsSub::Defer::::_getglobSub::Defer::_getglob
7211137µs137µsSub::Defer::::CORE:regcompSub::Defer::CORE:regcomp (opcode)
822156µs56µsSub::Defer::::CORE:matchSub::Defer::CORE:match (opcode)
11132µs35µsSub::Defer::::BEGIN@2Sub::Defer::BEGIN@2
11125µs91µsSub::Defer::::BEGIN@167Sub::Defer::BEGIN@167
11110µs19µsSub::Defer::::BEGIN@4Sub::Defer::BEGIN@4
1118µs45µsSub::Defer::::BEGIN@3Sub::Defer::BEGIN@3
1118µs39µsSub::Defer::::BEGIN@5Sub::Defer::BEGIN@5
1117µs19µsSub::Defer::::BEGIN@14Sub::Defer::BEGIN@14
1117µs23µsSub::Defer::::BEGIN@6Sub::Defer::BEGIN@6
1116µs16µsSub::Defer::::BEGIN@41Sub::Defer::BEGIN@41
1116µs20µsSub::Defer::::BEGIN@89Sub::Defer::BEGIN@89
1115µs28µsSub::Defer::::BEGIN@34Sub::Defer::BEGIN@34
1113µs3µsSub::Defer::::BEGIN@16Sub::Defer::BEGIN@16
0000s0sSub::Defer::::CLONESub::Defer::CLONE
0000s0sSub::Defer::::__ANON__[:23]Sub::Defer::__ANON__[:23]
0000s0sSub::Defer::::defer_infoSub::Defer::defer_info
0000s0sSub::Defer::::undefer_allSub::Defer::undefer_all
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Sub::Defer;
2235µs238µs
# spent 35µs (32+3) within Sub::Defer::BEGIN@2 which was called: # once (32µs+3µs) by Sub::Quote::BEGIN@8 at line 2
use strict;
# spent 35µs making 1 call to Sub::Defer::BEGIN@2 # spent 3µs making 1 call to strict::import
3229µs282µs
# spent 45µs (8+37) within Sub::Defer::BEGIN@3 which was called: # once (8µs+37µs) by Sub::Quote::BEGIN@8 at line 3
use warnings;
# spent 45µs making 1 call to Sub::Defer::BEGIN@3 # spent 37µs making 1 call to warnings::import
4229µs228µs
# spent 19µs (10+9) within Sub::Defer::BEGIN@4 which was called: # once (10µs+9µs) by Sub::Quote::BEGIN@8 at line 4
use Exporter qw(import);
# spent 19µs making 1 call to Sub::Defer::BEGIN@4 # spent 9µs making 1 call to Exporter::import
5223µs270µs
# spent 39µs (8+31) within Sub::Defer::BEGIN@5 which was called: # once (8µs+31µs) by Sub::Quote::BEGIN@8 at line 5
use Scalar::Util qw(weaken);
# spent 39µs making 1 call to Sub::Defer::BEGIN@5 # spent 31µs making 1 call to Exporter::import
6284µs239µs
# spent 23µs (7+16) within Sub::Defer::BEGIN@6 which was called: # once (7µs+16µs) by Sub::Quote::BEGIN@8 at line 6
use Carp qw(croak);
# spent 23µs making 1 call to Sub::Defer::BEGIN@6 # spent 16µs making 1 call to Exporter::import
7
811µsour $VERSION = '2.006006';
9118µs$VERSION = eval $VERSION;
# spent 4µs executing statements in string eval
10
1112µsour @EXPORT = qw(defer_sub undefer_sub undefer_all);
1210sour @EXPORT_OK = qw(undefer_package defer_info);
13
14127607µs231µs
# spent 329µs within Sub::Defer::_getglob which was called 125 times, avg 3µs/call: # 109 times (282µs+0s) by Sub::Defer::_install_coderef at line 33, avg 3µs/call # 8 times (40µs+0s) by Sub::Defer::undefer_sub at line 88, avg 5µs/call # 8 times (7µs+0s) by Sub::Defer::undefer_sub at line 93, avg 875ns/call # spent 19µs (7+12) within Sub::Defer::BEGIN@14 which was called: # once (7µs+12µs) by Sub::Quote::BEGIN@8 at line 14
sub _getglob { no strict 'refs'; \*{$_[0]} }
# spent 19µs making 1 call to Sub::Defer::BEGIN@14 # spent 12µs making 1 call to strict::unimport
15
16
# spent 3µs within Sub::Defer::BEGIN@16 which was called: # once (3µs+0s) by Sub::Quote::BEGIN@8 at line 25
BEGIN {
1710s my $no_subname;
18 *_subname
19 = defined &Sub::Util::set_subname ? \&Sub::Util::set_subname
20 : defined &Sub::Name::subname ? \&Sub::Name::subname
21 : (eval { require Sub::Util } && defined &Sub::Util::set_subname) ? \&Sub::Util::set_subname
22 : (eval { require Sub::Name } && defined &Sub::Name::subname ) ? \&Sub::Name::subname
2311µs : ($no_subname = 1, sub { $_[1] });
2414µs *_CAN_SUBNAME = $no_subname ? sub(){0} : sub(){1};
25181µs13µs}
# spent 3µs making 1 call to Sub::Defer::BEGIN@16
26
27
# spent 933µs (443+490) within Sub::Defer::_name_coderef which was called 109 times, avg 9µs/call: # 109 times (443µs+490µs) by Sub::Defer::_install_coderef at line 33, avg 9µs/call
sub _name_coderef {
2810939µs shift if @_ > 2; # three args is (target, name, sub)
29109953µs109490µs _CAN_SUBNAME ? _subname(@_) : $_[1];
# spent 490µs making 109 calls to Sub::Util::set_subname, avg 4µs/call
30}
31
32
# spent 2.03ms (816µs+1.22) within Sub::Defer::_install_coderef which was called 109 times, avg 19µs/call: # 99 times (740µs+1.09ms) by Sub::Quote::quote_sub at line 223 of Sub/Quote.pm, avg 18µs/call # 10 times (76µs+128µs) by Sub::Defer::defer_sub at line 179, avg 20µs/call
sub _install_coderef {
33109324µs2181.21ms my ($glob, $code) = (_getglob($_[0]), _name_coderef(@_));
# spent 933µs making 109 calls to Sub::Defer::_name_coderef, avg 9µs/call # spent 282µs making 109 calls to Sub::Defer::_getglob, avg 3µs/call
34241µs251µs
# spent 28µs (5+23) within Sub::Defer::BEGIN@34 which was called: # once (5µs+23µs) by Sub::Quote::BEGIN@8 at line 34
no warnings 'redefine';
# spent 28µs making 1 call to Sub::Defer::BEGIN@34 # spent 23µs making 1 call to warnings::unimport
35109342µs if (*{$glob}{CODE}) {
36 *{$glob} = $code;
37 }
38 # perl will sometimes warn about mismatched prototypes coming from the
39 # inheritance cache, so disable them if we aren't redefining a sub
40 else {
412157µs226µs
# spent 16µs (6+10) within Sub::Defer::BEGIN@41 which was called: # once (6µs+10µs) by Sub::Quote::BEGIN@8 at line 41
no warnings 'prototype';
# spent 16µs making 1 call to Sub::Defer::BEGIN@41 # spent 10µs making 1 call to warnings::unimport
4210973µs *{$glob} = $code;
43 }
44}
45
46# We are dealing with three subs. The first is the generator sub. It is
47# provided by the user, so we cannot modify it. When called, it generates the
48# undeferred sub. This is also created, so it also cannot be modified. These
49# are wrapped in a third sub. The deferred sub is generated by us, and when
50# called it uses the generator sub to create the undeferred sub. If it is a
51# named sub, it is installed in the symbol table, usually overwriting the
52# deferred sub. From then on, the deferred sub will goto the undeferred sub
53# if it is called.
54#
55# In %DEFERRED we store array refs with information about these subs. The key
56# is the stringified subref. We have a CLONE method to fix this up in the
57# case of threading to deal with changing refaddrs. The arrayrefs contain:
58#
59# 0. fully qualified sub name (or undef)
60# 1. generator sub
61# 2. options (attributes)
62# 3. scalar ref to undeferred sub (inner reference weakened)
63# 4. deferred sub (deferred only)
64# 5. info arrayref for undeferred sub (deferred only, after undefer)
65#
66# The deferred sub contains a strong reference to its info arrayref, and the
67# undeferred.
68
69our %DEFERRED;
70
71
# spent 42.2ms (426µs+41.8) within Sub::Defer::undefer_sub which was called 38 times, avg 1.11ms/call: # 24 times (106µs+0s) by Moo::_Utils::_install_modifier at line 79 of Moo/_Utils.pm, avg 4µs/call # 14 times (320µs+41.8ms) by JSON::Schema::Modern::Annotation::new or JSON::Schema::Modern::Document::OpenAPI::new or JSON::Schema::Modern::Document::new or JSON::Schema::Modern::Error::new or JSON::Schema::Modern::Result::new or JSON::Schema::Modern::new or Method::Generate::Constructor::new or OpenAPI::Modern::new or Sub::Defer::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm:178] at line 176, avg 3.01ms/call
sub undefer_sub {
723816µs my ($deferred) = @_;
7338140µs my $info = $DEFERRED{$deferred} or return $deferred;
741416µs my ($target, $maker, $options, $undeferred_ref, $deferred_sub) = @$info;
75
761412µs if (!(
77 $deferred_sub && $deferred eq $deferred_sub
78 || ${$undeferred_ref} && $deferred eq ${$undeferred_ref}
79 )) {
80 return $deferred;
81 }
82
83 return ${$undeferred_ref}
84146µs if ${$undeferred_ref};
851437µs1441.8ms ${$undeferred_ref} = my $made = $maker->();
# spent 38.8ms making 8 calls to Method::Generate::Constructor::__ANON__[Method/Generate/Constructor.pm:101], avg 4.85ms/call # spent 2.92ms making 6 calls to Sub::Quote::__ANON__[Sub/Quote.pm:232], avg 487µs/call
86
87 # make sure the method slot has not changed since deferral time
881446µs840µs if (defined($target) && $deferred eq *{_getglob($target)}{CODE}||'') {
# spent 40µs making 8 calls to Sub::Defer::_getglob, avg 5µs/call
892892µs234µs
# spent 20µs (6+14) within Sub::Defer::BEGIN@89 which was called: # once (6µs+14µs) by Sub::Quote::BEGIN@8 at line 89
no warnings 'redefine';
# spent 20µs making 1 call to Sub::Defer::BEGIN@89 # spent 14µs making 1 call to warnings::unimport
90
91 # I believe $maker already evals with the right package/name, so that
92 # _install_coderef calls are not necessary --ribasushi
93820µs87µs *{_getglob($target)} = $made;
# spent 7µs making 8 calls to Sub::Defer::_getglob, avg 875ns/call
94 }
951415µs my $undefer_info = [ $target, $maker, $options, $undeferred_ref ];
961427µs $info->[5] = $DEFERRED{$made} = $undefer_info;
971442µs1415µs weaken ${$undefer_info->[3]};
# spent 15µs making 14 calls to Scalar::Util::weaken, avg 1µs/call
98
991458µs return $made;
100}
101
102sub undefer_all {
103 undefer_sub($_) for keys %DEFERRED;
104 return;
105}
106
107
# spent 971µs (826+145) within Sub::Defer::undefer_package which was called 10 times, avg 97µs/call: # 10 times (826µs+145µs) by Moo::Role::_undefer_subs at line 288 of Moo/Role.pm, avg 97µs/call
sub undefer_package {
108102µs my $package = shift;
109 undefer_sub($_)
11010189µs for grep {
111333367µs my $name = $DEFERRED{$_} && $DEFERRED{$_}[0];
112333394µs144145µs $name && $name =~ /^${package}::[^:]+$/
# spent 137µs making 72 calls to Sub::Defer::CORE:regcomp, avg 2µs/call # spent 8µs making 72 calls to Sub::Defer::CORE:match, avg 111ns/call
113 } keys %DEFERRED;
1141020µs return;
115}
116
117sub defer_info {
118 my ($deferred) = @_;
119 my $info = $DEFERRED{$deferred||''} or return undef;
120
121 my ($target, $maker, $options, $undeferred_ref, $deferred_sub) = @$info;
122 if (!(
123 $deferred_sub && $deferred eq $deferred_sub
124 || ${$undeferred_ref} && $deferred eq ${$undeferred_ref}
125 )) {
126 delete $DEFERRED{$deferred};
127 return undef;
128 }
129 [
130 $target, $maker, $options,
131 ( $undeferred_ref && $$undeferred_ref ? $$undeferred_ref : ()),
132 ];
133}
134
135
# spent 1.03ms (701µs+332µs) within Sub::Defer::defer_sub which was called 37 times, avg 28µs/call: # 27 times (502µs+37µs) by Sub::Quote::quote_sub at line 235 of Sub/Quote.pm, avg 20µs/call # 10 times (199µs+295µs) by Method::Generate::Constructor::install_delayed at line 101 of Method/Generate/Constructor.pm, avg 49µs/call
sub defer_sub {
1363723µs my ($target, $maker, $options) = @_;
1373710µs my $package;
138 my $subname;
1393786µs1048µs ($package, $subname) = $target =~ /^(.*)::([^:]+)$/
# spent 48µs making 10 calls to Sub::Defer::CORE:match, avg 5µs/call
140 or croak "$target is not a fully qualified sub name!"
141 if $target;
1423726µs $package ||= $options && $options->{package} || caller;
1433748µs my @attributes = @{$options && $options->{attributes} || []};
1443715µs if (@attributes) {
145 /\A\w+(?:\(.*\))?\z/s || croak "invalid attribute $_"
146 for @attributes;
147 }
148373µs my $deferred;
149 my $undeferred;
1503761µs my $deferred_info = [ $target, $maker, $options, \$undeferred ];
1513728µs if (@attributes || $target && !_CAN_SUBNAME) {
152 my $code
153 = q[#line ].(__LINE__+2).q[ "].__FILE__.qq["\n]
154 . qq[package $package;\n]
155 . ($target ? "sub $subname" : '+sub') . join('', map " :$_", @attributes)
156 . q[ {
157 package Sub::Defer;
158 # uncoverable subroutine
159 # uncoverable statement
160 $undeferred ||= undefer_sub($deferred_info->[4]);
161 goto &$undeferred; # uncoverable statement
162 $undeferred; # fake lvalue return
163 }]."\n"
164 . ($target ? "\\&$subname" : '');
165 my $e;
166 $deferred = do {
1672399µs2157µs
# spent 91µs (25+66) within Sub::Defer::BEGIN@167 which was called: # once (25µs+66µs) by Sub::Quote::BEGIN@8 at line 167
no warnings qw(redefine closure);
# spent 91µs making 1 call to Sub::Defer::BEGIN@167 # spent 66µs making 1 call to warnings::unimport
168 local $@;
169 eval $code or $e = $@; # uncoverable branch true
170 };
171 die $e if defined $e; # uncoverable branch true
172 }
173 else {
174 # duplicated from above
175
# spent 11.3ms (598µs+10.7) within Sub::Defer::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm:178] which was called 68 times, avg 167µs/call: # 36 times (372µs+4.56ms) by JSON::Schema::Modern::Document::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/JSON/Schema/Modern/Document.pm:135] at line 120 of JSON/Schema/Modern/Document.pm, avg 137µs/call # 24 times (139µs+4.17ms) by JSON::Schema::Modern::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/JSON/Schema/Modern.pm:672] at line 646 of JSON/Schema/Modern.pm, avg 179µs/call # 5 times (43µs+625µs) by JSON::Schema::Modern::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/JSON/Schema/Modern.pm:124] at line 124 of JSON/Schema/Modern.pm, avg 134µs/call # once (11µs+606µs) by JSON::Schema::Modern::add_vocabulary at line 702 of JSON/Schema/Modern.pm # once (7µs+515µs) by JSON::Schema::Modern::add_vocabulary at line 707 of JSON/Schema/Modern.pm # once (26µs+274µs) by JSON::Schema::Modern::add_vocabulary at line 708 of JSON/Schema/Modern.pm
$deferred = sub {
1767660µs1442.1ms $undeferred ||= undefer_sub($deferred_info->[4]);
# spent 42.1ms making 14 calls to Sub::Defer::undefer_sub, avg 3.01ms/call
17776516µs76216s goto &$undeferred;
# spent 108s making 1 call to OpenAPI::Modern::new # spent 108s making 1 call to JSON::Schema::Modern::Document::OpenAPI::new # spent 15.1ms making 1 call to JSON::Schema::Modern::Document::new # spent 7.20ms making 36 calls to Type::Tiny::__ANON__[(eval 428)[Sub/Quote.pm:3]:16], avg 200µs/call # spent 3.58ms making 24 calls to Type::Tiny::__ANON__[(eval 430)[Sub/Quote.pm:3]:16], avg 149µs/call # spent 131µs making 1 call to JSON::Schema::Modern::Annotation::new # spent 110µs making 1 call to JSON::Schema::Modern::Result::new # spent 94µs making 1 call to Type::Tiny::__ANON__[(eval 419)[Sub/Quote.pm:3]:16] # spent 85µs making 1 call to Type::Tiny::__ANON__[(eval 421)[Sub/Quote.pm:3]:16] # spent 82µs making 1 call to JSON::Schema::Modern::new # spent 56µs making 1 call to JSON::Schema::Modern::Error::new # spent 39µs making 5 calls to Type::Tiny::__ANON__[(eval 423)[Sub/Quote.pm:3]:16], avg 8µs/call # spent 5µs making 1 call to Method::Generate::Constructor::new # spent 5µs making 1 call to Type::Tiny::__ANON__[(eval 422)[Sub/Quote.pm:3]:16]
1783791µs };
1793725µs10204µs _install_coderef($target, $deferred)
# spent 204µs making 10 calls to Sub::Defer::_install_coderef, avg 20µs/call
180 if $target;
181 }
18237185µs3765µs weaken($deferred_info->[4] = $deferred);
# spent 65µs making 37 calls to Scalar::Util::weaken, avg 2µs/call
18337133µs3715µs weaken($DEFERRED{$deferred} = $deferred_info);
# spent 15µs making 37 calls to Scalar::Util::weaken, avg 405ns/call
1843789µs return $deferred;
185}
186
187sub CLONE {
188 %DEFERRED = map {
189 defined $_ ? (
190 $_->[4] ? ($_->[4] => $_)
191 : ($_->[3] && ${$_->[3]}) ? (${$_->[3]} => $_)
192 : ()
193 ) : ()
194 } values %DEFERRED;
195}
196
19715µs1;
198__END__
 
# spent 56µs within Sub::Defer::CORE:match which was called 82 times, avg 683ns/call: # 72 times (8µs+0s) by Sub::Defer::undefer_package at line 112, avg 111ns/call # 10 times (48µs+0s) by Sub::Defer::defer_sub at line 139, avg 5µs/call
sub Sub::Defer::CORE:match; # opcode
# spent 137µs within Sub::Defer::CORE:regcomp which was called 72 times, avg 2µs/call: # 72 times (137µs+0s) by Sub::Defer::undefer_package at line 112, avg 2µs/call
sub Sub::Defer::CORE:regcomp; # opcode
Report produced by the NYTProf 6.12 Perl profiler, developed by Tim Bunce based on work by Adam Kaplan and Salvador Fandiño García.