← Index
NYTProf Performance Profile   « line view »
For ../prof.pl
  Run on Wed Dec 14 15:33:55 2022
Reported on Wed Dec 14 15:40:03 2022

Filename/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm
StatementsExecuted 2274 statements in 7.32ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
10922975µs1.99msSub::Defer::::_install_coderefSub::Defer::_install_coderef
3822785µs37.5msSub::Defer::::undefer_subSub::Defer::undefer_sub
1011689µs804µsSub::Defer::::undefer_packageSub::Defer::undefer_package
3722667µs974µsSub::Defer::::defer_subSub::Defer::defer_sub
6862596µs8.39msSub::Defer::::__ANON__[:178]Sub::Defer::__ANON__[:178]
10911339µs792µsSub::Defer::::_name_coderefSub::Defer::_name_coderef
12531256µs256µsSub::Defer::::_getglobSub::Defer::_getglob
7211102µs102µsSub::Defer::::CORE:regcompSub::Defer::CORE:regcomp (opcode)
11192µs135µsSub::Defer::::BEGIN@41Sub::Defer::BEGIN@41
822169µs69µsSub::Defer::::CORE:matchSub::Defer::CORE:match (opcode)
11128µs43µsSub::Defer::::BEGIN@167Sub::Defer::BEGIN@167
11122µs24µsSub::Defer::::BEGIN@2Sub::Defer::BEGIN@2
1116µs6µsSub::Defer::::BEGIN@16Sub::Defer::BEGIN@16
1116µs32µsSub::Defer::::BEGIN@3Sub::Defer::BEGIN@3
1116µs11µsSub::Defer::::BEGIN@4Sub::Defer::BEGIN@4
1116µs23µsSub::Defer::::BEGIN@89Sub::Defer::BEGIN@89
1115µs10µsSub::Defer::::BEGIN@14Sub::Defer::BEGIN@14
1115µs26µsSub::Defer::::BEGIN@5Sub::Defer::BEGIN@5
1115µs16µsSub::Defer::::BEGIN@6Sub::Defer::BEGIN@6
1114µs17µsSub::Defer::::BEGIN@34Sub::Defer::BEGIN@34
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;
2227µs226µs
# spent 24µs (22+2) within Sub::Defer::BEGIN@2 which was called: # once (22µs+2µs) by Sub::Quote::BEGIN@8 at line 2
use strict;
# spent 24µs making 1 call to Sub::Defer::BEGIN@2 # spent 2µs making 1 call to strict::import
3221µs258µs
# spent 32µs (6+26) within Sub::Defer::BEGIN@3 which was called: # once (6µs+26µs) by Sub::Quote::BEGIN@8 at line 3
use warnings;
# spent 32µs making 1 call to Sub::Defer::BEGIN@3 # spent 26µs making 1 call to warnings::import
4215µs216µs
# spent 11µs (6+5) within Sub::Defer::BEGIN@4 which was called: # once (6µs+5µs) by Sub::Quote::BEGIN@8 at line 4
use Exporter qw(import);
# spent 11µs making 1 call to Sub::Defer::BEGIN@4 # spent 5µs making 1 call to Exporter::import
5214µs247µs
# spent 26µs (5+21) within Sub::Defer::BEGIN@5 which was called: # once (5µs+21µs) by Sub::Quote::BEGIN@8 at line 5
use Scalar::Util qw(weaken);
# spent 26µs making 1 call to Sub::Defer::BEGIN@5 # spent 21µs making 1 call to Exporter::import
6242µs227µs
# spent 16µs (5+11) within Sub::Defer::BEGIN@6 which was called: # once (5µs+11µs) by Sub::Quote::BEGIN@8 at line 6
use Carp qw(croak);
# spent 16µs making 1 call to Sub::Defer::BEGIN@6 # spent 11µs making 1 call to Exporter::import
7
811µsour $VERSION = '2.006006';
9115µs$VERSION = eval $VERSION;
# spent 3µs executing statements in string eval
10
1111µsour @EXPORT = qw(defer_sub undefer_sub undefer_all);
1211µsour @EXPORT_OK = qw(undefer_package defer_info);
13
14127446µs215µs
# spent 256µs within Sub::Defer::_getglob which was called 125 times, avg 2µs/call: # 109 times (221µs+0s) by Sub::Defer::_install_coderef at line 33, avg 2µs/call # 8 times (28µs+0s) by Sub::Defer::undefer_sub at line 88, avg 4µs/call # 8 times (7µs+0s) by Sub::Defer::undefer_sub at line 93, avg 875ns/call # spent 10µs (5+5) within Sub::Defer::BEGIN@14 which was called: # once (5µs+5µs) by Sub::Quote::BEGIN@8 at line 14
sub _getglob { no strict 'refs'; \*{$_[0]} }
# spent 10µs making 1 call to Sub::Defer::BEGIN@14 # spent 5µs making 1 call to strict::unimport
15
16
# spent 6µs within Sub::Defer::BEGIN@16 which was called: # once (6µ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};
25163µs16µs}
# spent 6µs making 1 call to Sub::Defer::BEGIN@16
26
27
# spent 792µs (339+453) within Sub::Defer::_name_coderef which was called 109 times, avg 7µs/call: # 109 times (339µs+453µs) by Sub::Defer::_install_coderef at line 33, avg 7µs/call
sub _name_coderef {
2810935µs shift if @_ > 2; # three args is (target, name, sub)
29109996µs109453µs _CAN_SUBNAME ? _subname(@_) : $_[1];
# spent 453µs making 109 calls to Sub::Util::set_subname, avg 4µs/call
30}
31
32
# spent 1.99ms (975µs+1.01) within Sub::Defer::_install_coderef which was called 109 times, avg 18µs/call: # 99 times (901µs+889µs) by Sub::Quote::quote_sub at line 223 of Sub/Quote.pm, avg 18µs/call # 10 times (74µs+124µs) by Sub::Defer::defer_sub at line 179, avg 20µs/call
sub _install_coderef {
33109296µs2181.01ms my ($glob, $code) = (_getglob($_[0]), _name_coderef(@_));
# spent 792µs making 109 calls to Sub::Defer::_name_coderef, avg 7µs/call # spent 221µs making 109 calls to Sub::Defer::_getglob, avg 2µs/call
342108µs230µs
# spent 17µs (4+13) within Sub::Defer::BEGIN@34 which was called: # once (4µs+13µs) by Sub::Quote::BEGIN@8 at line 34
no warnings 'redefine';
# spent 17µs making 1 call to Sub::Defer::BEGIN@34 # spent 13µs making 1 call to warnings::unimport
35109381µ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 {
412234µs2178µs
# spent 135µs (92+43) within Sub::Defer::BEGIN@41 which was called: # once (92µs+43µs) by Sub::Quote::BEGIN@8 at line 41
no warnings 'prototype';
# spent 135µs making 1 call to Sub::Defer::BEGIN@41 # spent 43µs making 1 call to warnings::unimport
42109105µ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 37.5ms (785µs+36.7) within Sub::Defer::undefer_sub which was called 38 times, avg 986µs/call: # 24 times (50µs+0s) by Moo::_Utils::_install_modifier at line 79 of Moo/_Utils.pm, avg 2µs/call # 14 times (735µs+36.7ms) 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 2.67ms/call
sub undefer_sub {
723813µs my ($deferred) = @_;
7338135µs my $info = $DEFERRED{$deferred} or return $deferred;
7414119µs my ($target, $maker, $options, $undeferred_ref, $deferred_sub) = @$info;
75
761480µ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}
84142µs if ${$undeferred_ref};
851462µs1436.6ms ${$undeferred_ref} = my $made = $maker->();
# spent 33.7ms making 8 calls to Method::Generate::Constructor::__ANON__[Method/Generate/Constructor.pm:101], avg 4.22ms/call # spent 2.92ms making 6 calls to Sub::Quote::__ANON__[Sub/Quote.pm:232], avg 486µs/call
86
87 # make sure the method slot has not changed since deferral time
881445µs828µs if (defined($target) && $deferred eq *{_getglob($target)}{CODE}||'') {
# spent 28µs making 8 calls to Sub::Defer::_getglob, avg 4µs/call
8921.26ms240µs
# spent 23µs (6+17) within Sub::Defer::BEGIN@89 which was called: # once (6µs+17µs) by Sub::Quote::BEGIN@8 at line 89
no warnings 'redefine';
# spent 23µs making 1 call to Sub::Defer::BEGIN@89 # spent 17µ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
93817µs87µs *{_getglob($target)} = $made;
# spent 7µs making 8 calls to Sub::Defer::_getglob, avg 875ns/call
94 }
951476µs my $undefer_info = [ $target, $maker, $options, $undeferred_ref ];
961428µs $info->[5] = $DEFERRED{$made} = $undefer_info;
971438µs148µs weaken ${$undefer_info->[3]};
# spent 8µs making 14 calls to Scalar::Util::weaken, avg 571ns/call
98
991460µs return $made;
100}
101
102sub undefer_all {
103 undefer_sub($_) for keys %DEFERRED;
104 return;
105}
106
107
# spent 804µs (689+115) within Sub::Defer::undefer_package which was called 10 times, avg 80µs/call: # 10 times (689µs+115µs) by Moo::Role::_undefer_subs at line 288 of Moo/Role.pm, avg 80µs/call
sub undefer_package {
108103µs my $package = shift;
109 undefer_sub($_)
11010153µs for grep {
111333233µs my $name = $DEFERRED{$_} && $DEFERRED{$_}[0];
112333406µs144115µs $name && $name =~ /^${package}::[^:]+$/
# spent 102µs making 72 calls to Sub::Defer::CORE:regcomp, avg 1µs/call # spent 13µs making 72 calls to Sub::Defer::CORE:match, avg 181ns/call
113 } keys %DEFERRED;
1141017µ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 974µs (667+307) within Sub::Defer::defer_sub which was called 37 times, avg 26µs/call: # 27 times (431µs+34µs) by Sub::Quote::quote_sub at line 235 of Sub/Quote.pm, avg 17µs/call # 10 times (236µs+273µs) by Method::Generate::Constructor::install_delayed at line 101 of Method/Generate/Constructor.pm, avg 51µs/call
sub defer_sub {
1363724µs my ($target, $maker, $options) = @_;
1373717µs my $package;
138 my $subname;
1393799µs1056µs ($package, $subname) = $target =~ /^(.*)::([^:]+)$/
# spent 56µs making 10 calls to Sub::Defer::CORE:match, avg 6µs/call
140 or croak "$target is not a fully qualified sub name!"
141 if $target;
1423725µs $package ||= $options && $options->{package} || caller;
1433738µs my @attributes = @{$options && $options->{attributes} || []};
1443717µs if (@attributes) {
145 /\A\w+(?:\(.*\))?\z/s || croak "invalid attribute $_"
146 for @attributes;
147 }
148373µs my $deferred;
149 my $undeferred;
1503760µs my $deferred_info = [ $target, $maker, $options, \$undeferred ];
1513733µ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 {
1672330µs258µs
# spent 43µs (28+15) within Sub::Defer::BEGIN@167 which was called: # once (28µs+15µs) by Sub::Quote::BEGIN@8 at line 167
no warnings qw(redefine closure);
# spent 43µs making 1 call to Sub::Defer::BEGIN@167 # spent 15µ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 8.39ms (596µs+7.80) within Sub::Defer::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm:178] which was called 68 times, avg 123µs/call: # 36 times (241µs+2.42ms) 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 74µs/call # 24 times (152µs+2.74ms) by JSON::Schema::Modern::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/JSON/Schema/Modern.pm:646] at line 620 of JSON/Schema/Modern.pm, avg 121µs/call # 5 times (100µs+836µ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 187µs/call # once (7µs+744µs) by JSON::Schema::Modern::add_vocabulary at line 681 of JSON/Schema/Modern.pm # once (15µs+645µs) by JSON::Schema::Modern::add_vocabulary at line 676 of JSON/Schema/Modern.pm # once (81µs+405µs) by JSON::Schema::Modern::add_vocabulary at line 682 of JSON/Schema/Modern.pm
$deferred = sub {
17676220µs1437.4ms $undeferred ||= undefer_sub($deferred_info->[4]);
# spent 37.4ms making 14 calls to Sub::Defer::undefer_sub, avg 2.67ms/call
17776447µs76208s goto &$undeferred;
# spent 104s making 1 call to OpenAPI::Modern::new # spent 104s making 1 call to JSON::Schema::Modern::Document::OpenAPI::new # spent 8.69ms making 1 call to JSON::Schema::Modern::Document::new # spent 5.92ms making 36 calls to Type::Tiny::__ANON__[(eval 428)[Sub/Quote.pm:3]:16], avg 165µs/call # spent 3.15ms making 24 calls to Type::Tiny::__ANON__[(eval 430)[Sub/Quote.pm:3]:16], avg 131µs/call # spent 191µs making 1 call to JSON::Schema::Modern::Result::new # spent 82µs making 1 call to Type::Tiny::__ANON__[(eval 421)[Sub/Quote.pm:3]:16] # spent 73µs making 5 calls to Type::Tiny::__ANON__[(eval 423)[Sub/Quote.pm:3]:16], avg 15µs/call # spent 64µs making 1 call to JSON::Schema::Modern::new # spent 63µs making 1 call to Type::Tiny::__ANON__[(eval 419)[Sub/Quote.pm:3]:16] # spent 57µs making 1 call to JSON::Schema::Modern::Error::new # spent 50µs making 1 call to JSON::Schema::Modern::Annotation::new # spent 34µs making 1 call to Type::Tiny::__ANON__[(eval 422)[Sub/Quote.pm:3]:16] # spent 10µs making 1 call to Method::Generate::Constructor::new
1783767µs };
1793734µs10198µs _install_coderef($target, $deferred)
# spent 198µs making 10 calls to Sub::Defer::_install_coderef, avg 20µs/call
180 if $target;
181 }
18237128µs3731µs weaken($deferred_info->[4] = $deferred);
# spent 31µs making 37 calls to Scalar::Util::weaken, avg 838ns/call
18337125µs3722µs weaken($DEFERRED{$deferred} = $deferred_info);
# spent 22µs making 37 calls to Scalar::Util::weaken, avg 595ns/call
18437101µ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 69µs within Sub::Defer::CORE:match which was called 82 times, avg 841ns/call: # 72 times (13µs+0s) by Sub::Defer::undefer_package at line 112, avg 181ns/call # 10 times (56µs+0s) by Sub::Defer::defer_sub at line 139, avg 6µs/call
sub Sub::Defer::CORE:match; # opcode
# spent 102µs within Sub::Defer::CORE:regcomp which was called 72 times, avg 1µs/call: # 72 times (102µs+0s) by Sub::Defer::undefer_package at line 112, avg 1µ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.