← Index
NYTProf Performance Profile   « block view • line view • sub view »
For /usr/share/koha/opac/cgi-bin/opac/opac-search.pl
  Run on Tue Oct 15 17:10:45 2013
Reported on Tue Oct 15 17:12:30 2013

Filename/usr/share/perl/5.10/utf8_heavy.pl
StatementsExecuted 13111 statements in 56.6ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
16131146.1ms55.5msutf8::::SWASHNEWutf8::SWASHNEW (recurses: max depth 1, inclusive time 12.2ms)
85061118.63ms8.63msutf8::::CORE:matchutf8::CORE:match (opcode)
3790643.72ms3.72msutf8::::is_utf8utf8::is_utf8 (xsub)
1319111.70ms1.70msutf8::::decodeutf8::decode (xsub)
1511626µs626µsutf8::::CORE:sortutf8::CORE:sort (opcode)
5011133µs133µsutf8::::downgradeutf8::downgrade (xsub)
325178µs78µsutf8::::CORE:substutf8::CORE:subst (opcode)
572268µs68µsutf8::::encodeutf8::encode (xsub)
11128µs38µsutf8::::BEGIN@2utf8::BEGIN@2
11123µs59µsutf8::::BEGIN@211utf8::BEGIN@211
11122µs62µsutf8::::BEGIN@3utf8::BEGIN@3
11121µs58µsutf8::::BEGIN@76utf8::BEGIN@76
11113µs29µsutf8::::BEGIN@155utf8::BEGIN@155
0000s0sutf8::::DESTROYutf8::DESTROY
0000s0sutf8::::croakutf8::croak
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package utf8;
2362µs247µs
# spent 38µs (28+9) within utf8::BEGIN@2 which was called: # once (28µs+9µs) by utf8::AUTOLOAD at line 2
use strict;
# spent 38µs making 1 call to utf8::BEGIN@2 # spent 10µs making 1 call to strict::import
33542µs2102µs
# spent 62µs (22+40) within utf8::BEGIN@3 which was called: # once (22µs+40µs) by utf8::AUTOLOAD at line 3
use warnings;
# spent 62µs making 1 call to utf8::BEGIN@3 # spent 40µs making 1 call to warnings::import
4
5sub DEBUG () { 0 }
6
7sub DESTROY {}
8
91700nsmy %Cache;
10
1111µsour (%PropertyAlias, %PA_reverse, %PropValueAlias, %PVA_reverse, %PVA_abbr_map);
12
13sub croak { require Carp; Carp::croak(@_) }
14
15##
16## "SWASH" == "SWATCH HASH". A "swatch" is a swatch of the Unicode landscape.
17## It's a data structure that encodes a set of Unicode characters.
18##
19
20
# spent 55.5ms (46.1+9.33) within utf8::SWASHNEW which was called 16 times, avg 3.47ms/call: # 3 times (9.86ms+-9.86ms) by utf8::SWASHNEW at line 250, avg 0s/call # 2 times (92µs+15µs) by DBD::mysql::CORE:match at line 49 of DBD/mysql.pm, avg 54µs/call # once (26.5ms+4.66ms) by DBI::CORE:subst at line 18 of utf8.pm # once (8.00ms+1.96ms) by DBI::CORE:subst at line 600 of DBI.pm # once (98µs+6.25ms) by C4::ClassSortRoutine::Dewey::CORE:subst at line 67 of /usr/share/koha/lib/C4/ClassSortRoutine/Dewey.pm # once (95µs+5.92ms) by C4::ClassSortRoutine::Dewey::CORE:subst at line 84 of /usr/share/koha/lib/C4/ClassSortRoutine/Dewey.pm # once (504µs+108µs) by MARC::Field::CORE:match at line 198 of MARC/Field.pm # once (459µs+72µs) by Template::Directive::CORE:match at line 70 of Template/Directive.pm # once (194µs+51µs) by C4::Charset::CORE:subst at line 385 of /usr/share/koha/lib/C4/Charset.pm # once (94µs+104µs) by C4::ClassSortRoutine::Generic::CORE:subst at line 62 of /usr/share/koha/lib/C4/ClassSortRoutine/Generic.pm # once (145µs+33µs) by C4::Search::CORE:subst at line 578 of /usr/share/koha/lib/C4/Search.pm # once (68µs+10µs) by C4::Biblio::CORE:subst at line 1436 of /usr/share/koha/lib/C4/Biblio.pm # once (31µs+5µs) by DBD::mysql::CORE:match at line 56 of DBD/mysql.pm
sub SWASHNEW {
211637µs my ($class, $type, $list, $minbits, $none) = @_;
221623µs local $^D = 0 if $^D;
23
24164µs print STDERR "SWASHNEW @_\n" if DEBUG;
25
26 ##
27 ## Get the list of codepoints for the type.
28 ## Called from swash_init (see utf8.c) or SWASHNEW itself.
29 ##
30 ## Callers of swash_init:
31 ## op.c:pmtrans -- for tr/// and y///
32 ## regexec.c:regclass_swash -- for /[]/, \p, and \P
33 ## utf8.c:is_utf8_common -- for common Unicode properties
34 ## utf8.c:to_utf8_case -- for lc, uc, ucfirst, etc. and //i
35 ##
36 ## Given a $type, our goal is to fill $list with the set of codepoint
37 ## ranges. If $type is false, $list passed is used.
38 ##
39 ## $minbits:
40 ## For binary properties, $minbits must be 1.
41 ## For character mappings (case and transliteration), $minbits must
42 ## be a number except 1.
43 ##
44 ## $list (or that filled according to $type):
45 ## Refer to perlunicode.pod, "User-Defined Character Properties."
46 ##
47 ## For binary properties, only characters with the property value
48 ## of True should be listed. The 3rd column, if any, will be ignored.
49 ##
50 ## To make the parsing of $type clear, this code takes the a rather
51 ## unorthodox approach of last'ing out of the block once we have the
52 ## info we need. Were this to be a subroutine, the 'last' would just
53 ## be a 'return'.
54 ##
55167µs my $file; ## file to load data from, and also part of the %Cache key.
561611µs my $ListSorted = 0;
57
581611µs if ($type)
59 {
60754µs718µs $type =~ s/^\s+//;
# spent 18µs making 7 calls to utf8::CORE:subst, avg 3µs/call
61730µs712µs $type =~ s/\s+$//;
# spent 12µs making 7 calls to utf8::CORE:subst, avg 2µs/call
62
6372µs print STDERR "type = $type\n" if DEBUG;
64
65740µs75µs GETFILE:
# spent 5µs making 7 calls to utf8::CORE:subst, avg 743ns/call
66 {
67 ##
68 ## It could be a user-defined property.
69 ##
70
7174µs my $caller1 = $type =~ s/(.+)::// ? $1 : caller(1);
72
73755µs722µs if (defined $caller1 && $type =~ /^(?:\w+)$/) {
# spent 22µs making 7 calls to utf8::CORE:match, avg 3µs/call
74713µs my $prop = "${caller1}::$type";
75728µs if (exists &{$prop}) {
763733µs295µs
# spent 58µs (21+37) within utf8::BEGIN@76 which was called: # once (21µs+37µs) by utf8::AUTOLOAD at line 76
no strict 'refs';
# spent 58µs making 1 call to utf8::BEGIN@76 # spent 37µs making 1 call to strict::unimport
77
78 $list = &{$prop};
79 last GETFILE;
80 }
81 }
82
8373µs my $wasIs;
84
85770µs1034µs ($wasIs = $type =~ s/^Is(?:\s+|[-_])?//i)
# spent 34µs making 10 calls to utf8::CORE:subst, avg 3µs/call
86 or
87 $type =~ s/^(?:(?:General(?:\s+|_)?)?Category|gc)\s*[:=]\s*//i
88 or
89 $type =~ s/^(?:Script|sc)\s*[:=]\s*//i
90 or
91 $type =~ s/^Block\s*[:=]\s*/In/i;
92
93
94 ##
95 ## See if it's in some enumeration.
96 ##
9775.38ms require "unicore/PVA.pl";
98763µs722µs if ($type =~ /^([\w\s]+)[:=]\s*(.*)/) {
# spent 22µs making 7 calls to utf8::CORE:match, avg 3µs/call
99 my ($enum, $val) = (lc $1, lc $2);
100 $enum =~ tr/ _-//d;
101 $val =~ tr/ _-//d;
102
103 my $pa = $PropertyAlias{$enum} ? $enum : $PA_reverse{$enum};
104 my $f = $PropValueAlias{$pa}{$val} ? $val : $PVA_reverse{$pa}{lc $val};
105
106 if ($pa and $f) {
107 $pa = "gc_sc" if $pa eq "gc" or $pa eq "sc";
108 $file = "unicore/lib/$pa/$PVA_abbr_map{$pa}{lc $f}.pl";
109 last GETFILE;
110 }
111 }
112 else {
113715µs my $t = lc $type;
114723µs $t =~ tr/ _-//d;
115
116738µs if ($PropValueAlias{gc}{$t} or $PropValueAlias{sc}{$t}) {
117 $file = "unicore/lib/gc_sc/$PVA_abbr_map{gc_sc}{$t}.pl";
118 last GETFILE;
119 }
120 }
121
122 ##
123 ## See if it's in the direct mapping table.
124 ##
1257515µs require "unicore/Exact.pl";
126716µs if (my $base = $utf8::Exact{$type}) {
127611µs $file = "unicore/lib/gc_sc/$base.pl";
128612µs last GETFILE;
129 }
130
131 ##
132 ## If not there exactly, try the canonical form. The canonical
133 ## form is lowercased, with any separators (\s+|[-_]) removed.
134 ##
13511µs my $canonical = lc $type;
136115µs18µs $canonical =~ s/(?<=[a-z\d])(?:\s+|[-_])(?=[a-z\d])//g;
# spent 8µs making 1 call to utf8::CORE:subst
1371400ns print STDERR "canonical = $canonical\n" if DEBUG;
138
13911.48ms require "unicore/Canonical.pl";
14013µs if (my $base = ($utf8::Canonical{$canonical} || $utf8::Canonical{ lc $utf8::PropertyAlias{$canonical} })) {
141 $file = "unicore/lib/gc_sc/$base.pl";
142 last GETFILE;
143 }
144
145 ##
146 ## See if it's a user-level "To".
147 ##
148
14912µs my $caller0 = caller(0);
150
151115µs16µs if (defined $caller0 && $type =~ /^To(?:\w+)$/) {
# spent 6µs making 1 call to utf8::CORE:match
15212µs my $map = $caller0 . "::" . $type;
153
15414µs if (exists &{$map}) {
1553373µs245µs
# spent 29µs (13+16) within utf8::BEGIN@155 which was called: # once (13µs+16µs) by utf8::AUTOLOAD at line 155
no strict 'refs';
# spent 29µs making 1 call to utf8::BEGIN@155 # spent 16µs making 1 call to strict::unimport
156
157 $list = &{$map};
158 last GETFILE;
159 }
160 }
161
162 ##
163 ## Last attempt -- see if it's a standard "To" name
164 ## (e.g. "ToLower") ToTitle is used by ucfirst().
165 ## The user-level way to access ToDigit() and ToFold()
166 ## is to use Unicode::UCD.
167 ##
16818µs14µs if ($type =~ /^To(Digit|Fold|Lower|Title|Upper)$/) {
# spent 4µs making 1 call to utf8::CORE:match
16915µs $file = "unicore/To/$1.pl";
170 ## would like to test to see if $file actually exists....
17114µs last GETFILE;
172 }
173
174 ##
175 ## If we reach this line, it's because we couldn't figure
176 ## out what to do with $type. Ouch.
177 ##
178
179 return $type;
180 }
181
18277µs if (defined $file) {
18372µs print STDERR "found it (file='$file')\n" if DEBUG;
184
185 ##
186 ## If we reach here, it was due to a 'last GETFILE' above
187 ## (exception: user-defined properties and mappings), so we
188 ## have a filename, so now we load it if we haven't already.
189 ## If we have, return the cached results. The cache key is the
190 ## class and file to load.
191 ##
192718µs my $found = $Cache{$class, $file};
19375µs if ($found and ref($found) eq $class) {
1941300ns print STDERR "Returning cached '$file' for \\p{$type}\n" if DEBUG;
19514µs return $found;
196 }
197
198123.39ms $list = do $file; die $@ if $@;
199 }
200
20167µs $ListSorted = 1; ## we know that these lists are sorted
202 }
203
204157µs my $extras;
205156µs my $bits = $minbits;
206
2071522µs my $ORIG = $list;
20815619µs if ($list) {
20915917µs my @tmp = split(/^/m, $list);
210157µs my %seen;
21131.08ms294µs
# spent 59µs (23+36) within utf8::BEGIN@211 which was called: # once (23µs+36µs) by utf8::AUTOLOAD at line 211
no warnings;
# spent 59µs making 1 call to utf8::BEGIN@211 # spent 36µs making 1 call to warnings::unimport
212154.31ms24851.26ms $extras = join '', grep /^[^0-9a-fA-F]/, @tmp;
# spent 1.26ms making 2485 calls to utf8::CORE:match, avg 506ns/call
213 $list = join '',
214 map { $_->[1] }
21524737.61ms24732.90ms sort { $a->[0] <=> $b->[0] }
# spent 2.90ms making 2473 calls to utf8::CORE:match, avg 1µs/call
216495816.2ms24852.57ms map { /^([0-9a-fA-F]+)/; [ CORE::hex($1), $_ ] }
# spent 2.57ms making 2485 calls to utf8::CORE:match, avg 1µs/call
217154.77ms15626µs grep { /^([0-9a-fA-F]+)/ and not $seen{$1}++ } @tmp; # XXX doesn't do ranges right
# spent 626µs making 15 calls to utf8::CORE:sort, avg 42µs/call
218 }
219
2201512µs if ($none) {
221 my $hextra = sprintf "%04x", $none + 1;
222 $list =~ s/\tXXXX$/\t$hextra/mg;
223 }
224
2251521µs if ($minbits != 1 && $minbits < 32) { # not binary property
22611µs my $top = 0;
227119µs110µs while ($list =~ /^([0-9a-fA-F]+)(?:[\t]([0-9a-fA-F]+)?)(?:[ \t]([0-9a-fA-F]+))?/mg) {
# spent 10µs making 1 call to utf8::CORE:match
2281007904µs my $min = CORE::hex $1;
2291007480µs my $max = defined $2 ? CORE::hex $2 : $min;
2301007665µs my $val = defined $3 ? CORE::hex $3 : 0;
2311007609µs $val += $max - $min if defined $3;
23210074.02ms10071.79ms $top = $val if $val > $top;
# spent 1.79ms making 1007 calls to utf8::CORE:match, avg 2µs/call
233 }
2341800ns my $topbits =
235 $top > 0xffff ? 32 :
236 $top > 0xff ? 16 : 8;
23711µs $bits = $topbits if $bits < $topbits;
238 }
239
2401510µs my @extras;
2411532µs for my $x ($extras) {
2421551µs pos $x = 0;
24315120µs1524µs while ($x =~ /^([^0-9a-fA-F\n])(.*)/mg) {
# spent 24µs making 15 calls to utf8::CORE:match, avg 2µs/call
2441221µs my $char = $1;
2451216µs my $name = $2;
246123µs print STDERR "$1 => $2\n" if DEBUG;
2471296µs2431µs if ($char =~ /[-+!&]/) {
# spent 31µs making 24 calls to utf8::CORE:match, avg 1µs/call
248312µs my ($c,$t) = split(/::/, $name, 2); # bogus use of ::, really
24931µs my $subobj;
250336µs30s if ($c eq 'utf8') {
# spent 12.2ms making 3 calls to utf8::SWASHNEW, avg 4.08ms/call, recursion: max depth 1, sum of overlapping time 12.2ms
251 $subobj = utf8->SWASHNEW($t, "", $minbits, 0);
252 }
253 elsif (exists &$name) {
254 $subobj = utf8->SWASHNEW($name, "", $minbits, 0);
255 }
256 elsif ($c =~ /^([0-9a-fA-F]+)/) {
257 $subobj = utf8->SWASHNEW("", $c, $minbits, 0);
258 }
25933µs return $subobj unless ref $subobj;
26037µs push @extras, $name => $subobj;
26137µs $bits = $subobj->{BITS} if $bits < $subobj->{BITS};
262 }
263 }
264 }
265
266154µs print STDERR "CLASS = $class, TYPE => $type, BITS => $bits, NONE => $none\nEXTRAS =>\n$extras\nLIST =>\n$list\n" if DEBUG;
267
26815547µs my $SWASH = bless {
269 TYPE => $type,
270 BITS => $bits,
271 EXTRAS => $extras,
272 LIST => $list,
273 NONE => $none,
274 @extras,
275 } => $class;
276
2771530µs if ($file) {
278 $Cache{$class, $file} = $SWASH;
279 }
280
28115125µs return $SWASH;
282}
283
284# Now SWASHGET is recasted into a C function S_swash_get (see utf8.c).
285
28617µs1;
 
# spent 8.63ms within utf8::CORE:match which was called 8506 times, avg 1µs/call: # 2485 times (2.57ms+0s) by utf8::SWASHNEW at line 216, avg 1µs/call # 2485 times (1.26ms+0s) by utf8::SWASHNEW at line 212, avg 506ns/call # 2473 times (2.90ms+0s) by utf8::SWASHNEW at line 215, avg 1µs/call # 1007 times (1.79ms+0s) by utf8::SWASHNEW at line 232, avg 2µs/call # 24 times (31µs+0s) by utf8::SWASHNEW at line 247, avg 1µs/call # 15 times (24µs+0s) by utf8::SWASHNEW at line 243, avg 2µs/call # 7 times (22µs+0s) by utf8::SWASHNEW at line 73, avg 3µs/call # 7 times (22µs+0s) by utf8::SWASHNEW at line 98, avg 3µs/call # once (10µs+0s) by utf8::SWASHNEW at line 227 # once (6µs+0s) by utf8::SWASHNEW at line 151 # once (4µs+0s) by utf8::SWASHNEW at line 168
sub utf8::CORE:match; # opcode
# spent 626µs within utf8::CORE:sort which was called 15 times, avg 42µs/call: # 15 times (626µs+0s) by utf8::SWASHNEW at line 217, avg 42µs/call
sub utf8::CORE:sort; # opcode
# spent 78µs within utf8::CORE:subst which was called 32 times, avg 2µs/call: # 10 times (34µs+0s) by utf8::SWASHNEW at line 85, avg 3µs/call # 7 times (18µs+0s) by utf8::SWASHNEW at line 60, avg 3µs/call # 7 times (12µs+0s) by utf8::SWASHNEW at line 61, avg 2µs/call # 7 times (5µs+0s) by utf8::SWASHNEW at line 65, avg 743ns/call # once (8µs+0s) by utf8::SWASHNEW at line 136
sub utf8::CORE:subst; # opcode
# spent 1.70ms within utf8::decode which was called 1319 times, avg 1µs/call: # 1319 times (1.70ms+0s) by C4::Charset::NormalizeString at line 175 of /usr/share/koha/lib/C4/Charset.pm, avg 1µs/call
sub utf8::decode; # xsub
# spent 133µs within utf8::downgrade which was called 50 times, avg 3µs/call: # 50 times (133µs+0s) by Compress::Zlib::memGunzip at line 538 of Compress/Zlib.pm, avg 3µs/call
sub utf8::downgrade; # xsub
# spent 68µs within utf8::encode which was called 57 times, avg 1µs/call: # 51 times (57µs+0s) by C4::Templates::utf8_hashref at line 163 of /usr/share/koha/lib/C4/Templates.pm, avg 1µs/call # 6 times (10µs+0s) by JSON::PP::string_to_json at line 509 of JSON/PP.pm, avg 2µs/call
sub utf8::encode; # xsub
# spent 3.72ms within utf8::is_utf8 which was called 3790 times, avg 981ns/call: # 2284 times (2.26ms+0s) by C4::Templates::utf8_hashref at line 163 of /usr/share/koha/lib/C4/Templates.pm, avg 988ns/call # 1319 times (1.25ms+0s) by C4::Charset::NormalizeString at line 175 of /usr/share/koha/lib/C4/Charset.pm, avg 945ns/call # 149 times (140µs+0s) by C4::Templates::output at line 127 of /usr/share/koha/lib/C4/Templates.pm, avg 943ns/call # 27 times (56µs+0s) by Template::Filters::url_filter at line 303 of Template/Filters.pm, avg 2µs/call # 10 times (15µs+0s) by CGI::Util::escape at line 251 of CGI/Util.pm, avg 1µs/call # once (3µs+0s) by Template::Filters::uri_filter at line 278 of Template/Filters.pm
sub utf8::is_utf8; # xsub
Report produced by the NYTProf 4.04 Perl profiler, developed by Tim Bunce and Adam Kaplan.