← 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/Search/Elasticsearch/Role/Cxn.pm
StatementsExecuted 65 statements in 1.63ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
11145µs2.02msSearch::Elasticsearch::Role::Cxn::::pings_okSearch::Elasticsearch::Role::Cxn::pings_ok
21117µs17µsSearch::Elasticsearch::Role::Cxn::::process_responseSearch::Elasticsearch::Role::Cxn::process_response
22217µs20µsSearch::Elasticsearch::Role::Cxn::::mark_liveSearch::Elasticsearch::Role::Cxn::mark_live
11116µs330µsSearch::Elasticsearch::Role::Cxn::::BEGIN@3Search::Elasticsearch::Role::Cxn::BEGIN@3
11114µs64µsSearch::Elasticsearch::Role::Cxn::::BEGIN@5Search::Elasticsearch::Role::Cxn::BEGIN@5
11110µs147µsSearch::Elasticsearch::Role::Cxn::::BEGIN@4Search::Elasticsearch::Role::Cxn::BEGIN@4
1119µs272µsSearch::Elasticsearch::Role::Cxn::::BEGIN@9Search::Elasticsearch::Role::Cxn::BEGIN@9
1119µs43µsSearch::Elasticsearch::Role::Cxn::::BEGIN@6Search::Elasticsearch::Role::Cxn::BEGIN@6
1118µs154µsSearch::Elasticsearch::Role::Cxn::::BEGIN@8Search::Elasticsearch::Role::Cxn::BEGIN@8
1118µs10µsSearch::Elasticsearch::Role::Cxn::::force_pingSearch::Elasticsearch::Role::Cxn::force_ping
1118µs44µsSearch::Elasticsearch::Role::Cxn::::__ANON__[:3]Search::Elasticsearch::Role::Cxn::__ANON__[:3]
1116µs6µsSearch::Elasticsearch::Role::Cxn::::is_deadSearch::Elasticsearch::Role::Cxn::is_dead
1115µs6µsSearch::Elasticsearch::Role::Cxn::::is_liveSearch::Elasticsearch::Role::Cxn::is_live
1114µs4µsSearch::Elasticsearch::Role::Cxn::::BEGIN@7Search::Elasticsearch::Role::Cxn::BEGIN@7
5524µs4µsSearch::Elasticsearch::Role::Cxn::::next_pingSearch::Elasticsearch::Role::Cxn::next_ping (xsub)
2214µs4µsSearch::Elasticsearch::Role::Cxn::::loggerSearch::Elasticsearch::Role::Cxn::logger (xsub)
2213µs3µsSearch::Elasticsearch::Role::Cxn::::ping_failuresSearch::Elasticsearch::Role::Cxn::ping_failures (xsub)
1112µs2µsSearch::Elasticsearch::Role::Cxn::::__ANON__[:27]Search::Elasticsearch::Role::Cxn::__ANON__[:27]
1112µs2µsSearch::Elasticsearch::Role::Cxn::::request_timeoutSearch::Elasticsearch::Role::Cxn::request_timeout (xsub)
2211µs1µsSearch::Elasticsearch::Role::Cxn::::uriSearch::Elasticsearch::Role::Cxn::uri (xsub)
1111µs1µsSearch::Elasticsearch::Role::Cxn::::__ANON__[:26]Search::Elasticsearch::Role::Cxn::__ANON__[:26]
111900ns900nsSearch::Elasticsearch::Role::Cxn::::default_qs_paramsSearch::Elasticsearch::Role::Cxn::default_qs_params (xsub)
111800ns800nsSearch::Elasticsearch::Role::Cxn::::handle_argsSearch::Elasticsearch::Role::Cxn::handle_args (xsub)
111800ns800nsSearch::Elasticsearch::Role::Cxn::::ping_timeoutSearch::Elasticsearch::Role::Cxn::ping_timeout (xsub)
0000s0sSearch::Elasticsearch::Role::Cxn::::__ANON__[:113]Search::Elasticsearch::Role::Cxn::__ANON__[:113]
0000s0sSearch::Elasticsearch::Role::Cxn::::__ANON__[:117]Search::Elasticsearch::Role::Cxn::__ANON__[:117]
0000s0sSearch::Elasticsearch::Role::Cxn::::__ANON__[:91]Search::Elasticsearch::Role::Cxn::__ANON__[:91]
0000s0sSearch::Elasticsearch::Role::Cxn::::__ANON__[:96]Search::Elasticsearch::Role::Cxn::__ANON__[:96]
0000s0sSearch::Elasticsearch::Role::Cxn::::_munge_elasticsearch_exceptionSearch::Elasticsearch::Role::Cxn::_munge_elasticsearch_exception
0000s0sSearch::Elasticsearch::Role::Cxn::::mark_deadSearch::Elasticsearch::Role::Cxn::mark_dead
0000s0sSearch::Elasticsearch::Role::Cxn::::sniffSearch::Elasticsearch::Role::Cxn::sniff
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Search::Elasticsearch::Role::Cxn;
21500ns$Search::Elasticsearch::Role::Cxn::VERSION = '2.02';
3448µs3680µs
# spent 330µs (16+314) within Search::Elasticsearch::Role::Cxn::BEGIN@3 which was called: # once (16µs+314µs) by Module::Runtime::require_module at line 3 # spent 44µs (8+36) within Search::Elasticsearch::Role::Cxn::__ANON__[/opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn.pm:3] which was called: # once (8µs+36µs) by import::into at line 34 of Import/Into.pm
use Moo::Role;
# spent 330µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@3 # spent 314µs making 1 call to Moo::Role::import # spent 36µs making 1 call to strictures::import
4238µs2285µs
# spent 147µs (10+138) within Search::Elasticsearch::Role::Cxn::BEGIN@4 which was called: # once (10µs+138µs) by Module::Runtime::require_module at line 4
use Search::Elasticsearch::Util qw(throw);
# spent 147µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@4 # spent 138µs making 1 call to Sub::Exporter::__ANON__[/opt/flows/lib/lib/perl5/Sub/Exporter.pm:337]
5236µs2115µs
# spent 64µs (14+50) within Search::Elasticsearch::Role::Cxn::BEGIN@5 which was called: # once (14µs+50µs) by Module::Runtime::require_module at line 5
use List::Util qw(min);
# spent 64µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@5 # spent 50µs making 1 call to Exporter::import
6228µs277µs
# spent 43µs (9+34) within Search::Elasticsearch::Role::Cxn::BEGIN@6 which was called: # once (9µs+34µs) by Module::Runtime::require_module at line 6
use Try::Tiny;
# spent 43µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@6 # spent 34µs making 1 call to Exporter::import
7228µs14µs
# spent 4µs within Search::Elasticsearch::Role::Cxn::BEGIN@7 which was called: # once (4µs+0s) by Module::Runtime::require_module at line 7
use URI();
# spent 4µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@7
8235µs2300µs
# spent 154µs (8+146) within Search::Elasticsearch::Role::Cxn::BEGIN@8 which was called: # once (8µs+146µs) by Module::Runtime::require_module at line 8
use Search::Elasticsearch::Util qw(to_list);
# spent 154µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@8 # spent 146µs making 1 call to Sub::Exporter::__ANON__[/opt/flows/lib/lib/perl5/Sub/Exporter.pm:337]
921.17ms2536µs
# spent 272µs (9+264) within Search::Elasticsearch::Role::Cxn::BEGIN@9 which was called: # once (9µs+264µs) by Module::Runtime::require_module at line 9
use namespace::clean;
# spent 272µs making 1 call to Search::Elasticsearch::Role::Cxn::BEGIN@9 # spent 264µs making 1 call to namespace::clean::import
10
1112µs19µsrequires qw(protocol perform_request error_from_text);
# spent 9µs making 1 call to Moo::Role::requires
12
1311µs1136µshas 'host' => ( is => 'ro', required => 1 );
# spent 136µs making 1 call to Moo::Role::has
1411µs1114µshas 'port' => ( is => 'ro', required => 1 );
# spent 114µs making 1 call to Moo::Role::has
1511µs1110µshas 'uri' => ( is => 'ro', required => 1 );
# spent 110µs making 1 call to Moo::Role::has
1611µs1110µshas 'request_timeout' => ( is => 'ro', default => 30 );
# spent 110µs making 1 call to Moo::Role::has
1711µs1109µshas 'ping_timeout' => ( is => 'ro', default => 2 );
# spent 109µs making 1 call to Moo::Role::has
1811µs1110µshas 'sniff_timeout' => ( is => 'ro', default => 1 );
# spent 110µs making 1 call to Moo::Role::has
1911µs1110µshas 'sniff_request_timeout' => ( is => 'ro', default => 2 );
# spent 110µs making 1 call to Moo::Role::has
2011µs1119µshas 'next_ping' => ( is => 'rw', default => 0 );
# spent 119µs making 1 call to Moo::Role::has
2111µs1118µshas 'ping_failures' => ( is => 'rw', default => 0 );
# spent 118µs making 1 call to Moo::Role::has
2211µs1111µshas 'dead_timeout' => ( is => 'ro', default => 60 );
# spent 111µs making 1 call to Moo::Role::has
2311µs1110µshas 'max_dead_timeout' => ( is => 'ro', default => 3600 );
# spent 110µs making 1 call to Moo::Role::has
2411µs1124µshas 'serializer' => ( is => 'ro', required => 1 );
# spent 124µs making 1 call to Moo::Role::has
2511µs1128µshas 'logger' => ( is => 'ro', required => 1 );
# spent 128µs making 1 call to Moo::Role::has
26211µs1127µs
# spent 1µs within Search::Elasticsearch::Role::Cxn::__ANON__[/opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn.pm:26] which was called: # once (1µs+0s) by Search::Elasticsearch::Cxn::HTTPTiny::new at line 51 of (eval 87)[Sub/Quote.pm:5]
has 'handle_args' => ( is => 'ro', default => sub { {} } );
# spent 127µs making 1 call to Moo::Role::has
2727µs1125µs
# spent 2µs within Search::Elasticsearch::Role::Cxn::__ANON__[/opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn.pm:27] which was called: # once (2µs+0s) by Search::Elasticsearch::Cxn::HTTPTiny::new at line 43 of (eval 87)[Sub/Quote.pm:5]
has 'default_qs_params' => ( is => 'ro', default => sub { {} } );
# spent 125µs making 1 call to Moo::Role::has
28
2914µsmy %Code_To_Error = (
30 400 => 'Request',
31 401 => 'Unauthorized',
32 403 => 'Forbidden',
33 404 => 'Missing',
34 408 => 'RequestTimeout',
35 409 => 'Conflict',
36 503 => 'Unavailable'
37);
38
39#===================================
4018µs1700ns
# spent 6µs (5+700ns) within Search::Elasticsearch::Role::Cxn::is_live which was called: # once (5µs+700ns) by Search::Elasticsearch::CxnPool::Static::next_cxn at line 22 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/CxnPool/Static.pm
sub is_live { !shift->next_ping }
# spent 700ns making 1 call to Search::Elasticsearch::Role::Cxn::next_ping
41114µs1600ns
# spent 6µs (6+600ns) within Search::Elasticsearch::Role::Cxn::is_dead which was called: # once (6µs+600ns) by Search::Elasticsearch::Role::CxnPool::Static::schedule_check at line 23 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/CxnPool/Static.pm
sub is_dead { !!shift->next_ping }
# spent 600ns making 1 call to Search::Elasticsearch::Role::Cxn::next_ping
42#===================================
43
44#===================================
45
# spent 20µs (17+3) within Search::Elasticsearch::Role::Cxn::mark_live which was called 2 times, avg 10µs/call: # once (12µs+3µs) by Search::Elasticsearch::Role::Cxn::try {...} at line 89 # once (4µs+0s) by Search::Elasticsearch::Role::CxnPool::request_ok at line 66 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/CxnPool.pm
sub mark_live {
46#===================================
4721µs my $self = shift;
4829µs12µs $self->ping_failures(0);
# spent 2µs making 1 call to Search::Elasticsearch::Role::Cxn::ping_failures
49214µs12µs $self->next_ping(0);
# spent 2µs making 1 call to Search::Elasticsearch::Role::Cxn::next_ping
50}
51
52#===================================
53sub mark_dead {
54#===================================
55 my $self = shift;
56 my $fails = $self->ping_failures;
57 $self->ping_failures( $fails + 1 );
58
59 my $timeout
60 = min( $self->dead_timeout * 2**$fails, $self->max_dead_timeout );
61 my $next = $self->next_ping( time() + $timeout );
62
63 $self->logger->infof( 'Marking [%s] as dead. Next ping at: %s',
64 $self->stringify, scalar localtime($next) );
65
66}
67
68#===================================
69
# spent 10µs (8+2) within Search::Elasticsearch::Role::Cxn::force_ping which was called: # once (8µs+2µs) by Search::Elasticsearch::Role::CxnPool::Static::schedule_check at line 26 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/CxnPool/Static.pm
sub force_ping {
70#===================================
711200ns my $self = shift;
7215µs1900ns $self->ping_failures(0);
# spent 900ns making 1 call to Search::Elasticsearch::Role::Cxn::ping_failures
7316µs1700ns $self->next_ping(-1);
# spent 700ns making 1 call to Search::Elasticsearch::Role::Cxn::next_ping
74}
75
76#===================================
77
# spent 2.02ms (45µs+1.98) within Search::Elasticsearch::Role::Cxn::pings_ok which was called: # once (45µs+1.98ms) by Search::Elasticsearch::CxnPool::Static::next_cxn at line 24 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/CxnPool/Static.pm
sub pings_ok {
78#===================================
791300ns my $self = shift;
80111µs310µs $self->logger->infof( 'Pinging [%s]', $self->stringify );
# spent 8µs making 1 call to Search::Elasticsearch::Role::Cxn::HTTP::stringify # spent 2µs making 1 call to Search::Elasticsearch::Role::Logger::infof # spent 600ns making 1 call to Search::Elasticsearch::Role::Cxn::logger
81 return try {
82114µs21.79ms $self->perform_request(
# spent 1.79ms making 1 call to Search::Elasticsearch::Cxn::HTTPTiny::perform_request # spent 800ns making 1 call to Search::Elasticsearch::Role::Cxn::ping_timeout
83 { method => 'HEAD',
84 path => '/',
85 timeout => $self->ping_timeout,
86 }
87 );
88117µs323µs $self->logger->infof( 'Marking [%s] as live', $self->stringify );
# spent 15µs making 1 call to Search::Elasticsearch::Role::Cxn::HTTP::stringify # spent 5µs making 1 call to Search::Elasticsearch::Role::Logger::infof # spent 3µs making 1 call to Search::Elasticsearch::Role::Cxn::logger
8914µs116µs $self->mark_live;
# spent 16µs making 1 call to Search::Elasticsearch::Role::Cxn::mark_live
9015µs 1;
91 }
92 catch {
93 $self->logger->debug("$_");
94 $self->mark_dead;
95 0;
96126µs23µs };
# spent 3µs making 1 call to Try::Tiny::catch # spent 1.95ms making 1 call to Try::Tiny::try, recursion: max depth 1, sum of overlapping time 1.95ms
97}
98
99#===================================
100sub sniff {
101#===================================
102 my $self = shift;
103 my $protocol = $self->protocol;
104 $self->logger->infof( 'Sniffing [%s]', $self->stringify );
105 return try {
106 $self->perform_request(
107 { method => 'GET',
108 path => '/_nodes/' . $protocol,
109 qs => { timeout => $self->sniff_timeout . 's' },
110 timeout => $self->sniff_request_timeout,
111 }
112 )->{nodes};
113 }
114 catch {
115 $self->logger->debug($_);
116 return;
117 };
118}
119
120#===================================
121
# spent 17µs within Search::Elasticsearch::Role::Cxn::process_response which was called 2 times, avg 8µs/call: # 2 times (17µs+0s) by Search::Elasticsearch::Role::Cxn::HTTP::__ANON__[/opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn/HTTP.pm:136] at line 135 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn/HTTP.pm, avg 8µs/call
sub process_response {
122#===================================
12322µs my ( $self, $params, $code, $msg, $body, $mime_type ) = @_;
124
12523µs my $is_encoded = $mime_type && $mime_type ne 'text/plain';
126
127 # Request is successful
128
12923µs if ( $code >= 200 and $code <= 209 ) {
13021µs if ( defined $body and length $body ) {
131 $body = $self->serializer->decode($body)
132 if $is_encoded;
133 return $code, $body;
134 }
135214µs return ( $code, 1 ) if $params->{method} eq 'HEAD';
136 return ( $code, '' );
137 }
138
139 # Check if the error should be ignored
140 my @ignore = to_list( $params->{ignore} );
141 push @ignore, 404 if $params->{method} eq 'HEAD';
142 return ($code) if grep { $_ eq $code } @ignore;
143
144 # Determine error type
145 my $error_type = $Code_To_Error{$code};
146 unless ($error_type) {
147 if ( defined $body and length $body ) {
148 $msg = $body;
149 $body = undef;
150 }
151 $error_type = $self->error_from_text( $code, $msg );
152 }
153
154 delete $params->{data} if $params->{body};
155 my %error_args = ( status_code => $code, request => $params );
156
157 # Extract error message from the body, if present
158
159 if ( $body = $self->serializer->decode($body) ) {
160 $error_args{body} = $body;
161 $msg = $self->_munge_elasticsearch_exception($body) || $msg;
162
163 $error_args{current_version} = $1
164 if $error_type eq 'Conflict'
165 and $msg =~ /: version conflict, current \[(\d+)\]/;
166 }
167 $msg ||= $error_type;
168
169 chomp $msg;
170 throw( $error_type, "[" . $self->stringify . "]-[$code] $msg",
171 \%error_args );
172}
173
174#===================================
175sub _munge_elasticsearch_exception {
176#===================================
177 my ( $self, $body ) = @_;
178 return $body unless ref $body eq 'HASH';
179 my $error = $body->{error} || return;
180 return $error unless ref $error eq 'HASH';
181
182 my $root_causes = $error->{root_cause} || [];
183 unless (@$root_causes) {
184 my $msg = "[" . $error->{type} . "] " if $error->{type};
185 $msg .= $error->{reason} if $error->{reason};
186 return $msg;
187 }
188
189 my $json = $self->serializer;
190 my @msgs;
191 for (@$root_causes) {
192 my %cause = (%$_);
193 my $msg
194 = "[" . ( delete $cause{type} ) . "] " . ( delete $cause{reason} );
195 if ( keys %cause ) {
196 $msg .= ", with: " . $json->encode( \%cause );
197 }
198 push @msgs, $msg;
199 }
200 return ( join ", ", @msgs );
201}
202
203119µs1;
204
205# ABSTRACT: Provides common functionality to Cxn implementations
206
207125µs1497µs__END__
# spent 497µs making 1 call to B::Hooks::EndOfScope::XS::__ANON__[/opt/flows/lib/lib/perl5/B/Hooks/EndOfScope/XS.pm:17]
 
# spent 900ns within Search::Elasticsearch::Role::Cxn::default_qs_params which was called: # once (900ns+0s) by Search::Elasticsearch::Role::Cxn::HTTP::build_uri at line 93 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn/HTTP.pm
sub Search::Elasticsearch::Role::Cxn::default_qs_params; # xsub
# spent 800ns within Search::Elasticsearch::Role::Cxn::handle_args which was called: # once (800ns+0s) by Search::Elasticsearch::Cxn::HTTPTiny::_build_handle at line 69 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Cxn/HTTPTiny.pm
sub Search::Elasticsearch::Role::Cxn::handle_args; # xsub
# spent 4µs within Search::Elasticsearch::Role::Cxn::logger which was called 2 times, avg 2µs/call: # once (3µs+0s) by Search::Elasticsearch::Role::Cxn::try {...} at line 88 # once (600ns+0s) by Search::Elasticsearch::Role::Cxn::pings_ok at line 80
sub Search::Elasticsearch::Role::Cxn::logger; # xsub
# spent 4µs within Search::Elasticsearch::Role::Cxn::next_ping which was called 5 times, avg 800ns/call: # once (2µs+0s) by Search::Elasticsearch::Role::Cxn::mark_live at line 49 # once (700ns+0s) by Search::Elasticsearch::Role::Cxn::force_ping at line 73 # once (700ns+0s) by Search::Elasticsearch::Role::Cxn::is_live at line 40 # once (600ns+0s) by Search::Elasticsearch::Role::Cxn::is_dead at line 41 # once (500ns+0s) by Search::Elasticsearch::CxnPool::Static::next_cxn at line 24 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/CxnPool/Static.pm
sub Search::Elasticsearch::Role::Cxn::next_ping; # xsub
# spent 3µs within Search::Elasticsearch::Role::Cxn::ping_failures which was called 2 times, avg 1µs/call: # once (2µs+0s) by Search::Elasticsearch::Role::Cxn::mark_live at line 48 # once (900ns+0s) by Search::Elasticsearch::Role::Cxn::force_ping at line 72
sub Search::Elasticsearch::Role::Cxn::ping_failures; # xsub
# spent 800ns within Search::Elasticsearch::Role::Cxn::ping_timeout which was called: # once (800ns+0s) by Search::Elasticsearch::Role::Cxn::try {...} at line 82
sub Search::Elasticsearch::Role::Cxn::ping_timeout; # xsub
# spent 2µs within Search::Elasticsearch::Role::Cxn::request_timeout which was called: # once (2µs+0s) by Search::Elasticsearch::Cxn::HTTPTiny::perform_request at line 32 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Cxn/HTTPTiny.pm
sub Search::Elasticsearch::Role::Cxn::request_timeout; # xsub
# spent 1µs within Search::Elasticsearch::Role::Cxn::uri which was called 2 times, avg 650ns/call: # once (700ns+0s) by Search::Elasticsearch::Role::Cxn::HTTP::build_uri at line 91 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn/HTTP.pm # once (600ns+0s) by Search::Elasticsearch::Role::Cxn::HTTP::stringify at line 21 of /opt/flows/lib/lib/perl5/Search/Elasticsearch/Role/Cxn/HTTP.pm
sub Search::Elasticsearch::Role::Cxn::uri; # xsub
Report produced by the NYTProf 5.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.