← Index
NYTProf Performance Profile   « line view »
For starman worker -M FindBin --max-requests 50 --workers 2 --user=kohadev-koha --group kohadev-koha --pid /var/run/koha/kohadev/plack.pid --daemonize --access-log /var/log/koha/kohadev/plack.log --error-log /var/log/koha/kohadev/plack-error.log -E deployment --socket /var/run/koha/kohadev/plack.sock /etc/koha/sites/kohadev/plack.psgi
  Run on Fri Jan 8 14:31:06 2016
Reported on Fri Jan 8 14:33:27 2016

Filename/usr/lib/x86_64-linux-gnu/perl/5.20/B.pm
StatementsExecuted 0 statements in 0s
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
1178111.21ms1.21msB::::perlstring B::perlstring (xsub)
11122µs40µsB::::BEGIN@9 B::BEGIN@9
11119µs30µsB::::BEGIN@254 B::BEGIN@254
11114µs749µsB::::BEGIN@17 B::BEGIN@17
0000s0sB::GV::::SAFENAME B::GV::SAFENAME
0000s0sB::IV::::int_value B::IV::int_value
0000s0sB::Section::::addB::Section::add
0000s0sB::Section::::defaultB::Section::default
0000s0sB::Section::::getB::Section::get
0000s0sB::Section::::indexB::Section::index
0000s0sB::Section::::nameB::Section::name
0000s0sB::Section::::newB::Section::new
0000s0sB::Section::::outputB::Section::output
0000s0sB::Section::::symtableB::Section::symtable
0000s0sB::::class B::class
0000s0sB::::clearsym B::clearsym
0000s0sB::::compile_stats B::compile_stats
0000s0sB::::debug B::debug
0000s0sB::::objsym B::objsym
0000s0sB::::parents B::parents
0000s0sB::::peekop B::peekop
0000s0sB::::savesym B::savesym
0000s0sB::::timing_info B::timing_info
0000s0sB::::walkoptree_exec B::walkoptree_exec
0000s0sB::::walkoptree_slow B::walkoptree_slow
0000s0sB::::walksymtable B::walksymtable
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1# B.pm
2#
3# Copyright (c) 1996, 1997, 1998 Malcolm Beattie
4#
5# You may distribute under the terms of either the GNU General Public
6# License or the Artistic License, as specified in the README file.
7#
8package B;
9259µs
# spent 40µs (22+18) within B::BEGIN@9 which was called: # once (22µs+18µs) by Sub::Quote::BEGIN@10 at line 9
use strict;
# spent 40µs making 1 call to B::BEGIN@9 # spent 18µs making 1 call to strict::import
10
11require Exporter;
12@B::ISA = qw(Exporter);
13
14# walkoptree_slow comes from B.pm (you are there),
15# walkoptree comes from B.xs
16
17
# spent 749µs (14+734) within B::BEGIN@17 which was called: # once (14µs+734µs) by Sub::Quote::BEGIN@10 at line 28
BEGIN {
18 $B::VERSION = '1.48';
19 @B::EXPORT_OK = ();
20
21 # Our BOOT code needs $VERSION set, and will append to @EXPORT_OK.
22 # Want our constants loaded before the compiler meets OPf_KIDS below, as
23 # the combination of having the constant stay a Proxy Constant Subroutine
24 # and its value being inlined saves a little over .5K
25
26 require XSLoader;
271734µs XSLoader::load();
# spent 734µs making 1 call to XSLoader::load
281749µs}
# spent 749µs making 1 call to B::BEGIN@17
29
30push @B::EXPORT_OK, (qw(minus_c ppname save_BEGINs
31 class peekop cast_I32 cstring cchar hash threadsv_names
32 main_root main_start main_cv svref_2object opnumber
33 sub_generation amagic_generation perlstring
34 walkoptree_slow walkoptree walkoptree_exec walksymtable
35 parents comppadlist sv_undef compile_stats timing_info
36 begin_av init_av check_av end_av regex_padav dowarn
37 defstash curstash warnhook diehook inc_gv @optype
38 @specialsv_name unitcheck_av));
39
40@B::SV::ISA = 'B::OBJECT';
41@B::NULL::ISA = 'B::SV';
42@B::PV::ISA = 'B::SV';
43@B::IV::ISA = 'B::SV';
44@B::NV::ISA = 'B::SV';
45# RV is eliminated with 5.11.0, but effectively is a specialisation of IV now.
46@B::RV::ISA = $] >= 5.011 ? 'B::IV' : 'B::SV';
47@B::PVIV::ISA = qw(B::PV B::IV);
48@B::PVNV::ISA = qw(B::PVIV B::NV);
49@B::PVMG::ISA = 'B::PVNV';
50@B::REGEXP::ISA = 'B::PVMG' if $] >= 5.011;
51@B::INVLIST::ISA = 'B::PV' if $] >= 5.019;
52@B::PVLV::ISA = 'B::GV';
53@B::BM::ISA = 'B::GV';
54@B::AV::ISA = 'B::PVMG';
55@B::GV::ISA = 'B::PVMG';
56@B::HV::ISA = 'B::PVMG';
57@B::CV::ISA = 'B::PVMG';
58@B::IO::ISA = 'B::PVMG';
59@B::FM::ISA = 'B::CV';
60
61@B::OP::ISA = 'B::OBJECT';
62@B::UNOP::ISA = 'B::OP';
63@B::BINOP::ISA = 'B::UNOP';
64@B::LOGOP::ISA = 'B::UNOP';
65@B::LISTOP::ISA = 'B::BINOP';
66@B::SVOP::ISA = 'B::OP';
67@B::PADOP::ISA = 'B::OP';
68@B::PVOP::ISA = 'B::OP';
69@B::LOOP::ISA = 'B::LISTOP';
70@B::PMOP::ISA = 'B::LISTOP';
71@B::COP::ISA = 'B::OP';
72
73@B::SPECIAL::ISA = 'B::OBJECT';
74
75@B::optype = qw(OP UNOP BINOP LOGOP LISTOP PMOP SVOP PADOP PVOP LOOP COP);
76# bytecode.pl contained the following comment:
77# Nullsv *must* come first in the following so that the condition
78# ($$sv == 0) can continue to be used to test (sv == Nullsv).
79@B::specialsv_name = qw(Nullsv &PL_sv_undef &PL_sv_yes &PL_sv_no
80 (SV*)pWARN_ALL (SV*)pWARN_NONE (SV*)pWARN_STD);
81
82{
83 # Stop "-w" from complaining about the lack of a real B::OBJECT class
84 package B::OBJECT;
85}
86
87sub B::GV::SAFENAME {
88 my $name = (shift())->NAME;
89
90 # The regex below corresponds to the isCONTROLVAR macro
91 # from toke.c
92
93 $name =~ s/^\c?/^?/
94 or $name =~ s/^([\cA-\cZ\c\\c[\c]\c_\c^])/
95 "^" . chr( utf8::unicode_to_native( 64 ^ ord($1) ))/e;
96
97 # When we say unicode_to_native we really mean ascii_to_native,
98 # which matters iff this is a non-ASCII platform (EBCDIC). '\c?' would
99 # not have to be special cased, except for non-ASCII.
100
101 return $name;
102}
103
104sub B::IV::int_value {
105 my ($self) = @_;
106 return (($self->FLAGS() & SVf_IVisUV()) ? $self->UVX : $self->IV);
107}
108
109sub B::NULL::as_string() {""}
110*B::IV::as_string = \*B::IV::int_value;
111*B::PV::as_string = \*B::PV::PV;
112
113# The input typemap checking makes no distinction between different SV types,
114# so the XS body will generate the same C code, despite the different XS
115# "types". So there is no change in behaviour from doing "newXS" like this,
116# compared with the old approach of having a (near) duplicate XS body.
117# We should fix the typemap checking.
118*B::IV::RV = \*B::PV::RV if $] > 5.012;
119
120my $debug;
121my $op_count = 0;
122my @parents = ();
123
124sub debug {
125 my ($class, $value) = @_;
126 $debug = $value;
127 walkoptree_debug($value);
128}
129
130sub class {
131 my $obj = shift;
132 my $name = ref $obj;
133 $name =~ s/^.*:://;
134 return $name;
135}
136
137sub parents { \@parents }
138
139# For debugging
140sub peekop {
141 my $op = shift;
142 return sprintf("%s (0x%x) %s", class($op), $$op, $op->name);
143}
144
145sub walkoptree_slow {
146 my($op, $method, $level) = @_;
147 $op_count++; # just for statistics
148 $level ||= 0;
149 warn(sprintf("walkoptree: %d. %s\n", $level, peekop($op))) if $debug;
150 $op->$method($level) if $op->can($method);
151 if ($$op && ($op->flags & OPf_KIDS)) {
152 my $kid;
153 unshift(@parents, $op);
154 for ($kid = $op->first; $$kid; $kid = $kid->sibling) {
155 walkoptree_slow($kid, $method, $level + 1);
156 }
157 shift @parents;
158 }
159 if (class($op) eq 'PMOP'
160 && ref($op->pmreplroot)
161 && ${$op->pmreplroot}
162 && $op->pmreplroot->isa( 'B::OP' ))
163 {
164 unshift(@parents, $op);
165 walkoptree_slow($op->pmreplroot, $method, $level + 1);
166 shift @parents;
167 }
168}
169
170sub compile_stats {
171 return "Total number of OPs processed: $op_count\n";
172}
173
174sub timing_info {
175 my ($sec, $min, $hr) = localtime;
176 my ($user, $sys) = times;
177 sprintf("%02d:%02d:%02d user=$user sys=$sys",
178 $hr, $min, $sec, $user, $sys);
179}
180
181my %symtable;
182
183sub clearsym {
184 %symtable = ();
185}
186
187sub savesym {
188 my ($obj, $value) = @_;
189# warn(sprintf("savesym: sym_%x => %s\n", $$obj, $value)); # debug
190 $symtable{sprintf("sym_%x", $$obj)} = $value;
191}
192
193sub objsym {
194 my $obj = shift;
195 return $symtable{sprintf("sym_%x", $$obj)};
196}
197
198sub walkoptree_exec {
199 my ($op, $method, $level) = @_;
200 $level ||= 0;
201 my ($sym, $ppname);
202 my $prefix = " " x $level;
203 for (; $$op; $op = $op->next) {
204 $sym = objsym($op);
205 if (defined($sym)) {
206 print $prefix, "goto $sym\n";
207 return;
208 }
209 savesym($op, sprintf("%s (0x%lx)", class($op), $$op));
210 $op->$method($level);
211 $ppname = $op->name;
212 if ($ppname =~
213 /^(d?or(assign)?|and(assign)?|mapwhile|grepwhile|entertry|range|cond_expr)$/)
214 {
215 print $prefix, uc($1), " => {\n";
216 walkoptree_exec($op->other, $method, $level + 1);
217 print $prefix, "}\n";
218 } elsif ($ppname eq "match" || $ppname eq "subst") {
219 my $pmreplstart = $op->pmreplstart;
220 if ($$pmreplstart) {
221 print $prefix, "PMREPLSTART => {\n";
222 walkoptree_exec($pmreplstart, $method, $level + 1);
223 print $prefix, "}\n";
224 }
225 } elsif ($ppname eq "substcont") {
226 print $prefix, "SUBSTCONT => {\n";
227 walkoptree_exec($op->other->pmreplstart, $method, $level + 1);
228 print $prefix, "}\n";
229 $op = $op->other;
230 } elsif ($ppname eq "enterloop") {
231 print $prefix, "REDO => {\n";
232 walkoptree_exec($op->redoop, $method, $level + 1);
233 print $prefix, "}\n", $prefix, "NEXT => {\n";
234 walkoptree_exec($op->nextop, $method, $level + 1);
235 print $prefix, "}\n", $prefix, "LAST => {\n";
236 walkoptree_exec($op->lastop, $method, $level + 1);
237 print $prefix, "}\n";
238 } elsif ($ppname eq "subst") {
239 my $replstart = $op->pmreplstart;
240 if ($$replstart) {
241 print $prefix, "SUBST => {\n";
242 walkoptree_exec($replstart, $method, $level + 1);
243 print $prefix, "}\n";
244 }
245 }
246 }
247}
248
249sub walksymtable {
250 my ($symref, $method, $recurse, $prefix) = @_;
251 my $sym;
252 my $ref;
253 my $fullname;
254242µs
# spent 30µs (19+12) within B::BEGIN@254 which was called: # once (19µs+12µs) by Sub::Quote::BEGIN@10 at line 254
no strict 'refs';
# spent 30µs making 1 call to B::BEGIN@254 # spent 12µs making 1 call to strict::unimport
255 $prefix = '' unless defined $prefix;
256 foreach my $sym ( sort keys %$symref ) {
257 $ref= $symref->{$sym};
258 $fullname = "*main::".$prefix.$sym;
259 if ($sym =~ /::$/) {
260 $sym = $prefix . $sym;
261 if (svref_2object(\*$sym)->NAME ne "main::" && $sym ne "<none>::" && &$recurse($sym)) {
262 walksymtable(\%$fullname, $method, $recurse, $sym);
263 }
264 } else {
265 svref_2object(\*$fullname)->$method();
266 }
267 }
268}
269
270{
271 package B::Section;
272 my $output_fh;
273 my %sections;
274
275 sub new {
276 my ($class, $section, $symtable, $default) = @_;
277 $output_fh ||= FileHandle->new_tmpfile;
278 my $obj = bless [-1, $section, $symtable, $default], $class;
279 $sections{$section} = $obj;
280 return $obj;
281 }
282
283 sub get {
284 my ($class, $section) = @_;
285 return $sections{$section};
286 }
287
288 sub add {
289 my $section = shift;
290 while (defined($_ = shift)) {
291 print $output_fh "$section->[1]\t$_\n";
292 $section->[0]++;
293 }
294 }
295
296 sub index {
297 my $section = shift;
298 return $section->[0];
299 }
300
301 sub name {
302 my $section = shift;
303 return $section->[1];
304 }
305
306 sub symtable {
307 my $section = shift;
308 return $section->[2];
309 }
310
311 sub default {
312 my $section = shift;
313 return $section->[3];
314 }
315
316 sub output {
317 my ($section, $fh, $format) = @_;
318 my $name = $section->name;
319 my $sym = $section->symtable || {};
320 my $default = $section->default;
321
322 seek($output_fh, 0, 0);
323 while (<$output_fh>) {
324 chomp;
325 s/^(.*?)\t//;
326 if ($1 eq $name) {
327 s{(s\\_[0-9a-f]+)} {
328 exists($sym->{$1}) ? $sym->{$1} : $default;
329 }ge;
330 printf $fh $format, $_;
331 }
332 }
333 }
334}
335
3361;
337
338__END__
 
# spent 1.21ms within B::perlstring which was called 1178 times, avg 1µs/call: # 1178 times (1.21ms+0s) by Sub::Quote::quotify at line 24 of Sub/Quote.pm, avg 1µs/call
sub B::perlstring; # xsub
Report produced by the NYTProf 6.02 Perl profiler, developed by Tim Bunce and Adam Kaplan.