Profile of Sub/Quote.pm

Filename	/usr/share/perl5/Sub/Quote.pm
Statements	Executed 9947 statements in 31.1ms

Subroutines
Calls	P	F	Exclusive Time	Inclusive Time	Subroutine
539	13	6	17.0ms	45.7ms	Sub::Quote::::quote_subSub::Quote::quote_sub
1178	13	3	6.80ms	8.12ms	Sub::Quote::::quotifySub::Quote::quotify
16	1	1	5.34ms	6.09ms	Sub::Quote::::_clean_evalSub::Quote::_clean_eval
1	1	1	2.88ms	3.70ms	Sub::Quote::::BEGIN@10Sub::Quote::BEGIN@10
1	1	1	680µs	825µs	Sub::Quote::::BEGIN@3Sub::Quote::BEGIN@3
1	1	1	623µs	3.77ms	Sub::Quote::::BEGIN@7Sub::Quote::BEGIN@7
16	2	2	595µs	7.26ms	Sub::Quote::::unquote_subSub::Quote::unquote_sub
16	1	1	331µs	548µs	Sub::Quote::::capture_unrollSub::Quote::capture_unroll
14	1	1	77µs	6.01ms	Sub::Quote::::__ANON__[:100]Sub::Quote::__ANON__[:100]
38	1	1	58µs	58µs	Sub::Quote::::CORE:matchSub::Quote::CORE:match (opcode)
4	1	1	39µs	68µs	Sub::Quote::::inlinifySub::Quote::inlinify
4	1	1	38µs	38µs	Sub::Quote::::quoted_from_subSub::Quote::quoted_from_sub
8	2	1	29µs	29µs	Sub::Quote::::CORE:substSub::Quote::CORE:subst (opcode)
1	1	1	17µs	31µs	Sub::Quote::::BEGIN@152Sub::Quote::BEGIN@152
1	1	1	9µs	24µs	Sub::Quote::::BEGIN@8Sub::Quote::BEGIN@8
1	1	1	7µs	7µs	Sub::Quote::::BEGIN@11Sub::Quote::BEGIN@11
1	1	1	7µs	12µs	Sub::Quote::::BEGIN@9Sub::Quote::BEGIN@9
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	174µs	3	885µs	# spent 825µs (680+146) within Sub::Quote::BEGIN@3 which was called: # once (680µs+146µs) by DBIx::Class::_Util::BEGIN@64 at line 3 use strictures 1; # spent 825µs making 1 call to Sub::Quote::BEGIN@3 # spent 35µs making 1 call to strictures::VERSION # spent 25µs making 1 call to strictures::import
4
5	16	1.75ms			# spent 6.09ms (5.34+743µs) within Sub::Quote::_clean_eval which was called 16 times, avg 380µs/call: # 16 times (5.34ms+743µs) by Sub::Quote::unquote_sub at line 157, avg 380µs/call sub _clean_eval { eval $_[0] } # spent 5.39ms executing statements in string eval # includes 2.56ms spent executing 422 calls to 3 subs defined therein. # spent 3.65ms executing statements in string eval # includes 2.90ms spent executing 93 calls to 4 subs defined therein. # spent 1.81ms executing statements in string eval # includes 1.77ms spent executing 154 calls to 3 subs defined therein. # spent 1.03ms executing statements in string eval # includes 732µs spent executing 93 calls to 4 subs defined therein. # spent 1.01ms executing statements in string eval # includes 7.48ms spent executing 177 calls to 3 subs defined therein. # spent 923µs executing statements in string eval # includes 1.03ms spent executing 357 calls to 3 subs defined therein. # spent 867µs executing statements in string eval # includes 1.02ms spent executing 136 calls to 3 subs defined therein. # spent 694µs executing statements in string eval # includes 831µs spent executing 125 calls to 3 subs defined therein. # spent 663µs executing statements in string eval # includes 501µs spent executing 180 calls to 3 subs defined therein. # spent 481µs executing statements in string eval # includes 90µs spent executing 5 calls to 3 subs defined therein. # spent 478µs executing statements in string eval # includes 305µs spent executing 92 calls to 3 subs defined therein. # spent 339µs executing statements in string eval # includes 201µs spent executing 22 calls to 3 subs defined therein. # spent 295µs executing statements in string eval # includes 58µs spent executing 5 calls to 3 subs defined therein. # spent 282µs executing statements in string eval # includes 55µs spent executing 4 calls to 3 subs defined therein. # spent 238µs executing statements in string eval # includes 32µs spent executing 4 calls to 3 subs defined therein. # spent 231µs executing statements in string eval # includes 33µs spent executing 5 calls to 3 subs defined therein.
6
7	2	158µs	2	3.80ms	# spent 3.77ms (623µs+3.15) within Sub::Quote::BEGIN@7 which was called: # once (623µs+3.15ms) by DBIx::Class::_Util::BEGIN@64 at line 7 use Sub::Defer; # spent 3.77ms making 1 call to Sub::Quote::BEGIN@7 # spent 23µs making 1 call to Exporter::import
8	2	45µs	2	40µs	# spent 24µs (9+15) within Sub::Quote::BEGIN@8 which was called: # once (9µs+15µs) by DBIx::Class::_Util::BEGIN@64 at line 8 use Scalar::Util qw(weaken); # spent 24µs making 1 call to Sub::Quote::BEGIN@8 # spent 15µs making 1 call to Exporter::import
9	2	29µs	2	17µs	# spent 12µs (7+5) within Sub::Quote::BEGIN@9 which was called: # once (7µs+5µs) by DBIx::Class::_Util::BEGIN@64 at line 9 use Exporter qw(import); # spent 12µs making 1 call to Sub::Quote::BEGIN@9 # spent 5µs making 1 call to Exporter::import
10	2	212µs	1	3.70ms	# spent 3.70ms (2.88+824µs) within Sub::Quote::BEGIN@10 which was called: # once (2.88ms+824µs) by DBIx::Class::_Util::BEGIN@64 at line 10 use B (); # spent 3.70ms making 1 call to Sub::Quote::BEGIN@10
11					# spent 7µs within Sub::Quote::BEGIN@11 which was called: # once (7µs+0s) by DBIx::Class::_Util::BEGIN@64 at line 13 BEGIN {
12	1	6µs			*_HAVE_PERLSTRING = defined &B::perlstring ? sub(){1} : sub(){0};
13	1	944µs	1	7µs	} # spent 7µs making 1 call to Sub::Quote::BEGIN@11
14
15	1	500ns			our $VERSION = '1.006001';
16	1	18µs			$VERSION = eval $VERSION; # spent 3µs executing statements in string eval
17
18	1	2µs			our @EXPORT = qw(quote_sub unquote_sub quoted_from_sub qsub);
19	1	1µs			our @EXPORT_OK = qw(quotify capture_unroll inlinify);
20
21	1	100ns			our %QUOTED;
22
23					# spent 8.12ms (6.80+1.33) within Sub::Quote::quotify which was called 1178 times, avg 7µs/call: # 1078 times (6.56ms+1.22ms) by Sub::Quote::quote_sub at line 81, avg 7µs/call # 38 times (109µs+50µs) by Sub::Quote::capture_unroll at line 36, avg 4µs/call # 16 times (31µs+15µs) by Method::Generate::Accessor::_generate_simple_set at line 570 of Method/Generate/Accessor.pm, avg 3µs/call # 16 times (24µs+12µs) by Method::Generate::Accessor::_generate_core_set at line 564 of Method/Generate/Accessor.pm, avg 2µs/call # 11 times (24µs+11µs) by Method::Generate::Constructor::_assign_new at line 176 of Method/Generate/Constructor.pm, avg 3µs/call # 6 times (12µs+6µs) by Method::Generate::Accessor::_generate_simple_get at line 334 of Method/Generate/Accessor.pm, avg 3µs/call # 3 times (6µs+3µs) by Method::Generate::Accessor::_generate_simple_has at line 271 of Method/Generate/Accessor.pm, avg 3µ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 (13µs+7µs) by Method::Generate::Constructor::_handle_subconstructor at line 121 of Method/Generate/Constructor.pm, avg 10µ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+1µs) by Method::Generate::Accessor::_attr_desc at line 382 of Method/Generate/Accessor.pm # once (2µs+1µs) by Method::Generate::Accessor::_generate_simple_clear at line 276 of Method/Generate/Accessor.pm sub quotify {
24	1178	12.6ms	1178	1.33ms	! defined $_[0] ? 'undef()' # spent 1.33ms making 1178 calls to B::perlstring, avg 1µs/call
25					: _HAVE_PERLSTRING ? B::perlstring($_[0])
26					: qq["\Q$_[0]\E"];
27					}
28
29					# spent 548µs (331+217) within Sub::Quote::capture_unroll which was called 16 times, avg 34µs/call: # 16 times (331µs+217µs) by Sub::Quote::unquote_sub at line 132, avg 34µs/call sub capture_unroll {
30	16	10µs			my ($from, $captures, $indent) = @_;
31	38	132µs	38	58µs	join( # spent 58µs making 38 calls to Sub::Quote::CORE:match, avg 2µs/call
32					'',
33					map {
34	16	91µs			/^([\@\%\$])/
35					or die "capture key should start with \@, \% or \$: $_";
36	76	145µs	38	159µs	(' ' x $indent).qq{my ${_} = ${1}{${from}->{${\quotify $_}}};\n}; # spent 159µs making 38 calls to Sub::Quote::quotify, avg 4µs/call
37					} keys %$captures
38					);
39					}
40
41					# spent 68µs (39+29) within Sub::Quote::inlinify which was called 4 times, avg 17µs/call: # 4 times (39µs+29µs) by Method::Generate::Accessor::_generate_call_code at line 473 of Method/Generate/Accessor.pm, avg 17µs/call sub inlinify {
42	4	2µs			my ($code, $args, $extra, $local) = @_;
43	4	3µs			my $do = 'do { '.($extra\|\|'');
44	4	29µs	4	17µs	if ($code =~ s/^(\s*package\s+([a-zA-Z0-9:]+);)//) { # spent 17µs making 4 calls to Sub::Quote::CORE:subst, avg 4µs/call
45					$do .= $1;
46					}
47	4	24µs	4	12µs	if ($code =~ s{(\A\s\|\A# BEGIN quote_sub PRELUDE\n.?# END quote_sub PRELUDE\n\s)(^\s)(my\s$([^)]+)$\s=\s*\@_;)$}{ # spent 12µs making 4 calls to Sub::Quote::CORE:subst, avg 3µ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	13µs			$do.$code.' }';
63					}
64
65					# spent 45.7ms (17.0+28.7) within Sub::Quote::quote_sub which was called 539 times, avg 85µs/call: # 144 times (3.07ms+13.1ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 101 of DBIx/Class/Relationship/Accessor.pm, avg 112µs/call # 144 times (3.75ms+6.27ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 99 of DBIx/Class/Relationship/Accessor.pm, avg 70µs/call # 144 times (3.07ms+4.85ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 100 of DBIx/Class/Relationship/Accessor.pm, avg 55µs/call # 53 times (5.81ms+2.75ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 26 of DBIx/Class/Relationship/Accessor.pm, avg 162µs/call # 22 times (488µs+786µs) by base::import at line 84 of DBIx/Class/ResultSourceProxy.pm, avg 58µs/call # 18 times (400µs+551µs) by Class::C3::Componentised::ensure_class_loaded at line 124 of DBIx/Class/Storage/DBI.pm, avg 53µs/call # 4 times (87µs+72µs) by DBIx::Class::Storage::BEGIN@16 at line 76 of DBIx/Class/_Util.pm, avg 40µs/call # 3 times (64µs+97µs) by Class::C3::Componentised::ensure_class_loaded at line 1625 of DBIx/Class/Storage/DBI.pm, avg 54µs/call # 2 times (74µs+58µs) by Method::Generate::Constructor::generate_method at line 114 of Method/Generate/Constructor.pm, avg 66µs/call # 2 times (40µs+71µs) by Method::Generate::Accessor::generate_method at line 116 of Method/Generate/Accessor.pm, avg 55µs/call # once (51µs+55µs) by Method::Generate::Accessor::generate_method at line 137 of Method/Generate/Accessor.pm # once (21µs+42µs) by Method::Generate::Accessor::generate_method at line 156 of Method/Generate/Accessor.pm # once (20µs+29µ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	425µs			my $options =
73					(ref($_[-1]) eq 'HASH' and ref($_[-2]) eq 'HASH')
74					? pop
75					: {};
76	539	174µs			my $captures = ref($_[-1]) eq 'HASH' ? pop : undef;
77	539	72µs			undef($captures) if $captures && !keys %$captures;
78	539	118µs			my $code = pop;
79	539	80µs			my $name = $_[0];
80	539	1.85ms			my ($package, $hints, $bitmask, $hintshash) = (caller(0))[0,8,9,10];
81	539	2.30ms	1078	7.78ms	my $context # spent 7.78ms making 1078 calls to Sub::Quote::quotify, avg 7µ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	693µs			$code = "$context$code";
95	539	69µs			my $quoted_info;
96					my $unquoted;
97					# spent 6.01ms (77µs+5.93) within Sub::Quote::__ANON__[/usr/share/perl5/Sub/Quote.pm:100] which was called 14 times, avg 429µs/call: # 14 times (77µs+5.93ms) by Sub::Defer::undefer_sub at line 22 of Sub/Defer.pm, avg 429µs/call my $deferred = defer_sub +($options->{no_install} ? undef : $name) => sub {
98					$unquoted if 0;
99	14	67µs	14	5.93ms	unquote_sub($quoted_info->[4]); # spent 5.93ms making 14 calls to Sub::Quote::unquote_sub, avg 424µs/call
100	539	2.11ms	539	19.9ms	}; # spent 19.9ms making 539 calls to Sub::Defer::defer_sub, avg 37µs/call
101	539	560µs			$quoted_info = [ $name, $code, $captures, \$unquoted, $deferred ];
102	539	1.41ms	539	458µs	weaken($quoted_info->[3]); # spent 458µs making 539 calls to Scalar::Util::weaken, avg 849ns/call
103	539	995µs	539	306µs	weaken($quoted_info->[4]); # spent 306µs making 539 calls to Scalar::Util::weaken, avg 568ns/call
104	539	1.38ms	539	256µs	weaken($QUOTED{$deferred} = $quoted_info); # spent 256µs making 539 calls to Scalar::Util::weaken, avg 476ns/call
105	539	1.44ms			return $deferred;
106					}
107
108					# spent 38µs within Sub::Quote::quoted_from_sub which was called 4 times, avg 9µs/call: # 4 times (38µs+0s) by Method::Generate::Accessor::_generate_call_code at line 460 of Method/Generate/Accessor.pm, avg 9µs/call sub quoted_from_sub {
109	4	1µs			my ($sub) = @_;
110	4	4µs			my $quoted_info = $QUOTED{$sub\|\|''} or return undef;
111	4	5µs			my ($name, $code, $captured, $unquoted, $deferred) = @{$quoted_info};
112	4	10µs			$unquoted &&= $$unquoted;
113	4	26µ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 7.26ms (595µs+6.67) within Sub::Quote::unquote_sub which was called 16 times, avg 454µs/call: # 14 times (546µs+5.38ms) by Sub::Quote::__ANON__[/usr/share/perl5/Sub/Quote.pm:100] at line 99, avg 424µs/call # 2 times (49µs+1.28ms) by Method::Generate::Constructor::__ANON__[/usr/share/perl5/Method/Generate/Constructor.pm:81] at line 78 of Method/Generate/Constructor.pm, avg 665µs/call sub unquote_sub {
121	16	11µs			my ($sub) = @_;
122	16	19µs			my $quoted = $QUOTED{$sub} or return undef;
123	16	12µs			my $unquoted = $quoted->[3];
124	16	14µs			unless ($unquoted && $$unquoted) {
125	16	16µs			my ($name, $code, $captures) = @$quoted;
126
127	16	10µs			my $make_sub = "{\n";
128
129	16	23µs			my %captures = $captures ? %$captures : ();
130	16	16µs			$captures{'$_UNQUOTED'} = \$unquoted;
131	16	9µs			$captures{'$_QUOTED'} = \$quoted;
132	16	38µs	16	548µs	$make_sub .= capture_unroll("\$_[1]", \%captures, 2); # spent 548µs making 16 calls to Sub::Quote::capture_unroll, avg 34µs/call
133
134	16	12µ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	16	4µs			$make_sub .= " \$_QUOTED if 0;\n";
143	16	3µs			$make_sub .= " \$_UNQUOTED if 0;\n";
144	16	8µs			$make_sub .= $code;
145	16	8µs			$make_sub .= " }".($name ? '' : ';')."\n";
146	16	8µs			if ($name) {
147					$make_sub .= " \$\$_UNQUOTED = \\&${name}\n";
148					}
149	16	3µs			$make_sub .= "}\n1;\n";
150	16	10µs			$ENV{SUB_QUOTE_DEBUG} && warn $make_sub;
151					{
152	18	287µs	2	45µs	# spent 31µs (17+14) within Sub::Quote::BEGIN@152 which was called: # once (17µs+14µs) by DBIx::Class::_Util::BEGIN@64 at line 152 no strict 'refs'; # spent 31µs making 1 call to Sub::Quote::BEGIN@152 # spent 14µs making 1 call to strict::unimport
153	16	91µs			local *{$name} if $name;
154	16	2µs			my ($success, $e);
155					{
156	32	9µs			local $@;
157	16	30µs	16	6.09ms	$success = _clean_eval($make_sub, \%captures); # spent 6.09ms making 16 calls to Sub::Quote::_clean_eval, avg 380µs/call
158	16	11µs			$e = $@;
159					}
160	16	5µs			unless ($success) {
161					die "Eval went very, very wrong:\n\n${make_sub}\n\n$e";
162					}
163	16	152µs	16	32µs	weaken($QUOTED{$$unquoted} = $quoted); # spent 32µs making 16 calls to Scalar::Util::weaken, avg 2µs/call
164					}
165					}
166	16	47µ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 58µs within Sub::Quote::CORE:match which was called 38 times, avg 2µs/call: # 38 times (58µs+0s) by Sub::Quote::capture_unroll at line 31, avg 2µs/call sub Sub::Quote::CORE:match; # opcode
					# spent 29µs within Sub::Quote::CORE:subst which was called 8 times, avg 4µs/call: # 4 times (17µs+0s) by Sub::Quote::inlinify at line 44, avg 4µs/call # 4 times (12µs+0s) by Sub::Quote::inlinify at line 47, avg 3µs/call sub Sub::Quote::CORE:subst; # opcode