Profile of Sub/Quote.pm

Filename	/usr/share/perl5/Sub/Quote.pm
Statements	Executed 9859 statements in 24.8ms

Subroutines
Calls	P	F	Exclusive Time	Inclusive Time	Subroutine
539	13	6	13.9ms	34.7ms	Sub::Quote::::quote_subSub::Quote::quote_sub
14	1	1	4.81ms	5.31ms	Sub::Quote::::_clean_evalSub::Quote::_clean_eval
1	1	1	4.13ms	5.51ms	Sub::Quote::::BEGIN@10Sub::Quote::BEGIN@10
1172	13	3	2.78ms	4.04ms	Sub::Quote::::quotifySub::Quote::quotify
1	1	1	1.22ms	7.86ms	Sub::Quote::::BEGIN@7Sub::Quote::BEGIN@7
1	1	1	690µs	863µs	Sub::Quote::::BEGIN@3Sub::Quote::BEGIN@3
14	2	2	609µs	6.44ms	Sub::Quote::::unquote_subSub::Quote::unquote_sub
14	1	1	314µs	497µs	Sub::Quote::::capture_unrollSub::Quote::capture_unroll
1	1	1	77µs	156µs	Sub::Quote::::BEGIN@8Sub::Quote::BEGIN@8
1	1	1	76µs	92µs	Sub::Quote::::BEGIN@9Sub::Quote::BEGIN@9
12	1	1	57µs	5.18ms	Sub::Quote::::__ANON__[:100]Sub::Quote::__ANON__[:100]
32	1	1	49µs	49µs	Sub::Quote::::CORE:matchSub::Quote::CORE:match (opcode)
4	1	1	49µs	72µs	Sub::Quote::::inlinifySub::Quote::inlinify
1	1	1	34µs	58µs	Sub::Quote::::BEGIN@152Sub::Quote::BEGIN@152
4	1	1	29µs	29µs	Sub::Quote::::quoted_from_subSub::Quote::quoted_from_sub
8	2	1	24µs	24µs	Sub::Quote::::CORE:substSub::Quote::CORE:subst (opcode)
1	1	1	13µs	13µs	Sub::Quote::::BEGIN@11Sub::Quote::BEGIN@11
0	0	0	0s	0s	Sub::Quote::::CLONESub::Quote::CLONE
0	0	0	0s	0s	Sub::Quote::::qsubSub::Quote::qsub

Call graph for these subroutines as a Graphviz dot language file.

Line	State ments	Time on line	Calls	Time in subs	Code
1					package Sub::Quote;
2
3	3	194µs	3	932µs	# spent 863µs (690+173) within Sub::Quote::BEGIN@3 which was called: # once (690µs+173µs) by DBIx::Class::_Util::BEGIN@64 at line 3 use strictures 1; # spent 863µs making 1 call to Sub::Quote::BEGIN@3 # spent 40µs making 1 call to strictures::VERSION # spent 29µs making 1 call to strictures::import
4
5	14	1.57ms			# spent 5.31ms (4.81+499µs) within Sub::Quote::_clean_eval which was called 14 times, avg 379µs/call: # 14 times (4.81ms+499µs) by Sub::Quote::unquote_sub at line 157, avg 379µs/call sub _clean_eval { eval $_[0] } # spent 5.40ms executing statements in string eval # includes 2.24ms spent executing 422 calls to 3 subs defined therein. # spent 1.89ms executing statements in string eval # includes 1.60ms spent executing 154 calls to 3 subs defined therein. # spent 787µs executing statements in string eval # includes 934µs spent executing 136 calls to 3 subs defined therein. # spent 696µs executing statements in string eval # includes 155µs spent executing 8 calls to 4 subs defined therein. # spent 651µs executing statements in string eval # includes 4.79ms spent executing 125 calls to 3 subs defined therein. # spent 544µs executing statements in string eval # includes 209µs spent executing 9 calls to 3 subs defined therein. # spent 420µs executing statements in string eval # includes 59µs spent executing 5 calls to 3 subs defined therein. # spent 386µs executing statements in string eval # includes 51µs spent executing 4 calls to 3 subs defined therein. # spent 331µs executing statements in string eval # includes 34µs spent executing 5 calls to 3 subs defined therein. # spent 324µs executing statements in string eval # includes 188µs spent executing 22 calls to 3 subs defined therein. # spent 303µs executing statements in string eval # includes 68µs spent executing 8 calls to 4 subs defined therein. # spent 231µs executing statements in string eval # includes 110µs spent executing 9 calls to 3 subs defined therein. # spent 160µs executing statements in string eval # includes 38µs spent executing 7 calls to 3 subs defined therein. # spent 155µs executing statements in string eval # includes 88µs spent executing 15 calls to 3 subs defined therein.
6
7	2	319µs	2	7.92ms	# spent 7.86ms (1.22+6.64) within Sub::Quote::BEGIN@7 which was called: # once (1.22ms+6.64ms) by DBIx::Class::_Util::BEGIN@64 at line 7 use Sub::Defer; # spent 7.86ms making 1 call to Sub::Quote::BEGIN@7 # spent 53µs making 1 call to Exporter::import
8	2	263µs	2	235µs	# spent 156µs (77+79) within Sub::Quote::BEGIN@8 which was called: # once (77µs+79µs) by DBIx::Class::_Util::BEGIN@64 at line 8 use Scalar::Util qw(weaken); # spent 156µs making 1 call to Sub::Quote::BEGIN@8 # spent 79µs making 1 call to Exporter::import
9	2	114µs	2	108µs	# spent 92µs (76+16) within Sub::Quote::BEGIN@9 which was called: # once (76µs+16µs) by DBIx::Class::_Util::BEGIN@64 at line 9 use Exporter qw(import); # spent 92µs making 1 call to Sub::Quote::BEGIN@9 # spent 16µs making 1 call to Exporter::import
10	2	434µs	1	5.51ms	# spent 5.51ms (4.13+1.37) within Sub::Quote::BEGIN@10 which was called: # once (4.13ms+1.37ms) by DBIx::Class::_Util::BEGIN@64 at line 10 use B (); # spent 5.51ms making 1 call to Sub::Quote::BEGIN@10
11					# spent 13µs within Sub::Quote::BEGIN@11 which was called: # once (13µs+0s) by DBIx::Class::_Util::BEGIN@64 at line 13 BEGIN {
12	1	10µs			*_HAVE_PERLSTRING = defined &B::perlstring ? sub(){1} : sub(){0};
13	1	1.66ms	1	13µs	} # spent 13µs making 1 call to Sub::Quote::BEGIN@11
14
15	1	2µs			our $VERSION = '1.006001';
16	1	32µs			$VERSION = eval $VERSION; # spent 4µs executing statements in string eval
17
18	1	3µs			our @EXPORT = qw(quote_sub unquote_sub quoted_from_sub qsub);
19	1	2µs			our @EXPORT_OK = qw(quotify capture_unroll inlinify);
20
21	1	200ns			our %QUOTED;
22
23					# spent 4.04ms (2.78+1.27) within Sub::Quote::quotify which was called 1172 times, avg 3µs/call: # 1078 times (2.54ms+1.16ms) by Sub::Quote::quote_sub at line 81, avg 3µs/call # 32 times (93µs+41µs) by Sub::Quote::capture_unroll at line 36, avg 4µs/call # 16 times (32µs+14µs) by Method::Generate::Accessor::_generate_simple_set at line 570 of Method/Generate/Accessor.pm, avg 3µs/call # 16 times (27µs+13µs) by Method::Generate::Accessor::_generate_core_set at line 564 of Method/Generate/Accessor.pm, avg 2µs/call # 11 times (21µs+10µs) by Method::Generate::Constructor::_assign_new at line 176 of Method/Generate/Constructor.pm, avg 3µs/call # 6 times (16µs+7µs) by Method::Generate::Accessor::_generate_simple_get at line 334 of Method/Generate/Accessor.pm, avg 4µs/call # 3 times (23µs+5µs) by Method::Generate::Accessor::_generate_simple_has at line 271 of Method/Generate/Accessor.pm, avg 9µs/call # 3 times (5µs+2µs) by Method::Generate::Accessor::_wrap_attr_exception at line 419 of Method/Generate/Accessor.pm, avg 2µs/call # 2 times (12µs+7µs) by Method::Generate::Constructor::_handle_subconstructor at line 121 of Method/Generate/Constructor.pm, avg 9µs/call # 2 times (4µs+2µs) by Method::Generate::Accessor::_generate_get_default at line 315 of Method/Generate/Accessor.pm, avg 3µs/call # once (2µs+2µs) by Method::Generate::Accessor::_wrap_attr_exception at line 418 of Method/Generate/Accessor.pm # once (2µs+900ns) by Method::Generate::Accessor::_attr_desc at line 382 of Method/Generate/Accessor.pm # once (2µs+900ns) by Method::Generate::Accessor::_generate_simple_clear at line 276 of Method/Generate/Accessor.pm sub quotify {
24	1172	4.56ms	1172	1.27ms	! defined $_[0] ? 'undef()' # spent 1.27ms making 1172 calls to B::perlstring, avg 1µs/call
25					: _HAVE_PERLSTRING ? B::perlstring($_[0])
26					: qq["\Q$_[0]\E"];
27					}
28
29					# spent 497µs (314+183) within Sub::Quote::capture_unroll which was called 14 times, avg 36µs/call: # 14 times (314µs+183µs) by Sub::Quote::unquote_sub at line 132, avg 36µs/call sub capture_unroll {
30	14	7µs			my ($from, $captures, $indent) = @_;
31	32	115µs	32	49µs	join( # spent 49µs making 32 calls to Sub::Quote::CORE:match, avg 2µs/call
32					'',
33					map {
34	14	96µs			/^([\@\%\$])/
35					or die "capture key should start with \@, \% or \$: $_";
36	64	144µs	32	134µs	(' ' x $indent).qq{my ${_} = ${1}{${from}->{${\quotify $_}}};\n}; # spent 134µs making 32 calls to Sub::Quote::quotify, avg 4µs/call
37					} keys %$captures
38					);
39					}
40
41					# spent 72µs (49+24) within Sub::Quote::inlinify which was called 4 times, avg 18µs/call: # 4 times (49µs+24µs) by Method::Generate::Accessor::_generate_call_code at line 473 of Method/Generate/Accessor.pm, avg 18µs/call sub inlinify {
42	4	2µs			my ($code, $args, $extra, $local) = @_;
43	4	3µs			my $do = 'do { '.($extra\|\|'');
44	4	35µs	4	19µs	if ($code =~ s/^(\s*package\s+([a-zA-Z0-9:]+);)//) { # spent 19µs making 4 calls to Sub::Quote::CORE:subst, avg 5µs/call
45					$do .= $1;
46					}
47	4	16µs	4	5µs	if ($code =~ s{(\A\s\|\A# BEGIN quote_sub PRELUDE\n.?# END quote_sub PRELUDE\n\s)(^\s)(my\s$([^)]+)$\s=\s*\@_;)$}{ # spent 5µs making 4 calls to Sub::Quote::CORE:subst, avg 1µs/call
48					my ($pre, $indent, $assign, $code_args) = ($1, $2, $3, $4);
49					if ($code_args eq $args) {
50					$pre . $indent . ($local ? 'local ' : '').'@_ = ('.$args.");\n"
51					. $indent . $assign;
52					}
53					else {
54					$pre . 'my ('.$code_args.') = ('.$args.'); ';
55					}
56					}mse) {
57					#done
58					}
59					elsif ($local \|\| $args ne '@_') {
60					$do .= ($local ? 'local ' : '').'@_ = ('.$args.'); ';
61					}
62	4	21µs			$do.$code.' }';
63					}
64
65					# spent 34.7ms (13.9+20.8) within Sub::Quote::quote_sub which was called 539 times, avg 64µs/call: # 144 times (3.88ms+6.40ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 99 of DBIx/Class/Relationship/Accessor.pm, avg 71µs/call # 144 times (4.10ms+4.88ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 100 of DBIx/Class/Relationship/Accessor.pm, avg 62µs/call # 144 times (3.02ms+4.64ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 101 of DBIx/Class/Relationship/Accessor.pm, avg 53µs/call # 53 times (1.74ms+3.25ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 26 of DBIx/Class/Relationship/Accessor.pm, avg 94µs/call # 22 times (424µs+650µs) by base::import at line 84 of DBIx/Class/ResultSourceProxy.pm, avg 49µs/call # 18 times (393µs+541µs) by Class::C3::Componentised::ensure_class_loaded at line 124 of DBIx/Class/Storage/DBI.pm, avg 52µs/call # 4 times (87µs+70µs) by DBIx::Class::Storage::BEGIN@16 at line 76 of DBIx/Class/_Util.pm, avg 39µs/call # 3 times (58µs+87µs) by Class::C3::Componentised::ensure_class_loaded at line 1625 of DBIx/Class/Storage/DBI.pm, avg 48µs/call # 2 times (60µs+85µs) by Method::Generate::Accessor::generate_method at line 116 of Method/Generate/Accessor.pm, avg 72µs/call # 2 times (68µs+52µs) by Method::Generate::Constructor::generate_method at line 114 of Method/Generate/Constructor.pm, avg 60µs/call # once (29µs+41µs) by Method::Generate::Accessor::generate_method at line 137 of Method/Generate/Accessor.pm # once (22µs+33µs) by Method::Generate::Accessor::generate_method at line 156 of Method/Generate/Accessor.pm # once (16µs+28µs) by Method::Generate::Accessor::generate_method at line 183 of Method/Generate/Accessor.pm sub quote_sub {
66					# HOLY DWIMMERY, BATMAN!
67					# $name => $code => \%captures => \%options
68					# $name => $code => \%captures
69					# $name => $code
70					# $code => \%captures => \%options
71					# $code
72	539	447µs			my $options =
73					(ref($_[-1]) eq 'HASH' and ref($_[-2]) eq 'HASH')
74					? pop
75					: {};
76	539	220µs			my $captures = ref($_[-1]) eq 'HASH' ? pop : undef;
77	539	101µs			undef($captures) if $captures && !keys %$captures;
78	539	139µs			my $code = pop;
79	539	96µs			my $name = $_[0];
80	539	1.85ms			my ($package, $hints, $bitmask, $hintshash) = (caller(0))[0,8,9,10];
81	539	2.22ms	1078	3.70ms	my $context # spent 3.70ms making 1078 calls to Sub::Quote::quotify, avg 3µs/call
82					="# BEGIN quote_sub PRELUDE\n"
83					."package $package;\n"
84					."BEGIN {\n"
85					." \$^H = ".quotify($hints).";\n"
86					." \${^WARNING_BITS} = ".quotify($bitmask).";\n"
87					." \%^H = (\n"
88					. join('', map
89					" ".quotify($_)." => ".quotify($hintshash->{$_}).",",
90					keys %$hintshash)
91					." );\n"
92					."}\n"
93					."# END quote_sub PRELUDE\n";
94	539	685µs			$code = "$context$code";
95	539	62µs			my $quoted_info;
96					my $unquoted;
97					# spent 5.18ms (57µs+5.13) within Sub::Quote::__ANON__[/usr/share/perl5/Sub/Quote.pm:100] which was called 12 times, avg 432µs/call: # 12 times (57µs+5.13ms) by Sub::Defer::undefer_sub at line 22 of Sub/Defer.pm, avg 432µs/call my $deferred = defer_sub +($options->{no_install} ? undef : $name) => sub {
98					$unquoted if 0;
99	12	40µs	12	5.13ms	unquote_sub($quoted_info->[4]); # spent 5.13ms making 12 calls to Sub::Quote::unquote_sub, avg 427µs/call
100	539	2.33ms	539	16.0ms	}; # spent 16.0ms making 539 calls to Sub::Defer::defer_sub, avg 30µs/call
101	539	628µs			$quoted_info = [ $name, $code, $captures, \$unquoted, $deferred ];
102	539	1.41ms	539	524µs	weaken($quoted_info->[3]); # spent 524µs making 539 calls to Scalar::Util::weaken, avg 971ns/call
103	539	1.01ms	539	288µs	weaken($quoted_info->[4]); # spent 288µs making 539 calls to Scalar::Util::weaken, avg 534ns/call
104	539	1.38ms	539	256µs	weaken($QUOTED{$deferred} = $quoted_info); # spent 256µs making 539 calls to Scalar::Util::weaken, avg 475ns/call
105	539	1.38ms			return $deferred;
106					}
107
108					# spent 29µs within Sub::Quote::quoted_from_sub which was called 4 times, avg 7µs/call: # 4 times (29µs+0s) by Method::Generate::Accessor::_generate_call_code at line 460 of Method/Generate/Accessor.pm, avg 7µs/call sub quoted_from_sub {
109	4	1µs			my ($sub) = @_;
110	4	5µs			my $quoted_info = $QUOTED{$sub\|\|''} or return undef;
111	4	5µs			my ($name, $code, $captured, $unquoted, $deferred) = @{$quoted_info};
112	4	3µs			$unquoted &&= $$unquoted;
113	4	20µs			if (($deferred && $deferred eq $sub)
114					\|\| ($unquoted && $unquoted eq $sub)) {
115					return [ $name, $code, $captured, $unquoted, $deferred ];
116					}
117					return undef;
118					}
119
120					# spent 6.44ms (609µs+5.83) within Sub::Quote::unquote_sub which was called 14 times, avg 460µs/call: # 12 times (544µs+4.58ms) by Sub::Quote::__ANON__[/usr/share/perl5/Sub/Quote.pm:100] at line 99, avg 427µs/call # 2 times (65µs+1.25ms) by Method::Generate::Constructor::__ANON__[/usr/share/perl5/Method/Generate/Constructor.pm:81] at line 78 of Method/Generate/Constructor.pm, avg 658µs/call sub unquote_sub {
121	14	5µs			my ($sub) = @_;
122	14	12µs			my $quoted = $QUOTED{$sub} or return undef;
123	14	8µs			my $unquoted = $quoted->[3];
124	14	12µs			unless ($unquoted && $$unquoted) {
125	14	10µs			my ($name, $code, $captures) = @$quoted;
126
127	14	7µs			my $make_sub = "{\n";
128
129	14	18µs			my %captures = $captures ? %$captures : ();
130	14	13µs			$captures{'$_UNQUOTED'} = \$unquoted;
131	14	7µs			$captures{'$_QUOTED'} = \$quoted;
132	14	36µs	14	497µs	$make_sub .= capture_unroll("\$_[1]", \%captures, 2); # spent 497µs making 14 calls to Sub::Quote::capture_unroll, avg 36µs/call
133
134	14	11µs			$make_sub .= (
135					$name
136					# disable the 'variable $x will not stay shared' warning since
137					# we're not letting it escape from this scope anyway so there's
138					# nothing trying to share it
139					? " no warnings 'closure';\n sub ${name} {\n"
140					: " \$\$_UNQUOTED = sub {\n"
141					);
142	14	5µs			$make_sub .= " \$_QUOTED if 0;\n";
143	14	4µs			$make_sub .= " \$_UNQUOTED if 0;\n";
144	14	8µs			$make_sub .= $code;
145	14	8µs			$make_sub .= " }".($name ? '' : ';')."\n";
146	14	11µs			if ($name) {
147					$make_sub .= " \$\$_UNQUOTED = \\&${name}\n";
148					}
149	14	3µs			$make_sub .= "}\n1;\n";
150	14	13µs			$ENV{SUB_QUOTE_DEBUG} && warn $make_sub;
151					{
152	16	560µs	2	83µs	# spent 58µs (34+24) within Sub::Quote::BEGIN@152 which was called: # once (34µs+24µs) by DBIx::Class::_Util::BEGIN@64 at line 152 no strict 'refs'; # spent 58µs making 1 call to Sub::Quote::BEGIN@152 # spent 24µs making 1 call to strict::unimport
153	14	75µs			local *{$name} if $name;
154	14	3µs			my ($success, $e);
155					{
156	28	12µs			local $@;
157	14	35µs	14	5.31ms	$success = _clean_eval($make_sub, \%captures); # spent 5.31ms making 14 calls to Sub::Quote::_clean_eval, avg 379µs/call
158	14	12µs			$e = $@;
159					}
160	14	5µs			unless ($success) {
161					die "Eval went very, very wrong:\n\n${make_sub}\n\n$e";
162					}
163	14	219µs	14	28µs	weaken($QUOTED{$$unquoted} = $quoted); # spent 28µs making 14 calls to Scalar::Util::weaken, avg 2µs/call
164					}
165					}
166	14	42µs			$$unquoted;
167					}
168
169					sub qsub ($) {
170					goto &quote_sub;
171					}
172
173					sub CLONE {
174					%QUOTED = map { defined $_ ? (
175					$_->[3] && ${$_->[3]} ? (${ $_->[3] } => $_) : (),
176					$_->[4] ? ($_->[4] => $_) : (),
177					) : () } values %QUOTED;
178					weaken($_) for values %QUOTED;
179					}
180
181	1	6µs			1;
182					__END__

					# spent 49µs within Sub::Quote::CORE:match which was called 32 times, avg 2µs/call: # 32 times (49µs+0s) by Sub::Quote::capture_unroll at line 31, avg 2µs/call sub Sub::Quote::CORE:match; # opcode
					# spent 24µs within Sub::Quote::CORE:subst which was called 8 times, avg 3µs/call: # 4 times (19µs+0s) by Sub::Quote::inlinify at line 44, avg 5µs/call # 4 times (5µs+0s) by Sub::Quote::inlinify at line 47, avg 1µs/call sub Sub::Quote::CORE:subst; # opcode