← 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 13:01:18 2016
Reported on Fri Jan 8 13:01:34 2016

Filename/usr/share/perl5/DBIx/Class/Carp.pm
StatementsExecuted 147 statements in 1.72ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
171717490µs767µsDBIx::Class::Carp::::importDBIx::Class::Carp::import
1711246µs246µsDBIx::Class::Carp::::CORE:regcompDBIx::Class::Carp::CORE:regcomp (opcode)
171130µs30µsDBIx::Class::Carp::::CORE:qrDBIx::Class::Carp::CORE:qr (opcode)
11117µs30µsDBIx::Class::Carp::::BEGIN@4DBIx::Class::Carp::BEGIN@4
11112µs22µsDBIx::Class::Carp::::BEGIN@86DBIx::Class::Carp::BEGIN@86
1119µs19µsDBIx::Class::Carp::::BEGIN@5DBIx::Class::Carp::BEGIN@5
1114µs4µsDBIx::Class::Carp::::BEGIN@9DBIx::Class::Carp::BEGIN@9
0000s0sDBIx::Class::Carp::::__ANON__[:104]DBIx::Class::Carp::__ANON__[:104]
0000s0sDBIx::Class::Carp::::__ANON__[:121]DBIx::Class::Carp::__ANON__[:121]
0000s0sDBIx::Class::Carp::::__ANON__[:75]DBIx::Class::Carp::__ANON__[:75]
0000s0sDBIx::Class::Carp::::__ANON__[:93]DBIx::Class::Carp::__ANON__[:93]
0000s0sDBIx::Class::Carp::::__find_callerDBIx::Class::Carp::__find_caller
0000s0sDBIx::Class::Carp::::unimportDBIx::Class::Carp::unimport
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package # hide from pause
2 DBIx::Class::Carp;
3
4246µs244µs
# spent 30µs (17+14) within DBIx::Class::Carp::BEGIN@4 which was called: # once (17µs+14µs) by DBIx::Class::_Util::BEGIN@56 at line 4
use strict;
# spent 30µs making 1 call to DBIx::Class::Carp::BEGIN@4 # spent 14µs making 1 call to strict::import
5237µs229µs
# spent 19µs (9+10) within DBIx::Class::Carp::BEGIN@5 which was called: # once (9µs+10µs) by DBIx::Class::_Util::BEGIN@56 at line 5
use warnings;
# spent 19µs making 1 call to DBIx::Class::Carp::BEGIN@5 # spent 10µs making 1 call to warnings::import
6
7# load Carp early to prevent tickling of the ::Internal stash being
8# interpreted as "Carp is already loaded" by some braindead loader
92484µs14µs
# spent 4µs within DBIx::Class::Carp::BEGIN@9 which was called: # once (4µs+0s) by DBIx::Class::_Util::BEGIN@56 at line 9
use Carp ();
# spent 4µs making 1 call to DBIx::Class::Carp::BEGIN@9
1012µs$Carp::Internal{ (__PACKAGE__) }++;
11
12sub __find_caller {
13 my ($skip_pattern, $class) = @_;
14
15 my $skip_class_data = $class->_skip_namespace_frames
16 if ($class and $class->can('_skip_namespace_frames'));
17
18 $skip_pattern = qr/$skip_pattern|$skip_class_data/
19 if $skip_class_data;
20
21 my $fr_num = 1; # skip us and the calling carp*
22
23 my (@f, $origin);
24 while (@f = caller($fr_num++)) {
25
26 next if
27 ( $f[3] eq '(eval)' or $f[3] =~ /::__ANON__$/ );
28
29 $origin ||= (
30 $f[3] =~ /^ (.+) :: ([^\:]+) $/x
31 and
32 ! $Carp::Internal{$1}
33 and
34 $1 !~ /^(?: DBIx::Class::Storage::BlockRunner | Context::Preserve | Try::Tiny | Class::Accessor::Grouped | Class::C3::Componentised | Module::Runtime )$/x
35
36
37 and
38 $2 !~ /^(?: throw_exception | carp | carp_unique | carp_once | dbh_do | txn_do | with_deferred_fk_checks)$/x
39#############################
40 ) ? $f[3] : undef;
41
42 if (
43 $f[0]->can('_skip_namespace_frames')
44 and
45 my $extra_skip = $f[0]->_skip_namespace_frames
46 ) {
47 $skip_pattern = qr/$skip_pattern|$extra_skip/;
48 }
49
50 last if $f[0] !~ $skip_pattern;
51 }
52
53 my $site = @f # if empty - nothing matched - full stack
54 ? "at $f[1] line $f[2]"
55 : Carp::longmess()
56 ;
57 $origin ||= '{UNKNOWN}';
58
59 return (
60 $site,
61 $origin =~ /::/ ? "$origin(): " : "$origin: ", # cargo-cult from Carp::Clan
62 );
63};
64
65my $warn = sub {
66 my ($ln, @warn) = @_;
67 @warn = "Warning: something's wrong" unless @warn;
68
69 # back-compat with Carp::Clan - a warning ending with \n does
70 # not include caller info
71 warn (
72 @warn,
73 $warn[-1] =~ /\n$/ ? '' : " $ln\n"
74 );
7514µs};
76
77
# spent 767µs (490+276) within DBIx::Class::Carp::import which was called 17 times, avg 45µs/call: # once (45µs+29µs) by DBIx::Class::Componentised::BEGIN@10 at line 10 of DBIx/Class/Componentised.pm # once (46µs+27µs) by DBIx::Class::Schema::BEGIN@8 at line 8 of DBIx/Class/Schema.pm # once (37µs+20µs) by DBIx::Class::Storage::TxnScopeGuard::BEGIN@9 at line 9 of DBIx/Class/Storage/TxnScopeGuard.pm # once (35µs+19µs) by DBIx::Class::Row::BEGIN@11 at line 11 of DBIx/Class/Row.pm # once (31µs+23µs) by DBIx::Class::Relationship::Accessor::BEGIN@6 at line 6 of DBIx/Class/Relationship/Accessor.pm # once (35µs+14µs) by DBIx::Class::Relationship::HasOne::BEGIN@6 at line 6 of DBIx/Class/Relationship/HasOne.pm # once (26µs+18µs) by DBIx::Class::Storage::BEGIN@15 at line 15 of DBIx/Class/Storage.pm # once (29µs+16µs) by DBIx::Class::_Util::BEGIN@56 at line 56 of DBIx/Class/_Util.pm # once (28µs+14µs) by DBIx::Class::SQLMaker::BEGIN@42 at line 42 of DBIx/Class/SQLMaker.pm # once (28µs+13µs) by DBIx::Class::ResultSet::BEGIN@6 at line 6 of DBIx/Class/ResultSet.pm # once (24µs+16µs) by DBIx::Class::Storage::DBIHacks::BEGIN@20 at line 20 of DBIx/Class/Storage/DBIHacks.pm # once (26µs+13µs) by DBIx::Class::ResultSource::BEGIN@11 at line 11 of DBIx/Class/ResultSource.pm # once (25µs+11µs) by DBIx::Class::Storage::DBI::BEGIN@10 at line 10 of DBIx/Class/Storage/DBI.pm # once (22µs+12µs) by DBIx::Class::Relationship::ManyToMany::BEGIN@7 at line 7 of DBIx/Class/Relationship/ManyToMany.pm # once (18µs+11µs) by DBIx::Class::Relationship::CascadeActions::BEGIN@6 at line 6 of DBIx/Class/Relationship/CascadeActions.pm # once (19µs+10µs) by DBIx::Class::Storage::BlockRunner::BEGIN@8 at line 8 of DBIx/Class/Storage/BlockRunner.pm # once (17µs+10µs) by DBIx::Class::ResultSetColumn::BEGIN@7 at line 7 of DBIx/Class/ResultSetColumn.pm
sub import {
781718µs my (undef, $skip_pattern) = @_;
791716µs my $into = caller;
80
8117386µs34276µs $skip_pattern = $skip_pattern
# spent 246µs making 17 calls to DBIx::Class::Carp::CORE:regcomp, avg 14µs/call # spent 30µs making 17 calls to DBIx::Class::Carp::CORE:qr, avg 2µs/call
82 ? qr/ ^ $into $ | $skip_pattern /x
83 : qr/ ^ $into $ /x
84 ;
85
862331µs231µs
# spent 22µs (12+9) within DBIx::Class::Carp::BEGIN@86 which was called: # once (12µs+9µs) by DBIx::Class::_Util::BEGIN@56 at line 86
no strict 'refs';
# spent 22µs making 1 call to DBIx::Class::Carp::BEGIN@86 # spent 9µs making 1 call to strict::unimport
87
88 *{"${into}::carp"} = sub {
89 $warn->(
90 __find_caller($skip_pattern, $into),
91 @_
92 );
9317123µs };
94
951713µs my $fired = {};
96 *{"${into}::carp_once"} = sub {
97 return if $fired->{$_[0]};
98 $fired->{$_[0]} = 1;
99
100 $warn->(
101 __find_caller($skip_pattern, $into),
102 @_,
103 );
1041793µs };
105
106174µs my $seen;
107 *{"${into}::carp_unique"} = sub {
108 my ($ln, $calling) = __find_caller($skip_pattern, $into);
109 my $msg = join ('', $calling, @_);
110
111 # unique carping with a hidden caller makes no sense
112 $msg =~ s/\n+$//;
113
114 return if $seen->{$ln}{$msg};
115 $seen->{$ln}{$msg} = 1;
116
117 $warn->(
118 $ln,
119 $msg,
120 );
12117158µs };
122}
123
124sub unimport {
125 die (__PACKAGE__ . " does not implement unimport yet\n");
126}
127
12814µs1;
129
130__END__
 
# spent 30µs within DBIx::Class::Carp::CORE:qr which was called 17 times, avg 2µs/call: # 17 times (30µs+0s) by DBIx::Class::Carp::import at line 81, avg 2µs/call
sub DBIx::Class::Carp::CORE:qr; # opcode
# spent 246µs within DBIx::Class::Carp::CORE:regcomp which was called 17 times, avg 14µs/call: # 17 times (246µs+0s) by DBIx::Class::Carp::import at line 81, avg 14µs/call
sub DBIx::Class::Carp::CORE:regcomp; # opcode
Report produced by the NYTProf 6.02 Perl profiler, developed by Tim Bunce and Adam Kaplan.