← Index
NYTProf Performance Profile   « line view »
For flows_to_es.pl
  Run on Mon May 9 23:27:59 2016
Reported on Mon May 9 23:28:09 2016

Filename/opt/flows/lib/lib/perl5/Log/Any/Manager.pm
StatementsExecuted 63 statements in 1.44ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
211433µs1.16msLog::Any::Manager::::_require_dynamic Log::Any::Manager::_require_dynamic
21140µs1.29msLog::Any::Manager::::get_adapter Log::Any::Manager::get_adapter
21134µs1.21msLog::Any::Manager::::_choose_entry_for_category Log::Any::Manager::_choose_entry_for_category
11118µs18µsLog::Any::::BEGIN@1 Log::Any::BEGIN@1
21118µs19µsLog::Any::Manager::::_get_adapter_class Log::Any::Manager::_get_adapter_class
21116µs38µsLog::Any::Manager::::_new_adapter_for_entry Log::Any::Manager::_new_adapter_for_entry
11110µs21µsLog::Any::Manager::::BEGIN@36 Log::Any::Manager::BEGIN@36
1118µs13µsLog::Any::::BEGIN@3 Log::Any::BEGIN@3
1117µs20µsLog::Any::::BEGIN@2 Log::Any::BEGIN@2
1116µs6µsLog::Any::Manager::::new Log::Any::Manager::new
2112µs2µsLog::Any::Manager::::CORE:subst Log::Any::Manager::CORE:subst (opcode)
0000s0sLog::Any::Manager::_Guard::::DESTROYLog::Any::Manager::_Guard::DESTROY
0000s0sLog::Any::Manager::_Guard::::newLog::Any::Manager::_Guard::new
0000s0sLog::Any::Manager::::__ANON__[:103] Log::Any::Manager::__ANON__[:103]
0000s0sLog::Any::Manager::::_new_entry Log::Any::Manager::_new_entry
0000s0sLog::Any::Manager::::_reselect_matching_adapters Log::Any::Manager::_reselect_matching_adapters
0000s0sLog::Any::Manager::::remove Log::Any::Manager::remove
0000s0sLog::Any::Manager::::set Log::Any::Manager::set
0000s0sLog::Any::Manager::::set_default Log::Any::Manager::set_default
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1252µs118µs
# spent 18µs within Log::Any::BEGIN@1 which was called: # once (18µs+0s) by Log::Any::BEGIN@10 at line 1
use 5.008001;
# spent 18µs making 1 call to Log::Any::BEGIN@1
2226µs234µs
# spent 20µs (7+13) within Log::Any::BEGIN@2 which was called: # once (7µs+13µs) by Log::Any::BEGIN@10 at line 2
use strict;
# spent 20µs making 1 call to Log::Any::BEGIN@2 # spent 13µs making 1 call to strict::import
32178µs217µs
# spent 13µs (8+5) within Log::Any::BEGIN@3 which was called: # once (8µs+5µs) by Log::Any::BEGIN@10 at line 3
use warnings;
# spent 13µs making 1 call to Log::Any::BEGIN@3 # spent 5µs making 1 call to warnings::import
4
5package Log::Any::Manager;
6
71800nsour $VERSION = '1.040';
8
9
# spent 6µs within Log::Any::Manager::new which was called: # once (6µs+0s) by Search::Elasticsearch::Logger::LogAny::BEGIN@8 at line 27 of /opt/flows/lib/lib/perl5/Log/Any.pm
sub new {
101500ns my $class = shift;
1112µs my $self = {
12 entries => [],
13 category_cache => {},
14 default_adapter => {},
15 };
1611µs bless $self, $class;
17
1816µs return $self;
19}
20
21
# spent 1.29ms (40µs+1.25) within Log::Any::Manager::get_adapter which was called 2 times, avg 644µs/call: # 2 times (40µs+1.25ms) by Log::Any::get_logger at line 82 of /opt/flows/lib/lib/perl5/Log/Any.pm, avg 644µs/call
sub get_adapter {
2221µs my ( $self, $category ) = @_;
23
24 # Create a new adapter for this category if it is not already in cache
25 #
2629µs my $category_cache = $self->{category_cache};
2723µs if ( !defined( $category_cache->{$category} ) ) {
2826µs21.21ms my $entry = $self->_choose_entry_for_category($category);
# spent 1.21ms making 2 calls to Log::Any::Manager::_choose_entry_for_category, avg 605µs/call
2926µs238µs my $adapter = $self->_new_adapter_for_entry( $entry, $category );
# spent 38µs making 2 calls to Log::Any::Manager::_new_adapter_for_entry, avg 19µs/call
3025µs $category_cache->{$category} = { entry => $entry, adapter => $adapter };
31 }
3227µs return $category_cache->{$category}->{adapter};
33}
34
35{
363961µs232µs
# spent 21µs (10+11) within Log::Any::Manager::BEGIN@36 which was called: # once (10µs+11µs) by Log::Any::BEGIN@10 at line 36
no warnings 'once';
# spent 21µs making 1 call to Log::Any::Manager::BEGIN@36 # spent 11µs making 1 call to warnings::unimport
3712µs *get_logger = \&get_adapter; # backwards compatibility
38}
39
40
# spent 1.21ms (34µs+1.18) within Log::Any::Manager::_choose_entry_for_category which was called 2 times, avg 605µs/call: # 2 times (34µs+1.18ms) by Log::Any::Manager::get_adapter at line 28, avg 605µs/call
sub _choose_entry_for_category {
4121µs my ( $self, $category ) = @_;
42
4324µs foreach my $entry ( @{ $self->{entries} } ) {
44 if ( $category =~ $entry->{pattern} ) {
45 return $entry;
46 }
47 }
48 # nothing requested so fallback to default
4927µs219µs my $default = $self->{default_adapter}{$category}
# spent 19µs making 2 calls to Log::Any::Manager::_get_adapter_class, avg 10µs/call
50 || [ $self->_get_adapter_class("Null"), [] ];
5122µs my ($adapter_class, $adapter_params) = @$default;
5225µs21.16ms _require_dynamic($adapter_class);
# spent 1.16ms making 2 calls to Log::Any::Manager::_require_dynamic, avg 579µs/call
53 return {
54211µs adapter_class => $adapter_class,
55 adapter_params => $adapter_params,
56 };
57}
58
59
# spent 38µs (16+22) within Log::Any::Manager::_new_adapter_for_entry which was called 2 times, avg 19µs/call: # 2 times (16µs+22µs) by Log::Any::Manager::get_adapter at line 29, avg 19µs/call
sub _new_adapter_for_entry {
6022µs my ( $self, $entry, $category ) = @_;
61
62 return $entry->{adapter_class}
63214µs222µs ->new( @{ $entry->{adapter_params} }, category => $category );
# spent 22µs making 2 calls to Log::Any::Adapter::Base::new, avg 11µs/call
64}
65
66sub set_default {
67 my ( $self, $category, $adapter_name, @adapter_params ) = @_;
68 my $adapter_class = $self->_get_adapter_class($adapter_name);
69 $self->{default_adapter}{$category} = [$adapter_class, \@adapter_params];
70}
71
72sub set {
73 my $self = shift;
74 my $options;
75 if ( ref( $_[0] ) eq 'HASH' ) {
76 $options = shift(@_);
77 }
78 my ( $adapter_name, @adapter_params ) = @_;
79
80 unless ( defined($adapter_name) && $adapter_name =~ /\S/ ) {
81 require Carp;
82 Carp::croak("expected adapter name");
83 }
84
85 my $pattern = $options->{category};
86 if ( !defined($pattern) ) {
87 $pattern = qr/.*/;
88 }
89 elsif ( !ref($pattern) ) {
90 $pattern = qr/^\Q$pattern\E$/;
91 }
92
93 my $adapter_class = $self->_get_adapter_class($adapter_name);
94 _require_dynamic($adapter_class);
95
96 my $entry = $self->_new_entry( $pattern, $adapter_class, \@adapter_params );
97 unshift( @{ $self->{entries} }, $entry );
98
99 $self->_reselect_matching_adapters($pattern);
100
101 if ( my $lex_ref = $options->{lexically} ) {
102 $$lex_ref = Log::Any::Manager::_Guard->new(
103 sub { $self->remove($entry) unless _in_global_destruction() } );
104 }
105
106 return $entry;
107}
108
109sub remove {
110 my ( $self, $entry ) = @_;
111
112 my $pattern = $entry->{pattern};
113 $self->{entries} = [ grep { $_ ne $entry } @{ $self->{entries} } ];
114 $self->_reselect_matching_adapters($pattern);
115}
116
117sub _new_entry {
118 my ( $self, $pattern, $adapter_class, $adapter_params ) = @_;
119
120 return {
121 pattern => $pattern,
122 adapter_class => $adapter_class,
123 adapter_params => $adapter_params,
124 };
125}
126
127sub _reselect_matching_adapters {
128 my ( $self, $pattern ) = @_;
129
130 return if _in_global_destruction();
131
132 # Reselect adapter for each category matching $pattern
133 #
134 while ( my ( $category, $category_info ) =
135 each( %{ $self->{category_cache} } ) )
136 {
137 my $new_entry = $self->_choose_entry_for_category($category);
138 if ( $new_entry ne $category_info->{entry} ) {
139 my $new_adapter =
140 $self->_new_adapter_for_entry( $new_entry, $category );
141 %{ $category_info->{adapter} } = %$new_adapter;
142 bless( $category_info->{adapter}, ref($new_adapter) );
143 $category_info->{entry} = $new_entry;
144 }
145 }
146}
147
148
# spent 19µs (18+2) within Log::Any::Manager::_get_adapter_class which was called 2 times, avg 10µs/call: # 2 times (18µs+2µs) by Log::Any::Manager::_choose_entry_for_category at line 49, avg 10µs/call
sub _get_adapter_class {
14921µs my ( $self, $adapter_name ) = @_;
1502700ns return $Log::Any::OverrideDefaultAdapterClass if $Log::Any::OverrideDefaultAdapterClass;
151210µs22µs $adapter_name =~ s/^Log:://; # Log::Dispatch -> Dispatch, etc.
# spent 2µs making 2 calls to Log::Any::Manager::CORE:subst, avg 750ns/call
15224µs my $adapter_class = (
153 substr( $adapter_name, 0, 1 ) eq '+'
154 ? substr( $adapter_name, 1 )
155 : "Log::Any::Adapter::$adapter_name"
156 );
15727µs return $adapter_class;
158}
159
160# This is adapted from the pure perl parts of Devel::GlobalDestruction
16114µsif ( defined ${^GLOBAL_PHASE} ) {
162133µs eval 'sub _in_global_destruction () { ${^GLOBAL_PHASE} eq q[DESTRUCT] }; 1' ## no critic
# spent 2µs executing statements in string eval
163 or die $@;
164}
165else {
166 require B;
167 my $started = !B::main_start()->isa(q[B::NULL]);
168 unless ($started) {
169 eval '0 && $started; CHECK { $started = 1 }; 1' ## no critic
170 or die $@;
171 }
172 eval ## no critic
173 '0 && $started; sub _in_global_destruction () { $started && B::main_start()->isa(q[B::NULL]) }; 1'
174 or die $@;
175}
176
177# XXX not DRY and not a great way to do this, but oh, well.
178
# spent 1.16ms (433µs+724µs) within Log::Any::Manager::_require_dynamic which was called 2 times, avg 579µs/call: # 2 times (433µs+724µs) by Log::Any::Manager::_choose_entry_for_category at line 52, avg 579µs/call
sub _require_dynamic {
17921µs my ($class) = @_;
180
181226µs25µs return 1 if $class->can('new'); # duck-type that class is loaded
# spent 5µs making 2 calls to UNIVERSAL::can, avg 3µs/call
182
183136µs unless ( defined( eval "require $class; 1" ) )
# spent 77µs executing statements in string eval
184 { ## no critic (ProhibitStringyEval)
185 die $@;
186 }
187}
188
189package # hide from PAUSE
190 Log::Any::Manager::_Guard;
191
192sub new { bless $_[1], $_[0] }
193
194sub DESTROY { $_[0]->() }
195
19616µs1;
 
# spent 2µs within Log::Any::Manager::CORE:subst which was called 2 times, avg 750ns/call: # 2 times (2µs+0s) by Log::Any::Manager::_get_adapter_class at line 151, avg 750ns/call
sub Log::Any::Manager::CORE:subst; # opcode
Report produced by the NYTProf 5.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.