← Index
NYTProf Performance Profile   « line view »
For ../prof.pl
  Run on Wed Dec 14 16:10:05 2022
Reported on Wed Dec 14 16:12:58 2022

Filename/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm
StatementsExecuted 2260 statements in 5.87ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
10922845µs1.94msSub::Defer::::_install_coderef Sub::Defer::_install_coderef
3722713µs1.16msSub::Defer::::defer_sub Sub::Defer::defer_sub
6862643µs12.1msSub::Defer::::__ANON__[:178] Sub::Defer::__ANON__[:178]
1011570µs679µsSub::Defer::::undefer_package Sub::Defer::undefer_package
10911394µs862µsSub::Defer::::_name_coderef Sub::Defer::_name_coderef
3822386µs35.4msSub::Defer::::undefer_sub Sub::Defer::undefer_sub
12331259µs259µsSub::Defer::::_getglob Sub::Defer::_getglob
721196µs96µsSub::Defer::::CORE:regcomp Sub::Defer::CORE:regcomp (opcode)
822173µs73µsSub::Defer::::CORE:match Sub::Defer::CORE:match (opcode)
11118µs20µsSub::Defer::::BEGIN@2 Sub::Defer::BEGIN@2
1117µs22µsSub::Defer::::BEGIN@167 Sub::Defer::BEGIN@167
1116µs13µsSub::Defer::::BEGIN@41 Sub::Defer::BEGIN@41
1116µs32µsSub::Defer::::BEGIN@89 Sub::Defer::BEGIN@89
1115µs10µsSub::Defer::::BEGIN@14 Sub::Defer::BEGIN@14
1115µs22µsSub::Defer::::BEGIN@34 Sub::Defer::BEGIN@34
1115µs12µsSub::Defer::::BEGIN@4 Sub::Defer::BEGIN@4
1115µs23µsSub::Defer::::BEGIN@5 Sub::Defer::BEGIN@5
1114µs4µsSub::Defer::::BEGIN@16 Sub::Defer::BEGIN@16
1114µs20µsSub::Defer::::BEGIN@3 Sub::Defer::BEGIN@3
1114µs16µsSub::Defer::::BEGIN@6 Sub::Defer::BEGIN@6
0000s0sJSON::Schema::Modern::Annotation::::newJSON::Schema::Modern::Annotation::new
0000s0sSub::Defer::::CLONE Sub::Defer::CLONE
0000s0sSub::Defer::::__ANON__[:23] Sub::Defer::__ANON__[:23]
0000s0sSub::Defer::::defer_info Sub::Defer::defer_info
0000s0sSub::Defer::::undefer_all Sub::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;
2225µs222µs
# spent 20µs (18+2) within Sub::Defer::BEGIN@2 which was called: # once (18µs+2µs) by Sub::Quote::BEGIN@8 at line 2
use strict;
# spent 20µs making 1 call to Sub::Defer::BEGIN@2 # spent 2µs making 1 call to strict::import
3213µs236µs
# spent 20µs (4+16) within Sub::Defer::BEGIN@3 which was called: # once (4µs+16µs) by Sub::Quote::BEGIN@8 at line 3
use warnings;
# spent 20µs making 1 call to Sub::Defer::BEGIN@3 # spent 16µs making 1 call to warnings::import
4217µs219µs
# spent 12µs (5+7) within Sub::Defer::BEGIN@4 which was called: # once (5µs+7µs) by Sub::Quote::BEGIN@8 at line 4
use Exporter qw(import);
# spent 12µs making 1 call to Sub::Defer::BEGIN@4 # spent 7µs making 1 call to Exporter::import
5213µs241µs
# spent 23µs (5+18) within Sub::Defer::BEGIN@5 which was called: # once (5µs+18µs) by Sub::Quote::BEGIN@8 at line 5
use Scalar::Util qw(weaken);
# spent 23µs making 1 call to Sub::Defer::BEGIN@5 # spent 18µs making 1 call to Exporter::import
6238µs228µs
# spent 16µs (4+12) within Sub::Defer::BEGIN@6 which was called: # once (4µs+12µ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 12µs making 1 call to Exporter::import
7
811µsour $VERSION = '2.006006';
9115µs$VERSION = eval $VERSION;
# spent 4µs executing statements in string eval
10
1111µsour @EXPORT = qw(defer_sub undefer_sub undefer_all);
1210sour @EXPORT_OK = qw(undefer_package defer_info);
13
14125516µs215µs
# spent 259µs within Sub::Defer::_getglob which was called 123 times, avg 2µs/call: # 109 times (232µs+0s) by Sub::Defer::_install_coderef at line 33, avg 2µs/call # 7 times (23µs+0s) by Sub::Defer::undefer_sub at line 88, avg 3µs/call # 7 times (4µs+0s) by Sub::Defer::undefer_sub at line 93, avg 571ns/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 4µs within Sub::Defer::BEGIN@16 which was called: # once (4µ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};
25172µs14µs}
# spent 4µs making 1 call to Sub::Defer::BEGIN@16
26
27
# spent 862µs (394+468) within Sub::Defer::_name_coderef which was called 109 times, avg 8µs/call: # 109 times (394µs+468µs) by Sub::Defer::_install_coderef at line 33, avg 8µs/call
sub _name_coderef {
2810965µs shift if @_ > 2; # three args is (target, name, sub)
29109883µs109468µs _CAN_SUBNAME ? _subname(@_) : $_[1];
# spent 468µs making 109 calls to Sub::Util::set_subname, avg 4µs/call
30}
31
32
# spent 1.94ms (845µs+1.09) within Sub::Defer::_install_coderef which was called 109 times, avg 18µs/call: # 99 times (743µs+874µs) by Sub::Quote::quote_sub at line 223 of Sub/Quote.pm, avg 16µs/call # 10 times (102µs+220µs) by Sub::Defer::defer_sub at line 179, avg 32µs/call
sub _install_coderef {
33109327µs2181.09ms my ($glob, $code) = (_getglob($_[0]), _name_coderef(@_));
# spent 862µs making 109 calls to Sub::Defer::_name_coderef, avg 8µs/call # spent 232µs making 109 calls to Sub::Defer::_getglob, avg 2µs/call
34236µs239µs
# spent 22µs (5+17) within Sub::Defer::BEGIN@34 which was called: # once (5µs+17µs) by Sub::Quote::BEGIN@8 at line 34
no warnings 'redefine';
# spent 22µs making 1 call to Sub::Defer::BEGIN@34 # spent 17µs making 1 call to warnings::unimport
35109346µ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 {
412190µs220µs
# spent 13µs (6+7) within Sub::Defer::BEGIN@41 which was called: # once (6µs+7µs) by Sub::Quote::BEGIN@8 at line 41
no warnings 'prototype';
# spent 13µs making 1 call to Sub::Defer::BEGIN@41 # spent 7µs making 1 call to warnings::unimport
4210953µ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 35.4ms (386µs+35.0) within Sub::Defer::undefer_sub which was called 38 times, avg 932µs/call: # 25 times (52µs+0s) by Moo::_Utils::_install_modifier at line 79 of Moo/_Utils.pm, avg 2µs/call # 13 times (334µs+35.0ms) by 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.72ms/call
sub undefer_sub {
723845µs my ($deferred) = @_;
733867µs my $info = $DEFERRED{$deferred} or return $deferred;
741349µs my ($target, $maker, $options, $undeferred_ref, $deferred_sub) = @$info;
75
761337µ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}
84136µs if ${$undeferred_ref};
851338µs1335.0ms ${$undeferred_ref} = my $made = $maker->();
# spent 31.7ms making 7 calls to Method::Generate::Constructor::__ANON__[Method/Generate/Constructor.pm:101], avg 4.53ms/call # spent 3.25ms making 6 calls to Sub::Quote::__ANON__[Sub/Quote.pm:232], avg 542µs/call
86
87 # make sure the method slot has not changed since deferral time
881329µs723µs if (defined($target) && $deferred eq *{_getglob($target)}{CODE}||'') {
# spent 23µs making 7 calls to Sub::Defer::_getglob, avg 3µs/call
892549µs258µs
# spent 32µs (6+26) within Sub::Defer::BEGIN@89 which was called: # once (6µs+26µs) by Sub::Quote::BEGIN@8 at line 89
no warnings 'redefine';
# spent 32µs making 1 call to Sub::Defer::BEGIN@89 # spent 26µ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
93711µs74µs *{_getglob($target)} = $made;
# spent 4µs making 7 calls to Sub::Defer::_getglob, avg 571ns/call
94 }
951312µs my $undefer_info = [ $target, $maker, $options, $undeferred_ref ];
961330µs $info->[5] = $DEFERRED{$made} = $undefer_info;
971336µs1311µs weaken ${$undefer_info->[3]};
# spent 11µs making 13 calls to Scalar::Util::weaken, avg 846ns/call
98
991350µs return $made;
100}
101
102sub undefer_all {
103 undefer_sub($_) for keys %DEFERRED;
104 return;
105}
106
107
# spent 679µs (570+109) within Sub::Defer::undefer_package which was called 10 times, avg 68µs/call: # 10 times (570µs+109µs) by Moo::Role::_undefer_subs at line 288 of Moo/Role.pm, avg 68µs/call
sub undefer_package {
108106µs my $package = shift;
109 undefer_sub($_)
11010123µs for grep {
111333238µs my $name = $DEFERRED{$_} && $DEFERRED{$_}[0];
112333293µs144109µs $name && $name =~ /^${package}::[^:]+$/
# spent 96µ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;
1141018µ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.16ms (713µs+450µs) within Sub::Defer::defer_sub which was called 37 times, avg 31µs/call: # 27 times (510µs+46µs) by Sub::Quote::quote_sub at line 235 of Sub/Quote.pm, avg 21µs/call # 10 times (203µs+404µs) by Method::Generate::Constructor::install_delayed at line 101 of Method/Generate/Constructor.pm, avg 61µs/call
sub defer_sub {
1363752µs my ($target, $maker, $options) = @_;
1373714µs my $package;
138 my $subname;
1393793µs1060µs ($package, $subname) = $target =~ /^(.*)::([^:]+)$/
# spent 60µ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;
1423730µs $package ||= $options && $options->{package} || caller;
1433740µs my @attributes = @{$options && $options->{attributes} || []};
1443714µs if (@attributes) {
145 /\A\w+(?:\(.*\))?\z/s || croak "invalid attribute $_"
146 for @attributes;
147 }
148379µs my $deferred;
149 my $undeferred;
1503736µs my $deferred_info = [ $target, $maker, $options, \$undeferred ];
1513719µ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 {
1672269µs237µs
# spent 22µs (7+15) within Sub::Defer::BEGIN@167 which was called: # once (7µs+15µs) by Sub::Quote::BEGIN@8 at line 167
no warnings qw(redefine closure);
# spent 22µ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 12.1ms (643µs+11.4) within Sub::Defer::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/Sub/Defer.pm:178] which was called 68 times, avg 178µs/call: # 36 times (345µs+3.92ms) 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 118µs/call # 24 times (180µs+5.12ms) by JSON::Schema::Modern::__ANON__[/Users/ether/.perlbrew/libs/36.0@std/lib/perl5/JSON/Schema/Modern.pm:676] at line 650 of JSON/Schema/Modern.pm, avg 221µs/call # 5 times (72µs+910µ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 196µs/call # once (6µs+578µs) by JSON::Schema::Modern::add_vocabulary at line 711 of JSON/Schema/Modern.pm # once (9µs+526µs) by JSON::Schema::Modern::add_vocabulary at line 706 of JSON/Schema/Modern.pm # once (31µs+393µs) by JSON::Schema::Modern::add_vocabulary at line 712 of JSON/Schema/Modern.pm
$deferred = sub {
1767590µs1335.4ms $undeferred ||= undefer_sub($deferred_info->[4]);
# spent 35.4ms making 13 calls to Sub::Defer::undefer_sub, avg 2.72ms/call
17775433µs75189s goto &$undeferred;
# spent 94.3s making 1 call to OpenAPI::Modern::new # spent 94.3s making 1 call to JSON::Schema::Modern::Document::OpenAPI::new # spent 74.1ms making 1 call to JSON::Schema::Modern::Document::new # spent 6.56ms making 36 calls to Type::Tiny::__ANON__[(eval 432)[Sub/Quote.pm:3]:16], avg 182µs/call # spent 3.82ms making 24 calls to Type::Tiny::__ANON__[(eval 434)[Sub/Quote.pm:3]:16], avg 159µs/call # spent 176µs making 1 call to JSON::Schema::Modern::Result::new # spent 78µs making 1 call to Type::Tiny::__ANON__[(eval 425)[Sub/Quote.pm:3]:16] # spent 71µs making 1 call to JSON::Schema::Modern::new # spent 68µs making 5 calls to Type::Tiny::__ANON__[(eval 427)[Sub/Quote.pm:3]:16], avg 14µs/call # spent 55µs making 1 call to JSON::Schema::Modern::Error::new # spent 26µs making 1 call to Type::Tiny::__ANON__[(eval 423)[Sub/Quote.pm:3]:16] # spent 15µs making 1 call to Method::Generate::Constructor::new # spent 9µs making 1 call to Type::Tiny::__ANON__[(eval 426)[Sub/Quote.pm:3]:16]
1783783µs };
1793752µs10322µs _install_coderef($target, $deferred)
# spent 322µs making 10 calls to Sub::Defer::_install_coderef, avg 32µs/call
180 if $target;
181 }
18237152µs3744µs weaken($deferred_info->[4] = $deferred);
# spent 44µs making 37 calls to Scalar::Util::weaken, avg 1µs/call
18337143µs3724µs weaken($DEFERRED{$deferred} = $deferred_info);
# spent 24µs making 37 calls to Scalar::Util::weaken, avg 649ns/call
1843785µ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
19716µs1;
198__END__
 
# spent 73µs within Sub::Defer::CORE:match which was called 82 times, avg 890ns/call: # 72 times (13µs+0s) by Sub::Defer::undefer_package at line 112, avg 181ns/call # 10 times (60µs+0s) by Sub::Defer::defer_sub at line 139, avg 6µs/call
sub Sub::Defer::CORE:match; # opcode
# spent 96µs within Sub::Defer::CORE:regcomp which was called 72 times, avg 1µs/call: # 72 times (96µ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.