← Index
NYTProf Performance Profile   « line view »
For rbm/rbm
  Run on Wed Feb 12 03:38:15 2020
Reported on Wed Feb 12 04:56:35 2020

Filename/usr/share/perl5/IO/CaptureOutput.pm
StatementsExecuted 1366642 statements in 368s
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
1394511349s349sIO::CaptureOutput::::CORE:system IO::CaptureOutput::CORE:system (opcode)
27890116.61s6.61sIO::CaptureOutput::_proxy::::CORE:unlinkIO::CaptureOutput::_proxy::CORE:unlink (opcode)
27890112.61s13.8sIO::CaptureOutput::_proxy::::DESTROYIO::CaptureOutput::_proxy::DESTROY
13945111.98s380sIO::CaptureOutput::::_capture IO::CaptureOutput::_capture
27890211.92s14.1sIO::CaptureOutput::_proxy::::newIO::CaptureOutput::_proxy::new
111560411.65s1.65sIO::CaptureOutput::_proxy::::CORE:openIO::CaptureOutput::_proxy::CORE:open (opcode)
27890111.61s1.61sIO::CaptureOutput::_proxy::::CORE:closeIO::CaptureOutput::_proxy::CORE:close (opcode)
13945111.16s350sIO::CaptureOutput::::__ANON__[:74] IO::CaptureOutput::__ANON__[:74]
2789011899ms899msIO::CaptureOutput::_proxy::::CORE:readlineIO::CaptureOutput::_proxy::CORE:readline (opcode)
1394573505ms380sIO::CaptureOutput::::capture_exec IO::CaptureOutput::capture_exec
2789011353ms353msIO::CaptureOutput::_proxy::::CORE:ftisIO::CaptureOutput::_proxy::CORE:ftis (opcode)
5578011113ms113msIO::CaptureOutput::_proxy::::CORE:selectIO::CaptureOutput::_proxy::CORE:select (opcode)
2789011101ms101msIO::CaptureOutput::_proxy::::CORE:seekIO::CaptureOutput::_proxy::CORE:seek (opcode)
139451199.8ms99.8msIO::CaptureOutput::::_validate IO::CaptureOutput::_validate
278901193.1ms93.1msIO::CaptureOutput::_proxy::::_is_wperlIO::CaptureOutput::_proxy::_is_wperl
139451148.8ms48.8msIO::CaptureOutput::::__ANON__[:94] IO::CaptureOutput::__ANON__[:94]
1117.10ms9.73msIO::CaptureOutput::_proxy::::BEGIN@138IO::CaptureOutput::_proxy::BEGIN@138
11119µs48µsIO::CaptureOutput::_proxy::::BEGIN@139IO::CaptureOutput::_proxy::BEGIN@139
11113µs15µsRBM::::BEGIN@1.4 RBM::BEGIN@1.4
11110µs58µsIO::CaptureOutput::::BEGIN@9 IO::CaptureOutput::BEGIN@9
1118µs49µsIO::CaptureOutput::::BEGIN@11 IO::CaptureOutput::BEGIN@11
1117µs22µsIO::CaptureOutput::_proxy::::BEGIN@154IO::CaptureOutput::_proxy::BEGIN@154
1116µs36µsIO::CaptureOutput::_proxy::::BEGIN@141IO::CaptureOutput::_proxy::BEGIN@141
1116µs43µsIO::CaptureOutput::_proxy::::BEGIN@140IO::CaptureOutput::_proxy::BEGIN@140
1116µs19µsIO::CaptureOutput::::BEGIN@10 IO::CaptureOutput::BEGIN@10
1116µs13µsIO::CaptureOutput::_proxy::::BEGIN@178IO::CaptureOutput::_proxy::BEGIN@178
1116µs28µsRBM::::BEGIN@2.5 RBM::BEGIN@2.5
111900ns900nsIO::CaptureOutput::::CORE:match IO::CaptureOutput::CORE:match (opcode)
0000s0sIO::CaptureOutput::::__ANON__[:85] IO::CaptureOutput::__ANON__[:85]
0000s0sIO::CaptureOutput::::_shell_quote_win32 IO::CaptureOutput::_shell_quote_win32
0000s0sIO::CaptureOutput::::capture IO::CaptureOutput::capture
0000s0sIO::CaptureOutput::::capture_exec_combined IO::CaptureOutput::capture_exec_combined
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1221µs218µs
# spent 15µs (13+2) within RBM::BEGIN@1.4 which was called: # once (13µs+2µs) by RBM::BEGIN@12 at line 1
use strict;
# spent 15µs making 1 call to RBM::BEGIN@1.4 # spent 2µs making 1 call to strict::import
2242µs251µs
# spent 28µs (6+23) within RBM::BEGIN@2.5 which was called: # once (6µs+23µs) by RBM::BEGIN@12 at line 2
use warnings;
# spent 28µs making 1 call to RBM::BEGIN@2.5 # spent 23µs making 1 call to warnings::import
3
4package IO::CaptureOutput;
5# ABSTRACT: capture STDOUT and STDERR from Perl code, subprocesses or XS
6
711µsour $VERSION = '1.1104';
8
9226µs2107µs
# spent 58µs (10+49) within IO::CaptureOutput::BEGIN@9 which was called: # once (10µs+49µs) by RBM::BEGIN@12 at line 9
use vars qw/@ISA @EXPORT_OK %EXPORT_TAGS $CarpLevel/;
# spent 58µs making 1 call to IO::CaptureOutput::BEGIN@9 # spent 49µs making 1 call to vars::import
10221µs231µs
# spent 19µs (6+12) within IO::CaptureOutput::BEGIN@10 which was called: # once (6µs+12µs) by RBM::BEGIN@12 at line 10
use Exporter;
# spent 19µs making 1 call to IO::CaptureOutput::BEGIN@10 # spent 12µs making 1 call to Exporter::import
112612µs290µs
# spent 49µs (8+41) within IO::CaptureOutput::BEGIN@11 which was called: # once (8µs+41µs) by RBM::BEGIN@12 at line 11
use Carp qw/croak/;
# spent 49µs making 1 call to IO::CaptureOutput::BEGIN@11 # spent 41µs making 1 call to Exporter::import
1218µs@ISA = 'Exporter';
1312µs@EXPORT_OK = qw/capture capture_exec qxx capture_exec_combined qxy/;
1411µs%EXPORT_TAGS = (all => \@EXPORT_OK);
151500ns$CarpLevel = 0; # help capture report errors at the right level
16
17
# spent 380s (1.98+378) within IO::CaptureOutput::_capture which was called 13945 times, avg 27.2ms/call: # 13945 times (1.98s+378s) by IO::CaptureOutput::capture_exec at line 74, avg 27.2ms/call
sub _capture (&@) { ## no critic
181394512.7ms my ($code, $output, $error, $output_file, $error_file) = @_;
19
20 # check for valid combinations of input
21 {
222789026.5ms local $Carp::CarpLevel = 1;
231394562.3ms1394599.8ms my $error = _validate($output, $error, $output_file, $error_file);
# spent 99.8ms making 13945 calls to IO::CaptureOutput::_validate, avg 7µs/call
24139459.69ms croak $error if $error;
25 }
26
27 # if either $output or $error are defined, then we need a variable for
28 # results; otherwise we only capture to files and don't waste memory
291394513.7ms if ( defined $output || defined $error ) {
301394520.6ms for ($output, $error) {
312789011.7ms $_ = \do { my $s; $s = ''} unless ref $_;
322789044.1ms $$_ = '' if $_ != \undef && !defined($$_);
33 }
34 }
35
36 # merge if same refs for $output and $error or if both are undef --
37 # i.e. capture \&foo, undef, undef, $merged_file
38 # this means capturing into separate files *requires* at least one
39 # capture variable
401394532.7ms my $should_merge =
41 (defined $error && defined $output && $output == $error) ||
42 ( !defined $output && !defined $error ) ||
43 0;
44
45139454.32ms my ($capture_out, $capture_err);
46
47 # undef means capture anonymously; anything other than \undef means
48 # capture to that ref; \undef means skip capture
491394598.7ms139459.54s if ( !defined $output || $output != \undef ) {
# spent 9.54s making 13945 calls to IO::CaptureOutput::_proxy::new, avg 684µs/call
50 $capture_out = IO::CaptureOutput::_proxy->new(
51 'STDOUT', $output, undef, $output_file
52 );
53 }
541394549.2ms139454.58s if ( !defined $error || $error != \undef ) {
# spent 4.58s making 13945 calls to IO::CaptureOutput::_proxy::new, avg 329µs/call
55 $capture_err = IO::CaptureOutput::_proxy->new(
56 'STDERR', $error, ($should_merge ? 'STDOUT' : undef), $error_file
57 );
58 }
59
60 # now that output capture is setup, call the subroutine
61 # results get read when IO::CaptureOutput::_proxy objects go out of scope
62139451.29s41835364s &$code();
# spent 350s making 13945 calls to IO::CaptureOutput::__ANON__[IO/CaptureOutput.pm:74], avg 25.1ms/call # spent 13.8s making 27890 calls to IO::CaptureOutput::_proxy::DESTROY, avg 494µs/call
63}
64
65# Extra indirection for symmetry with capture_exec, etc. Gets error reporting
66# to the right level
67sub capture (&@) { ## no critic
68 return &_capture;
69}
70
71
# spent 380s (505ms+380) within IO::CaptureOutput::capture_exec which was called 13945 times, avg 27.3ms/call: # 3974 times (148ms+79.0s) by RBM::git_need_fetch at line 382 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 19.9ms/call # 3973 times (142ms+82.3s) by RBM::run_script at line 471 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 20.8ms/call # 3973 times (146ms+81.8s) by RBM::execute at line 483 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 20.6ms/call # 1991 times (68.7ms+128s) by RBM::DefaultConfig::lsb_release at line 60 of /root/tor-browser-build/rbm/lib/RBM/DefaultConfig.pm, avg 64.1ms/call # 15 times (597µs+873ms) by RBM::__ANON__[(eval 14)[rbm/lib/RBM.pm:39]:16] at line 14 of (eval 14)[rbm/lib/RBM.pm:39], avg 58.2ms/call # 15 times (609µs+831ms) by RBM::__ANON__[(eval 14)[rbm/lib/RBM.pm:39]:10] at line 8 of (eval 14)[rbm/lib/RBM.pm:39], avg 55.4ms/call # 4 times (132µs+7.50s) by RBM::run_script at line 468 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 1.88s/call
sub capture_exec {
721394518.9ms my @args = @_;
73139455.11ms my ($output, $error);
7427890350s41835729s
# spent 350s (1.16+349) within IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:74] which was called 13945 times, avg 25.1ms/call: # 13945 times (1.16s+349s) by IO::CaptureOutput::_capture at line 62, avg 25.1ms/call
my $exit = _capture sub { system _shell_quote(@args) }, \$output, \$error;
# spent 380s making 13945 calls to IO::CaptureOutput::_capture, avg 27.2ms/call # spent 349s making 13945 calls to IO::CaptureOutput::CORE:system, avg 25.0ms/call # spent 48.8ms making 13945 calls to IO::CaptureOutput::__ANON__[IO/CaptureOutput.pm:94], avg 3µs/call
751394521.1ms my $success = ($exit == 0 ) ? 1 : 0 ;
761394523.5ms $? = $exit;
7713945232ms return wantarray ? ($output, $error, $success, $exit) : $output;
78}
79
801900ns*qxx = \&capture_exec;
81
82sub capture_exec_combined {
83 my @args = @_;
84 my $output;
85 my $exit = _capture sub { system _shell_quote(@args) }, \$output, \$output;
86 my $success = ($exit == 0 ) ? 1 : 0 ;
87 $? = $exit;
88 return wantarray ? ($output, $success, $exit) : $output;
89}
90
9111µs*qxy = \&capture_exec_combined;
92
93# extra quoting required on Win32 systems
941394698.8ms1900ns
# spent 48.8ms within IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:94] which was called 13945 times, avg 3µs/call: # 13945 times (48.8ms+0s) by IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:74] at line 74, avg 3µs/call
*_shell_quote = ($^O =~ /MSWin32/) ? \&_shell_quote_win32 : sub {@_};
# spent 900ns making 1 call to IO::CaptureOutput::CORE:match
95sub _shell_quote_win32 {
96 my @args;
97 for (@_) {
98 if (/[ \"]/) { # TODO: check if ^ requires escaping
99 (my $escaped = $_) =~ s/([\"])/\\$1/g;
100 push @args, '"' . $escaped . '"';
101 next;
102 }
103 push @args, $_
104 }
105 return @args;
106}
107
108# detect errors and return an error message or empty string;
109
# spent 99.8ms within IO::CaptureOutput::_validate which was called 13945 times, avg 7µs/call: # 13945 times (99.8ms+0s) by IO::CaptureOutput::_capture at line 23, avg 7µs/call
sub _validate {
1101394510.8ms my ($output, $error, $output_file, $error_file) = @_;
111
112 # default to "ok"
1131394512.5ms my $msg = q{};
114
115 # \$out, \$out, $outfile, $errfile
1161394535.8ms if ( defined $output && defined $error
117 && defined $output_file && defined $error_file
118 && $output == $error
119 && $output != \undef
120 && $output_file ne $error_file
121 ) {
122 $msg = "Merged STDOUT and STDERR, but specified different output and error files";
123 }
124 # undef, undef, $outfile, $errfile
125 elsif ( !defined $output && !defined $error
126 && defined $output_file && defined $error_file
127 && $output_file ne $error_file
128 ) {
129 $msg = "Merged STDOUT and STDERR, but specified different output and error files";
130 }
131
13213945109ms return $msg;
133}
134
135# Captures everything printed to a filehandle for the lifetime of the object
136# and then transfers it to a scalar reference
137package IO::CaptureOutput::_proxy;
1383209µs39.81ms
# spent 9.73ms (7.10+2.63) within IO::CaptureOutput::_proxy::BEGIN@138 which was called: # once (7.10ms+2.63ms) by RBM::BEGIN@12 at line 138
use File::Temp 0.16 'tempfile';
# spent 9.73ms making 1 call to IO::CaptureOutput::_proxy::BEGIN@138 # spent 64µs making 1 call to Exporter::import # spent 18µs making 1 call to UNIVERSAL::VERSION
139226µs278µs
# spent 48µs (19+29) within IO::CaptureOutput::_proxy::BEGIN@139 which was called: # once (19µs+29µs) by RBM::BEGIN@12 at line 139
use File::Basename qw/basename/;
# spent 48µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@139 # spent 29µs making 1 call to Exporter::import
140223µs280µs
# spent 43µs (6+37) within IO::CaptureOutput::_proxy::BEGIN@140 which was called: # once (6µs+37µs) by RBM::BEGIN@12 at line 140
use Symbol qw/gensym qualify qualify_to_ref/;
# spent 43µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@140 # spent 37µs making 1 call to Exporter::import
141284µs265µs
# spent 36µs (6+29) within IO::CaptureOutput::_proxy::BEGIN@141 which was called: # once (6µs+29µs) by RBM::BEGIN@12 at line 141
use Carp;
# spent 36µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@141 # spent 29µs making 1 call to Exporter::import
142
14327890197ms
# spent 93.1ms within IO::CaptureOutput::_proxy::_is_wperl which was called 27890 times, avg 3µs/call: # 27890 times (93.1ms+0s) by IO::CaptureOutput::_proxy::new at line 155, avg 3µs/call
sub _is_wperl { $^O eq 'MSWin32' && basename($^X) eq 'wperl.exe' }
144
145
# spent 14.1s (1.92+12.2) within IO::CaptureOutput::_proxy::new which was called 27890 times, avg 506µs/call: # 13945 times (1.26s+8.28s) by IO::CaptureOutput::_capture at line 49, avg 684µs/call # 13945 times (658ms+3.93s) by IO::CaptureOutput::_capture at line 54, avg 329µs/call
sub new {
1462789015.0ms my $class = shift;
1472789023.1ms my ($orig_fh, $capture_var, $merge_fh, $capture_file) = @_;
1482789058.0ms27890589ms $orig_fh = qualify($orig_fh); # e.g. main::STDOUT
# spent 589ms making 27890 calls to Symbol::qualify, avg 21µs/call
1492789052.1ms27890286ms my $fhref = qualify_to_ref($orig_fh); # e.g. \*STDOUT
# spent 286ms making 27890 calls to Symbol::qualify_to_ref, avg 10µs/call
150
151 # Duplicate the filehandle
152278905.09ms my $saved_fh;
153 {
1542789223.6ms236µs
# spent 22µs (7+14) within IO::CaptureOutput::_proxy::BEGIN@154 which was called: # once (7µs+14µs) by RBM::BEGIN@12 at line 154
no strict 'refs'; ## no critic - needed for 5.005
# spent 22µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@154 # spent 14µs making 1 call to strict::unimport
1552789094.1ms2789093.1ms if ( defined fileno($orig_fh) && ! _is_wperl() ) {
# spent 93.1ms making 27890 calls to IO::CaptureOutput::_proxy::_is_wperl, avg 3µs/call
1562789063.9ms27890375ms $saved_fh = gensym;
# spent 375ms making 27890 calls to Symbol::gensym, avg 13µs/call
15727890585ms27890407ms open $saved_fh, ">&$orig_fh" or croak "Can't redirect <$orig_fh> - $!";
# spent 407ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:open, avg 15µs/call
158 }
159 }
160
161 # Create replacement filehandle if not merging
162278908.31ms my ($newio_fh, $newio_file);
1632789022.0ms if ( ! $merge_fh ) {
1642789029.6ms27890161ms $newio_fh = gensym;
# spent 161ms making 27890 calls to Symbol::gensym, avg 6µs/call
16527890207ms if ($capture_file) {
166 $newio_file = $capture_file;
167 } else {
1682789092.5ms278909.73s (undef, $newio_file) = tempfile;
# spent 9.73s making 27890 calls to File::Temp::tempfile, avg 349µs/call
169 }
17027890611ms27890432ms open $newio_fh, "+>$newio_file" or croak "Can't write temp file for $orig_fh - $!";
# spent 432ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:open, avg 15µs/call
171 }
172 else {
173 $newio_fh = qualify($merge_fh);
174 }
175
176 # Redirect (or merge)
177 {
1782789213.1ms220µs
# spent 13µs (6+7) within IO::CaptureOutput::_proxy::BEGIN@178 which was called: # once (6µs+7µs) by RBM::BEGIN@12 at line 178
no strict 'refs'; ## no critic -- needed for 5.005
# spent 13µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@178 # spent 7µs making 1 call to strict::unimport
17927890268ms27890136ms open $fhref, ">&".fileno($newio_fh) or croak "Can't redirect $orig_fh - $!";
# spent 136ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:open, avg 5µs/call
180 }
181
18227890244ms bless [$$, $orig_fh, $saved_fh, $capture_var, $newio_fh, $newio_file, $capture_file], $class;
183}
184
185
# spent 13.8s (2.61+11.2) within IO::CaptureOutput::_proxy::DESTROY which was called 27890 times, avg 494µs/call: # 27890 times (2.61s+11.2s) by IO::CaptureOutput::_capture at line 62, avg 494µs/call
sub DESTROY {
1862789037.6ms my $self = shift;
187
18827890154ms my ($pid, $orig_fh, $saved_fh, $capture_var, $newio_fh,
189 $newio_file, $capture_file) = @$self;
19027890178ms return unless $pid eq $$; # only cleanup in the process that is capturing
191
192 # restore the original filehandle
19327890174ms27890818ms my $fh_ref = Symbol::qualify_to_ref($orig_fh);
# spent 818ms making 27890 calls to Symbol::qualify_to_ref, avg 29µs/call
19427890423ms55780113ms select((select ($fh_ref), $|=1)[0]);
# spent 113ms making 55780 calls to IO::CaptureOutput::_proxy::CORE:select, avg 2µs/call
19527890909ms27890677ms if (defined $saved_fh) {
# spent 677ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:open, avg 24µs/call
196 open $fh_ref, ">&". fileno($saved_fh) or croak "Can't restore $orig_fh - $!";
197 }
198 else {
199 close $fh_ref;
200 }
201
202 # transfer captured data to the scalar reference if we didn't merge
203 # $newio_file is undef if this file handle is merged to another
2042789023.7ms if (ref $capture_var && $newio_file) {
205 # some versions of perl complain about reading from fd 1 or 2
206 # which could happen if STDOUT and STDERR were closed when $newio
207 # was opened, so we just squelch warnings here and continue
20827890186ms local $^W;
20927890257ms27890101ms seek $newio_fh, 0, 0;
# spent 101ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:seek, avg 4µs/call
210836701.28s27890899ms $$capture_var = do {local $/; <$newio_fh>};
# spent 899ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:readline, avg 32µs/call
211 }
212278901.78s278901.61s close $newio_fh if $newio_file;
# spent 1.61s making 27890 calls to IO::CaptureOutput::_proxy::CORE:close, avg 58µs/call
213
214 # Cleanup
21527890522ms27890353ms return unless defined $newio_file && -e $newio_file;
# spent 353ms making 27890 calls to IO::CaptureOutput::_proxy::CORE:ftis, avg 13µs/call
216278908.20ms return if $capture_file; # the "temp" file was explicitly named
217278906.98s278906.61s unlink $newio_file or carp "Couldn't remove temp file '$newio_file' - $!";
# spent 6.61s making 27890 calls to IO::CaptureOutput::_proxy::CORE:unlink, avg 237µs/call
218}
219
220111µs1;
221
222__END__
 
# spent 900ns within IO::CaptureOutput::CORE:match which was called: # once (900ns+0s) by RBM::BEGIN@12 at line 94
sub IO::CaptureOutput::CORE:match; # opcode
# spent 349s within IO::CaptureOutput::CORE:system which was called 13945 times, avg 25.0ms/call: # 13945 times (349s+0s) by IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:74] at line 74, avg 25.0ms/call
sub IO::CaptureOutput::CORE:system; # opcode
# spent 1.61s within IO::CaptureOutput::_proxy::CORE:close which was called 27890 times, avg 58µs/call: # 27890 times (1.61s+0s) by IO::CaptureOutput::_proxy::DESTROY at line 212, avg 58µs/call
sub IO::CaptureOutput::_proxy::CORE:close; # opcode
# spent 353ms within IO::CaptureOutput::_proxy::CORE:ftis which was called 27890 times, avg 13µs/call: # 27890 times (353ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 215, avg 13µs/call
sub IO::CaptureOutput::_proxy::CORE:ftis; # opcode
# spent 1.65s within IO::CaptureOutput::_proxy::CORE:open which was called 111560 times, avg 15µs/call: # 27890 times (677ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 195, avg 24µs/call # 27890 times (432ms+0s) by IO::CaptureOutput::_proxy::new at line 170, avg 15µs/call # 27890 times (407ms+0s) by IO::CaptureOutput::_proxy::new at line 157, avg 15µs/call # 27890 times (136ms+0s) by IO::CaptureOutput::_proxy::new at line 179, avg 5µs/call
sub IO::CaptureOutput::_proxy::CORE:open; # opcode
# spent 899ms within IO::CaptureOutput::_proxy::CORE:readline which was called 27890 times, avg 32µs/call: # 27890 times (899ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 210, avg 32µs/call
sub IO::CaptureOutput::_proxy::CORE:readline; # opcode
# spent 101ms within IO::CaptureOutput::_proxy::CORE:seek which was called 27890 times, avg 4µs/call: # 27890 times (101ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 209, avg 4µs/call
sub IO::CaptureOutput::_proxy::CORE:seek; # opcode
# spent 113ms within IO::CaptureOutput::_proxy::CORE:select which was called 55780 times, avg 2µs/call: # 55780 times (113ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 194, avg 2µs/call
sub IO::CaptureOutput::_proxy::CORE:select; # opcode
# spent 6.61s within IO::CaptureOutput::_proxy::CORE:unlink which was called 27890 times, avg 237µs/call: # 27890 times (6.61s+0s) by IO::CaptureOutput::_proxy::DESTROY at line 217, avg 237µs/call
sub IO::CaptureOutput::_proxy::CORE:unlink; # opcode
Report produced by the NYTProf 6.06 Perl profiler, developed by Tim Bunce based on work by Adam Kaplan and Salvador Fandiño García.