← 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/Proxy.pm
StatementsExecuted 168 statements in 1.09ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
41133µs38µsLog::Any::Proxy::::__ANON__[:80] Log::Any::Proxy::__ANON__[:80]
21126µs29µsLog::Any::Proxy::::new Log::Any::Proxy::new
11119µs19µsLog::Any::Adapter::Util::::BEGIN@1Log::Any::Adapter::Util::BEGIN@1
21118µs21µsLog::Any::Proxy::::__ANON__[:61] Log::Any::Proxy::__ANON__[:61]
11112µs17µsLog::Any::Adapter::Util::::BEGIN@3Log::Any::Adapter::Util::BEGIN@3
11110µs11µsLog::Any::Proxy::::__ANON__[:72] Log::Any::Proxy::__ANON__[:72]
1119µs21µsLog::Any::Proxy::::BEGIN@43 Log::Any::Proxy::BEGIN@43
1118µs20µsLog::Any::Proxy::::BEGIN@57 Log::Any::Proxy::BEGIN@57
1118µs21µsLog::Any::Adapter::Util::::BEGIN@2Log::Any::Adapter::Util::BEGIN@2
1115µs5µsLog::Any::Proxy::::BEGIN@10 Log::Any::Proxy::BEGIN@10
2112µs2µsLog::Any::Proxy::::init Log::Any::Proxy::init
0000s0sLog::Any::Proxy::::__ANON__[:44] Log::Any::Proxy::__ANON__[:44]
0000s0sLog::Any::Proxy::::_default_formatter Log::Any::Proxy::_default_formatter
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1252µs119µs
# spent 19µs within Log::Any::Adapter::Util::BEGIN@1 which was called: # once (19µs+0s) by Log::Any::Adapter::Util::require_dynamic at line 1
use 5.008001;
# spent 19µs making 1 call to Log::Any::Adapter::Util::BEGIN@1
2227µs235µs
# spent 21µs (8+14) within Log::Any::Adapter::Util::BEGIN@2 which was called: # once (8µs+14µs) by Log::Any::Adapter::Util::require_dynamic at line 2
use strict;
# spent 21µs making 1 call to Log::Any::Adapter::Util::BEGIN@2 # spent 14µs making 1 call to strict::import
3251µs222µs
# spent 17µs (12+5) within Log::Any::Adapter::Util::BEGIN@3 which was called: # once (12µs+5µs) by Log::Any::Adapter::Util::require_dynamic at line 3
use warnings;
# spent 17µs making 1 call to Log::Any::Adapter::Util::BEGIN@3 # spent 5µs making 1 call to warnings::import
4
5package Log::Any::Proxy;
6
7# ABSTRACT: Log::Any generator proxy object
81700nsour $VERSION = '1.040';
9
102234µs15µs
# spent 5µs within Log::Any::Proxy::BEGIN@10 which was called: # once (5µs+0s) by Log::Any::Adapter::Util::require_dynamic at line 10
use Log::Any::Adapter::Util ();
# spent 5µs making 1 call to Log::Any::Proxy::BEGIN@10
11
12sub _default_formatter {
13 my ( $cat, $lvl, $format, @params ) = @_;
14 return $format->() if ref($format) eq 'CODE';
15 my @new_params =
16 map {
17 !defined($_) ? '<undef>'
18 : ref($_) ? Log::Any::Adapter::Util::dump_one_line($_)
19 : $_
20 } @params;
21 return sprintf( $format, @new_params );
22}
23
24
# spent 29µs (26+2) within Log::Any::Proxy::new which was called 2 times, avg 14µs/call: # 2 times (26µs+2µs) by Log::Any::get_logger at line 85 of /opt/flows/lib/lib/perl5/Log/Any.pm, avg 14µs/call
sub new {
2521µs my $class = shift;
2626µs my $self = { formatter => \&_default_formatter, @_ };
2726µs unless ( $self->{adapter} ) {
28 require Carp;
29 Carp::croak("$class requires an 'adapter' parameter");
30 }
312800ns unless ( $self->{category} ) {
32 require Carp;
33 Carp::croak("$class requires an 'category' parameter")
34 }
3522µs bless $self, $class;
3623µs22µs $self->init(@_);
# spent 2µs making 2 calls to Log::Any::Proxy::init, avg 1µs/call
37217µs return $self;
38}
39
4027µs
# spent 2µs within Log::Any::Proxy::init which was called 2 times, avg 1µs/call: # 2 times (2µs+0s) by Log::Any::Proxy::new at line 36, avg 1µs/call
sub init { }
41
4211µsfor my $attr (qw/adapter filter formatter prefix/) {
432147µs234µs
# spent 21µs (9+12) within Log::Any::Proxy::BEGIN@43 which was called: # once (9µs+12µs) by Log::Any::Adapter::Util::require_dynamic at line 43
no strict 'refs';
# spent 21µs making 1 call to Log::Any::Proxy::BEGIN@43 # spent 12µs making 1 call to strict::unimport
44413µs *{$attr} = sub { return $_[0]->{$attr} };
45}
46
4714µs14µsmy %aliases = Log::Any::Adapter::Util::log_level_aliases();
# spent 4µs making 1 call to Log::Any::Adapter::Util::log_level_aliases
48
49# Set up methods/aliases and detection methods/aliases
5012µs12µsforeach my $name ( Log::Any::Adapter::Util::logging_methods(), keys(%aliases) )
# spent 2µs making 1 call to Log::Any::Adapter::Util::logging_methods
51{
52147µs my $realname = $aliases{$name} || $name;
53144µs my $namef = $name . "f";
54143µs my $is_name = "is_$name";
55143µs my $is_realname = "is_$realname";
561415µs1425µs my $numeric = Log::Any::Adapter::Util::numeric_level($realname);
# spent 25µs making 14 calls to Log::Any::Adapter::Util::numeric_level, avg 2µs/call
572284µs232µs
# spent 20µs (8+12) within Log::Any::Proxy::BEGIN@57 which was called: # once (8µs+12µs) by Log::Any::Adapter::Util::require_dynamic at line 57
no strict 'refs';
# spent 20µs making 1 call to Log::Any::Proxy::BEGIN@57 # spent 12µs making 1 call to strict::unimport
58
# spent 21µs (18+3) within Log::Any::Proxy::__ANON__[/opt/flows/lib/lib/perl5/Log/Any/Proxy.pm:61] which was called 2 times, avg 10µs/call: # 2 times (18µs+3µs) by Search::Elasticsearch::Role::Logger::is_trace at line 12 of (eval 108)[Sub/Quote.pm:5], avg 10µs/call
*{$is_name} = sub {
5921µs my ($self) = @_;
60214µs23µs return $self->{adapter}->$is_realname;
# spent 3µs making 2 calls to Log::Any::Adapter::Null::__ANON__[/opt/flows/lib/lib/perl5/Log/Any/Adapter/Null.pm:19], avg 2µs/call
611444µs };
62
# spent 11µs (10+800ns) within Log::Any::Proxy::__ANON__[/opt/flows/lib/lib/perl5/Log/Any/Proxy.pm:72] which was called: # once (10µs+800ns) by Search::Elasticsearch::Role::Logger::info at line 12 of (eval 93)[Sub/Quote.pm:5]
*{$name} = sub {
6311µs my ( $self, @parts ) = @_;
6412µs my $message = join(" ", grep { defined($_) && length($_) } @parts );
651200ns return unless length $message;
661400ns $message = $self->{filter}->( $self->{category}, $numeric, $message )
67 if defined $self->{filter};
681300ns return unless defined $message and length $message;
691300ns $message = "$self->{prefix}$message"
70 if defined $self->{prefix} && length $self->{prefix};
7115µs1800ns return $self->{adapter}->$realname($message);
# spent 800ns making 1 call to Log::Any::Adapter::Null::__ANON__[/opt/flows/lib/lib/perl5/Log/Any/Adapter/Null.pm:19]
721447µs };
73
# spent 38µs (33+5) within Log::Any::Proxy::__ANON__[/opt/flows/lib/lib/perl5/Log/Any/Proxy.pm:80] which was called 4 times, avg 10µs/call: # 4 times (33µs+5µs) by Search::Elasticsearch::Role::Logger::infof at line 12 of (eval 89)[Sub/Quote.pm:5], avg 10µs/call
*{$namef} = sub {
7445µs my ( $self, @args ) = @_;
75426µs45µs return unless $self->{adapter}->$is_realname;
# spent 5µs making 4 calls to Log::Any::Adapter::Null::__ANON__[/opt/flows/lib/lib/perl5/Log/Any/Adapter/Null.pm:19], avg 1µs/call
76 my $message =
77 $self->{formatter}->( $self->{category}, $numeric, @args );
78 return unless defined $message and length $message;
79 return $self->$name($message);
801444µs };
81}
82
83110µs1;
84
85
86# vim: ts=4 sts=4 sw=4 et tw=75:
87
88__END__
Report produced by the NYTProf 5.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.