← 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:08 2016

Filename/usr/share/perl5/Sub/Defer.pm
StatementsExecuted 674 statements in 1.82ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
5422556µs1.20msSub::Defer::::defer_subSub::Defer::defer_sub
2122341µs14.1msSub::Defer::::undefer_subSub::Defer::undefer_sub
101122µs22µsSub::Defer::::defer_infoSub::Defer::defer_info
11116µs67µsSub::Defer::::BEGIN@3Sub::Defer::BEGIN@3
11111µs66µsSub::Defer::::BEGIN@6Sub::Defer::BEGIN@6
11110µs21µsSub::Defer::::BEGIN@26Sub::Defer::BEGIN@26
1119µs75µsSub::Defer::::BEGIN@5Sub::Defer::BEGIN@5
1118µs75µsSub::Defer::::BEGIN@4Sub::Defer::BEGIN@4
0000s0sSub::Defer::::CLONESub::Defer::CLONE
0000s0sSub::Defer::::__ANON__[:54]Sub::Defer::__ANON__[:54]
0000s0sSub::Defer::::undefer_allSub::Defer::undefer_all
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Sub::Defer;
2
3337µs3118µs
# spent 67µs (16+51) within Sub::Defer::BEGIN@3 which was called: # once (16µs+51µs) by Moo::BEGIN@6 at line 3
use strictures 1;
# spent 67µs making 1 call to Sub::Defer::BEGIN@3 # spent 35µs making 1 call to strictures::import # spent 15µs making 1 call to strictures::VERSION
4231µs2142µs
# spent 75µs (8+67) within Sub::Defer::BEGIN@4 which was called: # once (8µs+67µs) by Moo::BEGIN@6 at line 4
use base qw(Exporter);
# spent 75µs making 1 call to Sub::Defer::BEGIN@4 # spent 67µs making 1 call to base::import
5232µs2141µs
# spent 75µs (9+66) within Sub::Defer::BEGIN@5 which was called: # once (9µs+66µs) by Moo::BEGIN@6 at line 5
use Moo::_Utils;
# spent 75µs making 1 call to Sub::Defer::BEGIN@5 # spent 66µs making 1 call to Exporter::import
62154µs2121µs
# spent 66µs (11+55) within Sub::Defer::BEGIN@6 which was called: # once (11µs+55µs) by Moo::BEGIN@6 at line 6
use Scalar::Util qw(weaken);
# spent 66µs making 1 call to Sub::Defer::BEGIN@6 # spent 55µs making 1 call to Exporter::import
7
81700nsour $VERSION = '1.004002';
9114µs$VERSION = eval $VERSION;
# spent 2µs executing statements in string eval
10
1111µsour @EXPORT = qw(defer_sub undefer_sub undefer_all);
12
131100nsour %DEFERRED;
14
15
# spent 14.1ms (341µs+13.7) within Sub::Defer::undefer_sub which was called 21 times, avg 670µs/call: # 17 times (316µs+13.5ms) by Method::Generate::Constructor::new or Search::Elasticsearch::Bulk::new or Search::Elasticsearch::Client::2_0::Direct::Indices::new or Search::Elasticsearch::Client::2_0::Direct::new or Search::Elasticsearch::Cxn::Factory::new or Search::Elasticsearch::Cxn::HTTPTiny::new or Search::Elasticsearch::CxnPool::Static::new or Search::Elasticsearch::Logger::LogAny::new or Search::Elasticsearch::Role::Client::Direct::Main::_bulk_class or Search::Elasticsearch::Role::Client::Direct::Main::indices or Search::Elasticsearch::Role::Logger::_assert_log_handle or Search::Elasticsearch::Role::Logger::_assert_trace_handle or Search::Elasticsearch::Role::Logger::info or Search::Elasticsearch::Role::Logger::infof or Search::Elasticsearch::Role::Logger::is_trace or Search::Elasticsearch::Serializer::JSON::new or Search::Elasticsearch::Transport::new at line 52, avg 810µs/call # 4 times (25µs+280µs) by Moo::_Utils::_install_modifier at line 33 of Moo/_Utils.pm, avg 76µs/call
sub undefer_sub {
16218µs my ($deferred) = @_;
17 my ($target, $maker, $undeferred_ref) = @{
182145µs $DEFERRED{$deferred}||return $deferred
19 };
20 return ${$undeferred_ref}
21184µs if ${$undeferred_ref};
221837µs1813.6ms ${$undeferred_ref} = my $made = $maker->();
# spent 11.4ms making 10 calls to Method::Generate::Constructor::__ANON__[Method/Generate/Constructor.pm:76], avg 1.14ms/call # spent 2.27ms making 8 calls to Sub::Quote::__ANON__[Sub/Quote.pm:82], avg 284µs/call
23
24 # make sure the method slot has not changed since deferral time
251869µs1857µs if (defined($target) && $deferred eq *{_getglob($target)}{CODE}||'') {
# spent 57µs making 18 calls to Moo::_Utils::_getglob, avg 3µs/call
262334µs232µs
# spent 21µs (10+11) within Sub::Defer::BEGIN@26 which was called: # once (10µs+11µs) by Moo::BEGIN@6 at line 26
no warnings 'redefine';
# spent 21µs making 1 call to Sub::Defer::BEGIN@26 # spent 11µs making 1 call to warnings::unimport
27
28 # I believe $maker already evals with the right package/name, so that
29 # _install_coderef calls are not necessary --ribasushi
301834µs1825µs *{_getglob($target)} = $made;
# spent 25µs making 18 calls to Moo::_Utils::_getglob, avg 1µs/call
31 }
321892µs1826µs weaken($DEFERRED{$made} = $DEFERRED{$deferred});
# spent 26µs making 18 calls to Scalar::Util::weaken, avg 1µs/call
33
341877µs return $made;
35}
36
37sub undefer_all {
38 undefer_sub($_) for keys %DEFERRED;
39 return;
40}
41
42
# spent 22µs within Sub::Defer::defer_info which was called 10 times, avg 2µs/call: # 10 times (22µs+0s) by Moo::_accessor_maker_for at line 129 of Moo.pm, avg 2µs/call
sub defer_info {
43103µs my ($deferred) = @_;
441030µs $DEFERRED{$deferred||''};
45}
46
47
# spent 1.20ms (556µs+641µs) within Sub::Defer::defer_sub which was called 54 times, avg 22µs/call: # 44 times (440µs+492µs) by Sub::Quote::quote_sub at line 82 of Sub/Quote.pm, avg 21µs/call # 10 times (116µs+149µs) by Method::Generate::Constructor::install_delayed at line 76 of Method/Generate/Constructor.pm, avg 26µs/call
sub defer_sub {
485423µs my ($target, $maker) = @_;
49546µs my $undeferred;
50544µs my $deferred_info;
51 my $deferred = sub {
522840µs1713.8ms $undeferred ||= undefer_sub($deferred_info->[3]);
# spent 13.8ms making 17 calls to Sub::Defer::undefer_sub, avg 810µs/call
5328146µs2872.9ms goto &$undeferred;
# spent 26.1ms making 1 call to Search::Elasticsearch::Cxn::Factory::new # spent 13.9ms making 1 call to Search::Elasticsearch::Role::Client::Direct::Main::_bulk_class # spent 13.7ms making 1 call to Search::Elasticsearch::CxnPool::Static::new # spent 7.99ms making 1 call to Search::Elasticsearch::Cxn::HTTPTiny::new # spent 4.51ms making 1 call to Search::Elasticsearch::Role::Client::Direct::Main::indices # spent 2.91ms making 4 calls to Search::Elasticsearch::Role::Logger::infof, avg 727µs/call # spent 2.52ms making 5 calls to Search::Elasticsearch::Role::Logger::_assert_log_handle, avg 503µs/call # spent 587µs making 2 calls to Search::Elasticsearch::Role::Logger::is_trace, avg 293µs/call # spent 204µs making 2 calls to Search::Elasticsearch::Role::Logger::_assert_trace_handle, avg 102µs/call # spent 114µs making 2 calls to Search::Elasticsearch::Role::Cxn::HTTP::handle, avg 57µs/call # spent 110µs making 1 call to Search::Elasticsearch::Transport::new # spent 52µs making 1 call to Search::Elasticsearch::Bulk::new # spent 51µs making 1 call to Search::Elasticsearch::Serializer::JSON::new # spent 26µs making 1 call to Search::Elasticsearch::Role::Logger::info # spent 20µs making 1 call to Search::Elasticsearch::Client::2_0::Direct::new # spent 16µs making 1 call to Search::Elasticsearch::Logger::LogAny::new # spent 15µs making 1 call to Search::Elasticsearch::Client::2_0::Direct::Indices::new # spent 14µs making 1 call to Method::Generate::Constructor::new
545495µs };
555460µs $deferred_info = [ $target, $maker, \$undeferred, $deferred ];
5654251µs5463µs weaken($DEFERRED{$deferred} = $deferred_info);
# spent 63µs making 54 calls to Scalar::Util::weaken, avg 1µs/call
575463µs44577µs _install_coderef($target => $deferred) if defined $target;
# spent 577µs making 44 calls to Moo::_Utils::_install_coderef, avg 13µs/call
5854123µs return $deferred;
59}
60
61sub CLONE {
62 %DEFERRED = map { defined $_ ? ($_->[3] => $_) : () } values %DEFERRED;
63 weaken($_) for values %DEFERRED;
64}
65
6614µs1;
67__END__
Report produced by the NYTProf 5.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.