Profile of Sub/Quote.pm

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

Subroutines
Calls	P	F	Exclusive Time	Inclusive Time	Subroutine
539	13	6	13.3ms	43.9ms	Sub::Quote::::quote_subSub::Quote::quote_sub
1172	13	3	6.70ms	7.98ms	Sub::Quote::::quotifySub::Quote::quotify
14	1	1	4.73ms	5.18ms	Sub::Quote::::_clean_evalSub::Quote::_clean_eval
1	1	1	2.44ms	3.49ms	Sub::Quote::::BEGIN@10Sub::Quote::BEGIN@10
1	1	1	642µs	791µs	Sub::Quote::::BEGIN@3Sub::Quote::BEGIN@3
1	1	1	618µs	3.74ms	Sub::Quote::::BEGIN@7Sub::Quote::BEGIN@7
14	2	2	559µs	6.29ms	Sub::Quote::::unquote_subSub::Quote::unquote_sub
14	1	1	304µs	519µs	Sub::Quote::::capture_unrollSub::Quote::capture_unroll
32	1	1	52µs	52µs	Sub::Quote::::CORE:matchSub::Quote::CORE:match (opcode)
12	1	1	48µs	5.00ms	Sub::Quote::::__ANON__[:100]Sub::Quote::__ANON__[:100]
4	1	1	39µs	62µs	Sub::Quote::::inlinifySub::Quote::inlinify
4	1	1	29µs	29µs	Sub::Quote::::quoted_from_subSub::Quote::quoted_from_sub
8	2	1	23µs	23µs	Sub::Quote::::CORE:substSub::Quote::CORE:subst (opcode)
1	1	1	13µs	20µ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	12µs	Sub::Quote::::BEGIN@9Sub::Quote::BEGIN@9
1	1	1	6µs	6µ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	172µs	3	852µs	# spent 791µs (642+148) within Sub::Quote::BEGIN@3 which was called: # once (642µs+148µs) by DBIx::Class::_Util::BEGIN@64 at line 3 use strictures 1; # spent 791µs making 1 call to Sub::Quote::BEGIN@3 # spent 37µs making 1 call to strictures::VERSION # spent 24µs making 1 call to strictures::import
4
5	14	1.53ms			# spent 5.18ms (4.73+452µs) within Sub::Quote::_clean_eval which was called 14 times, avg 370µs/call: # 14 times (4.73ms+452µs) by Sub::Quote::unquote_sub at line 157, avg 370µs/call sub _clean_eval { eval $_[0] } # spent 120ms executing statements in string eval # includes 105ms spent executing 3005 calls to 4 subs defined therein. # spent 36.9ms executing statements in string eval # includes 23.4ms spent executing 3005 calls to 4 subs defined therein. # spent 27.6ms executing statements in string eval # includes 31.2ms spent executing 12003 calls to 3 subs defined therein. # spent 23.0ms executing statements in string eval # includes 131ms spent executing 6003 calls to 3 subs defined therein. # spent 16.5ms executing statements in string eval # includes 17.4ms spent executing 6003 calls to 3 subs defined therein. # spent 10.5ms executing statements in string eval # includes 6.48ms spent executing 3004 calls to 3 subs defined therein. # spent 1.99ms executing statements in string eval # includes 2.42ms spent executing 422 calls to 3 subs defined therein. # spent 1.75ms executing statements in string eval # includes 1.63ms spent executing 154 calls to 3 subs defined therein. # spent 803µs executing statements in string eval # includes 1.01ms spent executing 136 calls to 3 subs defined therein. # spent 648µs executing statements in string eval # includes 772µs spent executing 125 calls to 3 subs defined therein. # spent 480µs executing statements in string eval # includes 71µs spent executing 5 calls to 3 subs defined therein. # spent 328µs executing statements in string eval # includes 179µs spent executing 22 calls to 3 subs defined therein. # spent 277µs executing statements in string eval # includes 37µs spent executing 5 calls to 3 subs defined therein. # spent 269µs executing statements in string eval # includes 42µs spent executing 4 calls to 3 subs defined therein.
6
7	2	167µs	2	3.76ms	# spent 3.74ms (618µs+3.12) within Sub::Quote::BEGIN@7 which was called: # once (618µs+3.12ms) by DBIx::Class::_Util::BEGIN@64 at line 7 use Sub::Defer; # spent 3.74ms making 1 call to Sub::Quote::BEGIN@7 # spent 20µs making 1 call to Exporter::import
8	2	45µs	2	40µs	# spent 24µs (9+16) within Sub::Quote::BEGIN@8 which was called: # once (9µs+16µ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 16µs making 1 call to Exporter::import
9	2	28µs	2	16µ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	190µs	1	3.49ms	# spent 3.49ms (2.44+1.05) within Sub::Quote::BEGIN@10 which was called: # once (2.44ms+1.05ms) by DBIx::Class::_Util::BEGIN@64 at line 10 use B (); # spent 3.49ms making 1 call to Sub::Quote::BEGIN@10
11					# spent 6µs within Sub::Quote::BEGIN@11 which was called: # once (6µ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	882µs	1	6µs	} # spent 6µs making 1 call to Sub::Quote::BEGIN@11
14
15	1	400ns			our $VERSION = '1.006001';
16	1	16µs			$VERSION = eval $VERSION; # spent 2µs executing statements in string eval
17
18	1	1µs			our @EXPORT = qw(quote_sub unquote_sub quoted_from_sub qsub);
19	1	500ns			our @EXPORT_OK = qw(quotify capture_unroll inlinify);
20
21	1	100ns			our %QUOTED;
22
23					# spent 7.98ms (6.70+1.29) within Sub::Quote::quotify which was called 1172 times, avg 7µs/call: # 1078 times (6.45ms+1.17ms) by Sub::Quote::quote_sub at line 81, avg 7µs/call # 32 times (105µs+58µs) by Sub::Quote::capture_unroll at line 36, avg 5µs/call # 16 times (31µs+14µs) by Method::Generate::Accessor::_generate_simple_set at line 570 of Method/Generate/Accessor.pm, avg 3µs/call # 16 times (26µ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+10µs) by Method::Generate::Constructor::_assign_new at line 176 of Method/Generate/Constructor.pm, avg 3µs/call # 6 times (20µs+9µs) by Method::Generate::Accessor::_generate_simple_get at line 334 of Method/Generate/Accessor.pm, avg 5µs/call # 3 times (5µs+2µ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 3µs/call # 2 times (14µs+7µs) by Method::Generate::Constructor::_handle_subconstructor at line 121 of Method/Generate/Constructor.pm, avg 11µ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 (3µs+1µs) by Method::Generate::Accessor::_attr_desc at line 382 of Method/Generate/Accessor.pm # 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::_generate_simple_clear at line 276 of Method/Generate/Accessor.pm sub quotify {
24	1172	8.68ms	1172	1.29ms	! defined $_[0] ? 'undef()' # spent 1.29ms 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 519µs (304+215) within Sub::Quote::capture_unroll which was called 14 times, avg 37µs/call: # 14 times (304µs+215µs) by Sub::Quote::unquote_sub at line 132, avg 37µs/call sub capture_unroll {
30	14	9µs			my ($from, $captures, $indent) = @_;
31	32	123µs	32	52µs	join( # spent 52µs making 32 calls to Sub::Quote::CORE:match, avg 2µs/call
32					'',
33					map {
34	14	78µs			/^([\@\%\$])/
35					or die "capture key should start with \@, \% or \$: $_";
36	64	139µs	32	163µs	(' ' x $indent).qq{my ${_} = ${1}{${from}->{${\quotify $_}}};\n}; # spent 163µs making 32 calls to Sub::Quote::quotify, avg 5µs/call
37					} keys %$captures
38					);
39					}
40
41					# spent 62µs (39+23) within Sub::Quote::inlinify which was called 4 times, avg 15µs/call: # 4 times (39µs+23µs) by Method::Generate::Accessor::_generate_call_code at line 473 of Method/Generate/Accessor.pm, avg 15µ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	18µs	if ($code =~ s/^(\s*package\s+([a-zA-Z0-9:]+);)//) { # spent 18µs making 4 calls to Sub::Quote::CORE:subst, avg 5µs/call
45					$do .= $1;
46					}
47	4	15µs	4	4µs	if ($code =~ s{(\A\s\|\A# BEGIN quote_sub PRELUDE\n.?# END quote_sub PRELUDE\n\s)(^\s)(my\s$([^)]+)$\s=\s*\@_;)$}{ # spent 4µ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	12µs			$do.$code.' }';
63					}
64
65					# spent 43.9ms (13.3+30.6) within Sub::Quote::quote_sub which was called 539 times, avg 81µs/call: # 144 times (4.26ms+14.9ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 99 of DBIx/Class/Relationship/Accessor.pm, avg 133µs/call # 144 times (2.97ms+6.44ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 101 of DBIx/Class/Relationship/Accessor.pm, avg 65µs/call # 144 times (2.84ms+4.70ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 100 of DBIx/Class/Relationship/Accessor.pm, avg 52µs/call # 53 times (2.03ms+2.86ms) by DBIx::Class::Relationship::Accessor::add_relationship_accessor at line 26 of DBIx/Class/Relationship/Accessor.pm, avg 92µs/call # 22 times (420µs+697µs) by base::import at line 84 of DBIx/Class/ResultSourceProxy.pm, avg 51µs/call # 18 times (422µs+543µs) by Class::C3::Componentised::ensure_class_loaded at line 124 of DBIx/Class/Storage/DBI.pm, avg 54µs/call # 4 times (90µs+72µs) by DBIx::Class::Storage::BEGIN@16 at line 76 of DBIx/Class/_Util.pm, avg 41µs/call # 3 times (58µs+86µs) by Class::C3::Componentised::ensure_class_loaded at line 1625 of DBIx/Class/Storage/DBI.pm, avg 48µs/call # 2 times (59µs+82µs) by Method::Generate::Accessor::generate_method at line 116 of Method/Generate/Accessor.pm, avg 71µs/call # 2 times (73µs+58µs) by Method::Generate::Constructor::generate_method at line 114 of Method/Generate/Constructor.pm, avg 66µs/call # once (25µs+42µs) by Method::Generate::Accessor::generate_method at line 137 of Method/Generate/Accessor.pm # once (26µs+32µs) by Method::Generate::Accessor::generate_method at line 156 of Method/Generate/Accessor.pm # once (17µs+33µ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	397µs			my $options =
73					(ref($_[-1]) eq 'HASH' and ref($_[-2]) eq 'HASH')
74					? pop
75					: {};
76	539	178µs			my $captures = ref($_[-1]) eq 'HASH' ? pop : undef;
77	539	74µs			undef($captures) if $captures && !keys %$captures;
78	539	115µs			my $code = pop;
79	539	84µs			my $name = $_[0];
80	539	1.89ms			my ($package, $hints, $bitmask, $hintshash) = (caller(0))[0,8,9,10];
81	539	2.33ms	1078	7.62ms	my $context # spent 7.62ms 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	735µs			$code = "$context$code";
95	539	110µs			my $quoted_info;
96					my $unquoted;
97					# spent 5.00ms (48µs+4.96) within Sub::Quote::__ANON__[/usr/share/perl5/Sub/Quote.pm:100] which was called 12 times, avg 417µs/call: # 12 times (48µs+4.96ms) by Sub::Defer::undefer_sub at line 22 of Sub/Defer.pm, avg 417µs/call my $deferred = defer_sub +($options->{no_install} ? undef : $name) => sub {
98					$unquoted if 0;
99	12	42µs	12	4.96ms	unquote_sub($quoted_info->[4]); # spent 4.96ms making 12 calls to Sub::Quote::unquote_sub, avg 413µs/call
100	539	2.11ms	539	21.9ms	}; # spent 21.9ms making 539 calls to Sub::Defer::defer_sub, avg 41µs/call
101	539	533µs			$quoted_info = [ $name, $code, $captures, \$unquoted, $deferred ];
102	539	1.51ms	539	482µs	weaken($quoted_info->[3]); # spent 482µs making 539 calls to Scalar::Util::weaken, avg 894ns/call
103	539	983µs	539	291µs	weaken($quoted_info->[4]); # spent 291µs making 539 calls to Scalar::Util::weaken, avg 541ns/call
104	539	1.32ms	539	258µs	weaken($QUOTED{$deferred} = $quoted_info); # spent 258µs making 539 calls to Scalar::Util::weaken, avg 480ns/call
105	539	10.6ms			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	4µs			my $quoted_info = $QUOTED{$sub\|\|''} or return undef;
111	4	4µs			my ($name, $code, $captured, $unquoted, $deferred) = @{$quoted_info};
112	4	2µ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.29ms (559µs+5.73) within Sub::Quote::unquote_sub which was called 14 times, avg 449µs/call: # 12 times (491µs+4.46ms) by Sub::Quote::__ANON__[/usr/share/perl5/Sub/Quote.pm:100] at line 99, avg 413µs/call # 2 times (68µs+1.26ms) by Method::Generate::Constructor::__ANON__[/usr/share/perl5/Method/Generate/Constructor.pm:81] at line 78 of Method/Generate/Constructor.pm, avg 666µs/call sub unquote_sub {
121	14	4µs			my ($sub) = @_;
122	14	14µs			my $quoted = $QUOTED{$sub} or return undef;
123	14	7µs			my $unquoted = $quoted->[3];
124	14	10µs			unless ($unquoted && $$unquoted) {
125	14	12µs			my ($name, $code, $captures) = @$quoted;
126
127	14	6µ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	37µs	14	519µs	$make_sub .= capture_unroll("\$_[1]", \%captures, 2); # spent 519µs making 14 calls to Sub::Quote::capture_unroll, avg 37µs/call
133
134	14	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	14	4µs			$make_sub .= " \$_QUOTED if 0;\n";
143	14	3µs			$make_sub .= " \$_UNQUOTED if 0;\n";
144	14	8µs			$make_sub .= $code;
145	14	7µs			$make_sub .= " }".($name ? '' : ';')."\n";
146	14	7µs			if ($name) {
147					$make_sub .= " \$\$_UNQUOTED = \\&${name}\n";
148					}
149	14	3µs			$make_sub .= "}\n1;\n";
150	14	11µs			$ENV{SUB_QUOTE_DEBUG} && warn $make_sub;
151					{
152	16	277µs	2	27µs	# spent 20µs (13+7) within Sub::Quote::BEGIN@152 which was called: # once (13µs+7µs) by DBIx::Class::_Util::BEGIN@64 at line 152 no strict 'refs'; # spent 20µs making 1 call to Sub::Quote::BEGIN@152 # spent 7µs making 1 call to strict::unimport
153	14	119µs			local *{$name} if $name;
154	14	2µs			my ($success, $e);
155					{
156	28	9µs			local $@;
157	14	26µs	14	5.18ms	$success = _clean_eval($make_sub, \%captures); # spent 5.18ms making 14 calls to Sub::Quote::_clean_eval, avg 370µs/call
158	14	9µs			$e = $@;
159					}
160	14	3µs			unless ($success) {
161					die "Eval went very, very wrong:\n\n${make_sub}\n\n$e";
162					}
163	14	158µs	14	24µs	weaken($QUOTED{$$unquoted} = $quoted); # spent 24µs making 14 calls to Scalar::Util::weaken, avg 2µs/call
164					}
165					}
166	14	40µ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	3µs			1;
182					__END__

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