← Index
NYTProf Performance Profile   « block view • line view • sub view »
For C:/lo/libo-master/solenv/bin/make_installer.pl
  Run on Mon Sep 24 00:52:54 2012
Reported on Mon Sep 24 07:34:46 2012

Filename/usr/lib/perl5/5.14/Carp.pm
StatementsExecuted 417 statements in 5.31ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
111232µs247µsCarp::::BEGIN@3Carp::BEGIN@3
211188µs549µsCarp::::short_error_locCarp::short_error_loc
1121148µs325µsCarp::::trustsCarp::trusts
211124µs218µsCarp::::caller_infoCarp::caller_info
1421113µs177µsCarp::::get_statusCarp::get_status
11169µs502µsCarp::::carpCarp::carp
71164µs64µsCarp::::trusts_directlyCarp::trusts_directly
21159µs276µsCarp::::ret_summaryCarp::ret_summary
173155µs55µsCarp::::_cgcCarp::_cgc
22144µs913µsCarp::::shortmessCarp::shortmess
11142µs71µsCarp::::format_argCarp::format_arg
21131µs856µsCarp::::shortmess_heavyCarp::shortmess_heavy
11131µs82µsCarp::::BEGIN@341Carp::BEGIN@341
21118µs18µsCarp::::get_subnameCarp::get_subname
11117µs43µsCarp::::BEGIN@4Carp::BEGIN@4
11116µs52µsCarp::::BEGIN@342Carp::BEGIN@342
11115µs495µsCarp::::croakCarp::croak
11115µs52µsCarp::::BEGIN@46Carp::BEGIN@46
11113µs13µsCarp::::str_len_trimCarp::str_len_trim
2218µs8µsCarp::::CORE:substCarp::CORE:subst (opcode)
1115µs5µsCarp::::CORE:matchCarp::CORE:match (opcode)
0000s0sCarp::::cluckCarp::cluck
0000s0sCarp::::confessCarp::confess
0000s0sCarp::::export_failCarp::export_fail
0000s0sCarp::::long_error_locCarp::long_error_loc
0000s0sCarp::::longmessCarp::longmess
0000s0sCarp::::longmess_heavyCarp::longmess_heavy
0000s0sCarp::::ret_backtraceCarp::ret_backtrace
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Carp;
2
3273µs2263µs
# spent 247µs (232+15) within Carp::BEGIN@3 which was called: # once (232µs+15µs) by DynaLoader::croak at line 3
use strict;
# spent 247µs making 1 call to Carp::BEGIN@3 # spent 15µs making 1 call to strict::import
42431µs269µs
# spent 43µs (17+26) within Carp::BEGIN@4 which was called: # once (17µs+26µs) by DynaLoader::croak at line 4
use warnings;
# spent 43µs making 1 call to Carp::BEGIN@4 # spent 26µs making 1 call to warnings::import
5
612µsour $VERSION = '1.20';
7
811µsour $MaxEvalLen = 0;
91500nsour $Verbose = 0;
101600nsour $CarpLevel = 0;
111500nsour $MaxArgLen = 64; # How much of each argument to print. 0 = all.
121500nsour $MaxArgNums = 8; # How many arguments to print. 0 = all.
13
141500nsrequire Exporter;
15115µsour @ISA = ('Exporter');
1613µsour @EXPORT = qw(confess croak carp);
1714µsour @EXPORT_OK = qw(cluck verbose longmess shortmess);
1811µsour @EXPORT_FAIL = qw(verbose); # hook to enable verbose mode
19
20# The members of %Internal are packages that are internal to perl.
21# Carp will not report errors from within these packages if it
22# can. The members of %CarpInternal are internal to Perl's warning
23# system. Carp will not report errors from within these packages
24# either, and will not report calls *to* these packages for carp and
25# croak. They replace $CarpLevel, which is deprecated. The
26# $Max(EvalLen|(Arg(Len|Nums)) variables are used to specify how the eval
27# text and function arguments should be formatted when printed.
28
2910sour %CarpInternal;
3010sour %Internal;
31
32# disable these by default, so they can live w/o require Carp
3312µs$CarpInternal{Carp}++;
341500ns$CarpInternal{warnings}++;
3511µs$Internal{Exporter}++;
361500ns$Internal{'Exporter::Heavy'}++;
37
38# if the caller specifies verbose usage ("perl -MCarp=verbose script.pl")
39# then the following method will be called by the Exporter which knows
40# to do this thanks to @EXPORT_FAIL, above. $_[1] will contain the word
41# 'verbose'.
42
43sub export_fail { shift; $Verbose = shift if $_[0] eq 'verbose'; @_ }
44
45
# spent 55µs within Carp::_cgc which was called 17 times, avg 3µs/call: # 13 times (36µs+0s) by Carp::short_error_loc at line 275, avg 3µs/call # 2 times (13µs+0s) by Carp::shortmess at line 72, avg 7µs/call # 2 times (6µs+0s) by Carp::caller_info at line 87, avg 3µs/call
sub _cgc {
4623.37ms289µs
# spent 52µs (15+37) within Carp::BEGIN@46 which was called: # once (15µs+37µs) by DynaLoader::croak at line 46
no strict 'refs';
# spent 52µs making 1 call to Carp::BEGIN@46 # spent 37µs making 1 call to strict::unimport
471723µs return \&{"CORE::GLOBAL::caller"} if defined &{"CORE::GLOBAL::caller"};
481766µs return;
49}
50
51sub longmess {
52 # Icky backwards compatibility wrapper. :-(
53 #
54 # The story is that the original implementation hard-coded the
55 # number of call levels to go back, so calls to longmess were off
56 # by one. Other code began calling longmess and expecting this
57 # behaviour, so the replacement has to emulate that behaviour.
58 my $cgc = _cgc();
59 my $call_pack = $cgc ? $cgc->() : caller();
60 if ( $Internal{$call_pack} or $CarpInternal{$call_pack} ) {
61 return longmess_heavy(@_);
62 }
63 else {
64 local $CarpLevel = $CarpLevel + 1;
65 return longmess_heavy(@_);
66 }
67}
68
691500nsour @CARP_NOT;
70
71
# spent 913µs (44+869) within Carp::shortmess which was called 2 times, avg 457µs/call: # once (24µs+456µs) by Carp::croak at line 79 # once (20µs+413µs) by Carp::carp at line 81
sub shortmess {
7226µs213µs my $cgc = _cgc();
# spent 13µs making 2 calls to Carp::_cgc, avg 7µs/call
73
74 # Icky backwards compatibility wrapper. :-(
75212µs local @CARP_NOT = $cgc ? $cgc->() : caller();
76217µs2856µs shortmess_heavy(@_);
# spent 856µs making 2 calls to Carp::shortmess_heavy, avg 428µs/call
77}
78
79144µs1480µs
# spent 495µs (15+480) within Carp::croak which was called: # once (15µs+480µs) by DynaLoader::croak at line 98 of DynaLoader.pm
sub croak { die shortmess @_ }
# spent 480µs making 1 call to Carp::shortmess
80sub confess { die longmess @_ }
81171µs1433µs
# spent 502µs (69+433) within Carp::carp which was called: # once (69µs+433µs) by Exporter::Heavy::__ANON__[/usr/lib/perl5/5.14/Exporter/Heavy.pm:52] at line 47 of Exporter/Heavy.pm
sub carp { warn shortmess @_ }
# spent 433µs making 1 call to Carp::shortmess
82sub cluck { warn longmess @_ }
83
84
# spent 218µs (124+94) within Carp::caller_info which was called 2 times, avg 109µs/call: # 2 times (124µs+94µs) by Carp::ret_summary at line 263, avg 109µs/call
sub caller_info {
8523µs my $i = shift(@_) + 1;
8622µs my %call_info;
8724µs26µs my $cgc = _cgc();
# spent 6µs making 2 calls to Carp::_cgc, avg 3µs/call
88 {
8926µs package DB;
9024µs
- -
92233µs
- -
9622µs unless ( defined $call_info{pack} ) {
97 return ();
98 }
99
10029µs218µs my $sub_name = Carp::get_subname( \%call_info );
# spent 18µs making 2 calls to Carp::get_subname, avg 9µs/call
10122µs if ( $call_info{has_args} ) {
1021600ns my @args;
10315µs if ( @DB::args == 1
104 && ref $DB::args[0] eq ref \$i
105 && $DB::args[0] == \$i ) {
106 @DB::args = (); # Don't let anyone see the address of $i
107 local $@;
108 my $where = eval {
109 my $func = $cgc or return '';
110 my $gv = B::svref_2object($func)->GV;
111 my $package = $gv->STASH->NAME;
112 my $subname = $gv->NAME;
113 return unless defined $package && defined $subname;
114
115 # returning CORE::GLOBAL::caller isn't useful for tracing the cause:
116 return if $package eq 'CORE::GLOBAL' && $subname eq 'caller';
117 " in &${package}::$subname";
118 } // '';
119 @args
120 = "** Incomplete caller override detected$where; \@DB::args were not set **";
121 }
122 else {
12328µs171µs @args = map { Carp::format_arg($_) } @DB::args;
# spent 71µs making 1 call to Carp::format_arg
124 }
12511µs if ( $MaxArgNums and @args > $MaxArgNums )
126 { # More than we want to show?
127 $#args = $MaxArgNums;
128 push @args, '...';
129 }
130
131 # Push the args onto the subroutine
13214µs $sub_name .= '(' . join( ', ', @args ) . ')';
133 }
13424µs $call_info{sub_name} = $sub_name;
135230µs return wantarray() ? %call_info : \%call_info;
136}
137
138# Transform an argument to a function into a string.
139
# spent 71µs (42+28) within Carp::format_arg which was called: # once (42µs+28µs) by Carp::caller_info at line 123
sub format_arg {
14011µs my $arg = shift;
1411500ns if ( ref($arg) ) {
142 $arg = defined($overload::VERSION) ? overload::StrVal($arg) : "$arg";
143 }
14412µs if ( defined($arg) ) {
145111µs12µs $arg =~ s/'/\\'/g;
# spent 2µs making 1 call to Carp::CORE:subst
14614µs113µs $arg = str_len_trim( $arg, $MaxArgLen );
# spent 13µs making 1 call to Carp::str_len_trim
147
148 # Quote it?
149115µs15µs $arg = "'$arg'" unless $arg =~ /^-?[0-9.]+\z/;
# spent 5µs making 1 call to Carp::CORE:match
150 } # 0-9, not \d, as \d will try to
151 else { # load Unicode tables
152 $arg = 'undef';
153 }
154
155 # The following handling of "control chars" is direct from
156 # the original code - it is broken on Unicode though.
157 # Suggestions?
158 utf8::is_utf8($arg)
159117µs28µs or $arg =~ s/([[:cntrl:]]|[[:^ascii:]])/sprintf("\\x{%x}",ord($1))/eg;
# spent 6µs making 1 call to Carp::CORE:subst # spent 3µs making 1 call to utf8::is_utf8
16016µs return $arg;
161}
162
163# Takes an inheritance cache and a package and returns
164# an anon hash of known inheritances and anon array of
165# inheritances which consequences have not been figured
166# for.
167
# spent 177µs (113+64) within Carp::get_status which was called 14 times, avg 13µs/call: # 11 times (95µs+57µs) by Carp::trusts at line 323, avg 14µs/call # 3 times (18µs+8µs) by Carp::trusts at line 330, avg 9µs/call
sub get_status {
168146µs my $cache = shift;
169148µs my $pkg = shift;
1701447µs764µs $cache->{$pkg} ||= [ { $pkg => $pkg }, [ trusts_directly($pkg) ] ];
# spent 64µs making 7 calls to Carp::trusts_directly, avg 9µs/call
1711458µs return @{ $cache->{$pkg} };
172}
173
174# Takes the info from caller() and figures out the name of
175# the sub/require/eval
176
# spent 18µs within Carp::get_subname which was called 2 times, avg 9µs/call: # 2 times (18µs+0s) by Carp::caller_info at line 100, avg 9µs/call
sub get_subname {
17722µs my $info = shift;
17823µs if ( defined( $info->{evaltext} ) ) {
17912µs my $eval = $info->{evaltext};
18019µs if ( $info->{is_require} ) {
181 return "require $eval";
182 }
183 else {
184 $eval =~ s/([\\\'])/\\$1/g;
185 return "eval '" . str_len_trim( $eval, $MaxEvalLen ) . "'";
186 }
187 }
188
18916µs return ( $info->{sub} eq '(eval)' ) ? 'eval {...}' : $info->{sub};
190}
191
192# Figures out what call (from the point of view of the caller)
193# the long error backtrace should start at.
194sub long_error_loc {
195 my $i;
196 my $lvl = $CarpLevel;
197 {
198 ++$i;
199 my $cgc = _cgc();
200 my $pkg = $cgc ? $cgc->($i) : caller($i);
201 unless ( defined($pkg) ) {
202
203 # This *shouldn't* happen.
204 if (%Internal) {
205 local %Internal;
206 $i = long_error_loc();
207 last;
208 }
209 else {
210
211 # OK, now I am irritated.
212 return 2;
213 }
214 }
215 redo if $CarpInternal{$pkg};
216 redo unless 0 > --$lvl;
217 redo if $Internal{$pkg};
218 }
219 return $i - 1;
220}
221
222sub longmess_heavy {
223 return @_ if ref( $_[0] ); # don't break references as exceptions
224 my $i = long_error_loc();
225 return ret_backtrace( $i, @_ );
226}
227
228# Returns a full stack backtrace starting from where it is
229# told.
230sub ret_backtrace {
231 my ( $i, @error ) = @_;
232 my $mess;
233 my $err = join '', @error;
234 $i++;
235
236 my $tid_msg = '';
237 if ( defined &threads::tid ) {
238 my $tid = threads->tid;
239 $tid_msg = " thread $tid" if $tid;
240 }
241
242 my %i = caller_info($i);
243 $mess = "$err at $i{file} line $i{line}$tid_msg\n";
244
245 while ( my %i = caller_info( ++$i ) ) {
246 $mess .= "\t$i{sub_name} called at $i{file} line $i{line}$tid_msg\n";
247 }
248
249 return $mess;
250}
251
252
# spent 276µs (59+218) within Carp::ret_summary which was called 2 times, avg 138µs/call: # 2 times (59µs+218µs) by Carp::shortmess_heavy at line 295, avg 138µs/call
sub ret_summary {
25324µs my ( $i, @error ) = @_;
25426µs my $err = join '', @error;
25521µs $i++;
256
25722µs my $tid_msg = '';
25823µs if ( defined &threads::tid ) {
259 my $tid = threads->tid;
260 $tid_msg = " thread $tid" if $tid;
261 }
262
263216µs2218µs my %i = caller_info($i);
# spent 218µs making 2 calls to Carp::caller_info, avg 109µs/call
264226µs return "$err at $i{file} line $i{line}$tid_msg\n";
265}
266
267
# spent 549µs (188+361) within Carp::short_error_loc which was called 2 times, avg 274µs/call: # 2 times (188µs+361µs) by Carp::shortmess_heavy at line 294, avg 274µs/call
sub short_error_loc {
268 # You have to create your (hash)ref out here, rather than defaulting it
269 # inside trusts *on a lexical*, as you want it to persist across calls.
270 # (You can default it on $_[2], but that gets messy)
27123µs my $cache = {};
27222µs my $i = 1;
27321µs my $lvl = $CarpLevel;
274 {
2751531µs1336µs my $cgc = _cgc();
# spent 36µs making 13 calls to Carp::_cgc, avg 3µs/call
2761314µs my $called = $cgc ? $cgc->($i) : caller($i);
277134µs $i++;
2781314µs my $caller = $cgc ? $cgc->($i) : caller($i);
279
280135µs return 0 unless defined($caller); # What happened?
281139µs redo if $Internal{$caller};
282108µs redo if $CarpInternal{$caller};
28384µs redo if $CarpInternal{$called};
284719µs7147µs redo if trusts( $called, $caller, $cache );
# spent 147µs making 7 calls to Carp::trusts, avg 21µs/call
285412µs4178µs redo if trusts( $caller, $called, $cache );
# spent 178µs making 4 calls to Carp::trusts, avg 44µs/call
28634µs redo unless 0 > --$lvl;
287 }
288227µs return $i - 1;
289}
290
291
# spent 856µs (31+825) within Carp::shortmess_heavy which was called 2 times, avg 428µs/call: # 2 times (31µs+825µs) by Carp::shortmess at line 76, avg 428µs/call
sub shortmess_heavy {
29222µs return longmess_heavy(@_) if $Verbose;
29322µs return @_ if ref( $_[0] ); # don't break references as exceptions
29427µs2549µs my $i = short_error_loc();
# spent 549µs making 2 calls to Carp::short_error_loc, avg 274µs/call
295216µs2276µs if ($i) {
# spent 276µs making 2 calls to Carp::ret_summary, avg 138µs/call
296 ret_summary( $i, @_ );
297 }
298 else {
299 longmess_heavy(@_);
300 }
301}
302
303# If a string is too long, trims it with ...
304
# spent 13µs within Carp::str_len_trim which was called: # once (13µs+0s) by Carp::format_arg at line 146
sub str_len_trim {
30511µs my $str = shift;
3061600ns my $max = shift || 0;
30718µs if ( 2 < $max and $max < length($str) ) {
308 substr( $str, $max - 3 ) = '...';
309 }
31017µs return $str;
311}
312
313# Takes two packages and an optional cache. Says whether the
314# first inherits from the second.
315#
316# Recursive versions of this have to work to avoid certain
317# possible endless loops, and when following long chains of
318# inheritance are less efficient.
319
# spent 325µs (148+177) within Carp::trusts which was called 11 times, avg 30µs/call: # 7 times (75µs+72µs) by Carp::short_error_loc at line 284, avg 21µs/call # 4 times (72µs+106µs) by Carp::short_error_loc at line 285, avg 44µs/call
sub trusts {
320118µs my $child = shift;
321116µs my $parent = shift;
322115µs my $cache = shift;
3231131µs11152µs my ( $known, $partial ) = get_status( $cache, $child );
# spent 152µs making 11 calls to Carp::get_status, avg 14µs/call
324
325 # Figure out consequences until we have an answer
3261113µs while ( @$partial and not exists $known->{$parent} ) {
32733µs my $anc = shift @$partial;
32832µs next if exists $known->{$anc};
32932µs $known->{$anc}++;
33038µs326µs my ( $anc_knows, $anc_partial ) = get_status( $cache, $anc );
# spent 26µs making 3 calls to Carp::get_status, avg 9µs/call
33137µs my @found = keys %$anc_knows;
33233µs @$known{@found} = ();
33335µs push @$partial, @$anc_partial;
334 }
3351151µs return exists $known->{$parent};
336}
337
338# Takes a package and gives a list of those trusted directly
339
# spent 64µs within Carp::trusts_directly which was called 7 times, avg 9µs/call: # 7 times (64µs+0s) by Carp::get_status at line 170, avg 9µs/call
sub trusts_directly {
34075µs my $class = shift;
341267µs2132µs
# spent 82µs (31+51) within Carp::BEGIN@341 which was called: # once (31µs+51µs) by DynaLoader::croak at line 341
no strict 'refs';
# spent 82µs making 1 call to Carp::BEGIN@341 # spent 51µs making 1 call to strict::unimport
3422248µs288µs
# spent 52µs (16+36) within Carp::BEGIN@342 which was called: # once (16µs+36µs) by DynaLoader::croak at line 342
no warnings 'once';
# spent 52µs making 1 call to Carp::BEGIN@342 # spent 36µs making 1 call to warnings::unimport
343 return @{"$class\::CARP_NOT"}
344 ? @{"$class\::CARP_NOT"}
345774µs : @{"$class\::ISA"};
346}
347
348154µs1;
349
350__END__
 
# spent 5µs within Carp::CORE:match which was called: # once (5µs+0s) by Carp::format_arg at line 149
sub Carp::CORE:match; # opcode
# spent 8µs within Carp::CORE:subst which was called 2 times, avg 4µs/call: # once (6µs+0s) by Carp::format_arg at line 159 # once (2µs+0s) by Carp::format_arg at line 145
sub Carp::CORE:subst; # opcode
Report produced by the NYTProf 4.09 Perl profiler, developed by Tim Bunce and Adam Kaplan.