← Index
NYTProf Performance Profile   « line view »
For rbm/rbm
  Run on Wed Feb 12 20:36:06 2020
Reported on Wed Feb 12 21:42:25 2020

Filename/usr/share/perl5/IO/CaptureOutput.pm
StatementsExecuted 223864 statements in 152s
Subroutines
Calls P F Exclusive
Time
Inclusive
Time
Subroutine
228411149s149sIO::CaptureOutput::::CORE:system IO::CaptureOutput::CORE:system (opcode)
4568111.37s1.37sIO::CaptureOutput::_proxy::::CORE:unlinkIO::CaptureOutput::_proxy::CORE:unlink (opcode)
456811373ms2.48sIO::CaptureOutput::_proxy::::DESTROYIO::CaptureOutput::_proxy::DESTROY
228411344ms154sIO::CaptureOutput::::_capture IO::CaptureOutput::_capture
1827241306ms306msIO::CaptureOutput::_proxy::::CORE:openIO::CaptureOutput::_proxy::CORE:open (opcode)
456821262ms2.32sIO::CaptureOutput::_proxy::::newIO::CaptureOutput::_proxy::new
456811254ms254msIO::CaptureOutput::_proxy::::CORE:closeIO::CaptureOutput::_proxy::CORE:close (opcode)
228411204ms149sIO::CaptureOutput::::__ANON__[:74] IO::CaptureOutput::__ANON__[:74]
456811148ms148msIO::CaptureOutput::_proxy::::CORE:readlineIO::CaptureOutput::_proxy::CORE:readline (opcode)
22847399.8ms154sIO::CaptureOutput::::capture_exec IO::CaptureOutput::capture_exec
45681156.6ms56.6msIO::CaptureOutput::_proxy::::CORE:ftisIO::CaptureOutput::_proxy::CORE:ftis (opcode)
91361130.1ms30.1msIO::CaptureOutput::_proxy::::CORE:selectIO::CaptureOutput::_proxy::CORE:select (opcode)
45681119.7ms19.7msIO::CaptureOutput::_proxy::::_is_wperlIO::CaptureOutput::_proxy::_is_wperl
22841115.8ms15.8msIO::CaptureOutput::::_validate IO::CaptureOutput::_validate
45681114.0ms14.0msIO::CaptureOutput::_proxy::::CORE:seekIO::CaptureOutput::_proxy::CORE:seek (opcode)
2284117.77ms7.77msIO::CaptureOutput::::__ANON__[:94] IO::CaptureOutput::__ANON__[:94]
1116.62ms9.38msIO::CaptureOutput::_proxy::::BEGIN@138IO::CaptureOutput::_proxy::BEGIN@138
11111µs14µsRBM::::BEGIN@1.4 RBM::BEGIN@1.4
11110µs62µsIO::CaptureOutput::::BEGIN@9 IO::CaptureOutput::BEGIN@9
11110µs53µsIO::CaptureOutput::::BEGIN@11 IO::CaptureOutput::BEGIN@11
1118µs34µsRBM::::BEGIN@2.5 RBM::BEGIN@2.5
1118µs25µsIO::CaptureOutput::_proxy::::BEGIN@154IO::CaptureOutput::_proxy::BEGIN@154
1118µs72µsIO::CaptureOutput::_proxy::::BEGIN@139IO::CaptureOutput::_proxy::BEGIN@139
1117µs143µsIO::CaptureOutput::_proxy::::BEGIN@141IO::CaptureOutput::_proxy::BEGIN@141
1117µs46µsIO::CaptureOutput::_proxy::::BEGIN@140IO::CaptureOutput::_proxy::BEGIN@140
1116µs18µsIO::CaptureOutput::::BEGIN@10 IO::CaptureOutput::BEGIN@10
1116µs13µsIO::CaptureOutput::_proxy::::BEGIN@178IO::CaptureOutput::_proxy::BEGIN@178
1111µs1µsIO::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
1248µs218µs
# spent 14µs (11+3) within RBM::BEGIN@1.4 which was called: # once (11µs+3µs) by RBM::BEGIN@12 at line 1
use strict;
# spent 14µs making 1 call to RBM::BEGIN@1.4 # spent 3µs making 1 call to strict::import
2243µs261µs
# spent 34µs (8+26) within RBM::BEGIN@2.5 which was called: # once (8µs+26µs) by RBM::BEGIN@12 at line 2
use warnings;
# spent 34µs making 1 call to RBM::BEGIN@2.5 # spent 26µ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
9227µs2115µs
# spent 62µs (10+52) within IO::CaptureOutput::BEGIN@9 which was called: # once (10µs+52µs) by RBM::BEGIN@12 at line 9
use vars qw/@ISA @EXPORT_OK %EXPORT_TAGS $CarpLevel/;
# spent 62µs making 1 call to IO::CaptureOutput::BEGIN@9 # spent 52µs making 1 call to vars::import
10220µs230µs
# spent 18µ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 18µs making 1 call to IO::CaptureOutput::BEGIN@10 # spent 12µs making 1 call to Exporter::import
112607µs296µs
# spent 53µs (10+43) within IO::CaptureOutput::BEGIN@11 which was called: # once (10µs+43µs) by RBM::BEGIN@12 at line 11
use Carp qw/croak/;
# spent 53µs making 1 call to IO::CaptureOutput::BEGIN@11 # spent 43µs making 1 call to Exporter::import
1219µs@ISA = 'Exporter';
1311µs@EXPORT_OK = qw/capture capture_exec qxx capture_exec_combined qxy/;
1412µs%EXPORT_TAGS = (all => \@EXPORT_OK);
151300ns$CarpLevel = 0; # help capture report errors at the right level
16
17
# spent 154s (344ms+154) within IO::CaptureOutput::_capture which was called 2284 times, avg 67.6ms/call: # 2284 times (344ms+154s) by IO::CaptureOutput::capture_exec at line 74, avg 67.6ms/call
sub _capture (&@) { ## no critic
1822841.86ms my ($code, $output, $error, $output_file, $error_file) = @_;
19
20 # check for valid combinations of input
21 {
2245684.61ms local $Carp::CarpLevel = 1;
2322848.22ms228415.8ms my $error = _validate($output, $error, $output_file, $error_file);
# spent 15.8ms making 2284 calls to IO::CaptureOutput::_validate, avg 7µs/call
2422841.79ms 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
2922842.32ms if ( defined $output || defined $error ) {
3022842.77ms for ($output, $error) {
3145681.90ms $_ = \do { my $s; $s = ''} unless ref $_;
3245687.37ms $$_ = '' 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
4022844.56ms my $should_merge =
41 (defined $error && defined $output && $output == $error) ||
42 ( !defined $output && !defined $error ) ||
43 0;
44
452284669µs 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
49228420.5ms22841.59s if ( !defined $output || $output != \undef ) {
# spent 1.59s making 2284 calls to IO::CaptureOutput::_proxy::new, avg 694µs/call
50 $capture_out = IO::CaptureOutput::_proxy->new(
51 'STDOUT', $output, undef, $output_file
52 );
53 }
5422847.41ms2284731ms if ( !defined $error || $error != \undef ) {
# spent 731ms making 2284 calls to IO::CaptureOutput::_proxy::new, avg 320µ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
622284210ms6852152s &$code();
# spent 149s making 2284 calls to IO::CaptureOutput::__ANON__[IO/CaptureOutput.pm:74], avg 65.3ms/call # spent 2.48s making 4568 calls to IO::CaptureOutput::_proxy::DESTROY, avg 544µ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 154s (99.8ms+154) within IO::CaptureOutput::capture_exec which was called 2284 times, avg 67.6ms/call: # 1991 times (89.3ms+142s) by RBM::DefaultConfig::lsb_release at line 60 of /root/tor-browser-build/rbm/lib/RBM/DefaultConfig.pm, avg 71.4ms/call # 87 times (3.15ms+917ms) by RBM::git_need_fetch at line 382 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 10.6ms/call # 86 times (3.38ms+992ms) by RBM::execute at line 487 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 11.6ms/call # 86 times (2.64ms+965ms) by RBM::run_script at line 471 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 11.2ms/call # 15 times (636µs+901ms) by RBM::__ANON__[(eval 14)[rbm/lib/RBM.pm:39]:16] at line 14 of (eval 14)[rbm/lib/RBM.pm:39], avg 60.1ms/call # 15 times (588µs+890ms) by RBM::__ANON__[(eval 14)[rbm/lib/RBM.pm:39]:10] at line 8 of (eval 14)[rbm/lib/RBM.pm:39], avg 59.4ms/call # 4 times (134µs+7.47s) by RBM::run_script at line 468 of /root/tor-browser-build/rbm/lib/RBM.pm, avg 1.87s/call
sub capture_exec {
7222843.72ms my @args = @_;
732284825µs my ($output, $error);
744568149s6852303s
# spent 149s (204ms+149) within IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:74] which was called 2284 times, avg 65.3ms/call: # 2284 times (204ms+149s) by IO::CaptureOutput::_capture at line 62, avg 65.3ms/call
my $exit = _capture sub { system _shell_quote(@args) }, \$output, \$error;
# spent 154s making 2284 calls to IO::CaptureOutput::_capture, avg 67.6ms/call # spent 149s making 2284 calls to IO::CaptureOutput::CORE:system, avg 65.2ms/call # spent 7.77ms making 2284 calls to IO::CaptureOutput::__ANON__[IO/CaptureOutput.pm:94], avg 3µs/call
7522842.60ms my $success = ($exit == 0 ) ? 1 : 0 ;
7622843.34ms $? = $exit;
77228434.8ms return wantarray ? ($output, $error, $success, $exit) : $output;
78}
79
8011µs*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
911900ns*qxy = \&capture_exec_combined;
92
93# extra quoting required on Win32 systems
94228531.3ms11µs
# spent 7.77ms within IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:94] which was called 2284 times, avg 3µs/call: # 2284 times (7.77ms+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 1µs 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 15.8ms within IO::CaptureOutput::_validate which was called 2284 times, avg 7µs/call: # 2284 times (15.8ms+0s) by IO::CaptureOutput::_capture at line 23, avg 7µs/call
sub _validate {
11022841.62ms my ($output, $error, $output_file, $error_file) = @_;
111
112 # default to "ok"
11322841.89ms my $msg = q{};
114
115 # \$out, \$out, $outfile, $errfile
11622845.70ms 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
132228410.2ms 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;
1383248µs39.46ms
# spent 9.38ms (6.62+2.76) within IO::CaptureOutput::_proxy::BEGIN@138 which was called: # once (6.62ms+2.76ms) by RBM::BEGIN@12 at line 138
use File::Temp 0.16 'tempfile';
# spent 9.38ms making 1 call to IO::CaptureOutput::_proxy::BEGIN@138 # spent 65µs making 1 call to Exporter::import # spent 18µs making 1 call to UNIVERSAL::VERSION
139229µs2136µs
# spent 72µs (8+64) within IO::CaptureOutput::_proxy::BEGIN@139 which was called: # once (8µs+64µs) by RBM::BEGIN@12 at line 139
use File::Basename qw/basename/;
# spent 72µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@139 # spent 64µs making 1 call to Exporter::import
140223µs284µs
# spent 46µs (7+39) within IO::CaptureOutput::_proxy::BEGIN@140 which was called: # once (7µs+39µs) by RBM::BEGIN@12 at line 140
use Symbol qw/gensym qualify qualify_to_ref/;
# spent 46µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@140 # spent 39µs making 1 call to Exporter::import
141286µs2279µs
# spent 143µs (7+136) within IO::CaptureOutput::_proxy::BEGIN@141 which was called: # once (7µs+136µs) by RBM::BEGIN@12 at line 141
use Carp;
# spent 143µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@141 # spent 136µs making 1 call to Exporter::import
142
143456834.9ms
# spent 19.7ms within IO::CaptureOutput::_proxy::_is_wperl which was called 4568 times, avg 4µs/call: # 4568 times (19.7ms+0s) by IO::CaptureOutput::_proxy::new at line 155, avg 4µs/call
sub _is_wperl { $^O eq 'MSWin32' && basename($^X) eq 'wperl.exe' }
144
145
# spent 2.32s (262ms+2.05) within IO::CaptureOutput::_proxy::new which was called 4568 times, avg 507µs/call: # 2284 times (197ms+1.39s) by IO::CaptureOutput::_capture at line 49, avg 694µs/call # 2284 times (65.8ms+665ms) by IO::CaptureOutput::_capture at line 54, avg 320µs/call
sub new {
14645682.38ms my $class = shift;
14745683.29ms my ($orig_fh, $capture_var, $merge_fh, $capture_file) = @_;
148456812.8ms456884.3ms $orig_fh = qualify($orig_fh); # e.g. main::STDOUT
# spent 84.3ms making 4568 calls to Symbol::qualify, avg 18µs/call
149456810.1ms456855.3ms my $fhref = qualify_to_ref($orig_fh); # e.g. \*STDOUT
# spent 55.3ms making 4568 calls to Symbol::qualify_to_ref, avg 12µs/call
150
151 # Duplicate the filehandle
1524568846µs my $saved_fh;
153 {
15445702.51ms242µs
# spent 25µs (8+17) within IO::CaptureOutput::_proxy::BEGIN@154 which was called: # once (8µs+17µs) by RBM::BEGIN@12 at line 154
no strict 'refs'; ## no critic - needed for 5.005
# spent 25µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@154 # spent 17µs making 1 call to strict::unimport
155456816.9ms456819.7ms if ( defined fileno($orig_fh) && ! _is_wperl() ) {
# spent 19.7ms making 4568 calls to IO::CaptureOutput::_proxy::_is_wperl, avg 4µs/call
156456810.2ms456850.2ms $saved_fh = gensym;
# spent 50.2ms making 4568 calls to Symbol::gensym, avg 11µs/call
1574568123ms456897.0ms open $saved_fh, ">&$orig_fh" or croak "Can't redirect <$orig_fh> - $!";
# spent 97.0ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:open, avg 21µs/call
158 }
159 }
160
161 # Create replacement filehandle if not merging
16245681.41ms my ($newio_fh, $newio_file);
16345684.18ms if ( ! $merge_fh ) {
16445684.59ms456824.6ms $newio_fh = gensym;
# spent 24.6ms making 4568 calls to Symbol::gensym, avg 5µs/call
165456842.2ms if ($capture_file) {
166 $newio_file = $capture_file;
167 } else {
168456812.7ms45681.62s (undef, $newio_file) = tempfile;
# spent 1.62s making 4568 calls to File::Temp::tempfile, avg 355µs/call
169 }
170456890.5ms456874.7ms open $newio_fh, "+>$newio_file" or croak "Can't write temp file for $orig_fh - $!";
# spent 74.7ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:open, avg 16µs/call
171 }
172 else {
173 $newio_fh = qualify($merge_fh);
174 }
175
176 # Redirect (or merge)
177 {
17845702.22ms220µ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
179456839.2ms456824.9ms open $fhref, ">&".fileno($newio_fh) or croak "Can't redirect $orig_fh - $!";
# spent 24.9ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:open, avg 5µs/call
180 }
181
182456853.0ms bless [$$, $orig_fh, $saved_fh, $capture_var, $newio_fh, $newio_file, $capture_file], $class;
183}
184
185
# spent 2.48s (373ms+2.11) within IO::CaptureOutput::_proxy::DESTROY which was called 4568 times, avg 544µs/call: # 4568 times (373ms+2.11s) by IO::CaptureOutput::_capture at line 62, avg 544µs/call
sub DESTROY {
18645686.08ms my $self = shift;
187
188456824.9ms my ($pid, $orig_fh, $saved_fh, $capture_var, $newio_fh,
189 $newio_file, $capture_file) = @$self;
190456826.6ms return unless $pid eq $$; # only cleanup in the process that is capturing
191
192 # restore the original filehandle
193456813.0ms4568123ms my $fh_ref = Symbol::qualify_to_ref($orig_fh);
# spent 123ms making 4568 calls to Symbol::qualify_to_ref, avg 27µs/call
194456866.3ms913630.1ms select((select ($fh_ref), $|=1)[0]);
# spent 30.1ms making 9136 calls to IO::CaptureOutput::_proxy::CORE:select, avg 3µs/call
1954568166ms4568109ms if (defined $saved_fh) {
# spent 109ms making 4568 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
20445684.19ms 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
208456821.9ms local $^W;
209456833.6ms456814.0ms seek $newio_fh, 0, 0;
# spent 14.0ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:seek, avg 3µs/call
21013704202ms4568148ms $$capture_var = do {local $/; <$newio_fh>};
# spent 148ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:readline, avg 32µs/call
211 }
2124568273ms4568254ms close $newio_fh if $newio_file;
# spent 254ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:close, avg 56µs/call
213
214 # Cleanup
215456885.1ms456856.6ms return unless defined $newio_file && -e $newio_file;
# spent 56.6ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:ftis, avg 12µs/call
21645681.65ms return if $capture_file; # the "temp" file was explicitly named
21745681.44s45681.37s unlink $newio_file or carp "Couldn't remove temp file '$newio_file' - $!";
# spent 1.37s making 4568 calls to IO::CaptureOutput::_proxy::CORE:unlink, avg 301µs/call
218}
219
220111µs1;
221
222__END__
 
# spent 1µs within IO::CaptureOutput::CORE:match which was called: # once (1µs+0s) by RBM::BEGIN@12 at line 94
sub IO::CaptureOutput::CORE:match; # opcode
# spent 149s within IO::CaptureOutput::CORE:system which was called 2284 times, avg 65.2ms/call: # 2284 times (149s+0s) by IO::CaptureOutput::__ANON__[/usr/share/perl5/IO/CaptureOutput.pm:74] at line 74, avg 65.2ms/call
sub IO::CaptureOutput::CORE:system; # opcode
# spent 254ms within IO::CaptureOutput::_proxy::CORE:close which was called 4568 times, avg 56µs/call: # 4568 times (254ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 212, avg 56µs/call
sub IO::CaptureOutput::_proxy::CORE:close; # opcode
# spent 56.6ms within IO::CaptureOutput::_proxy::CORE:ftis which was called 4568 times, avg 12µs/call: # 4568 times (56.6ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 215, avg 12µs/call
sub IO::CaptureOutput::_proxy::CORE:ftis; # opcode
# spent 306ms within IO::CaptureOutput::_proxy::CORE:open which was called 18272 times, avg 17µs/call: # 4568 times (109ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 195, avg 24µs/call # 4568 times (97.0ms+0s) by IO::CaptureOutput::_proxy::new at line 157, avg 21µs/call # 4568 times (74.7ms+0s) by IO::CaptureOutput::_proxy::new at line 170, avg 16µs/call # 4568 times (24.9ms+0s) by IO::CaptureOutput::_proxy::new at line 179, avg 5µs/call
sub IO::CaptureOutput::_proxy::CORE:open; # opcode
# spent 148ms within IO::CaptureOutput::_proxy::CORE:readline which was called 4568 times, avg 32µs/call: # 4568 times (148ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 210, avg 32µs/call
sub IO::CaptureOutput::_proxy::CORE:readline; # opcode
# spent 14.0ms within IO::CaptureOutput::_proxy::CORE:seek which was called 4568 times, avg 3µs/call: # 4568 times (14.0ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 209, avg 3µs/call
sub IO::CaptureOutput::_proxy::CORE:seek; # opcode
# spent 30.1ms within IO::CaptureOutput::_proxy::CORE:select which was called 9136 times, avg 3µs/call: # 9136 times (30.1ms+0s) by IO::CaptureOutput::_proxy::DESTROY at line 194, avg 3µs/call
sub IO::CaptureOutput::_proxy::CORE:select; # opcode
# spent 1.37s within IO::CaptureOutput::_proxy::CORE:unlink which was called 4568 times, avg 301µs/call: # 4568 times (1.37s+0s) by IO::CaptureOutput::_proxy::DESTROY at line 217, avg 301µs/call
sub IO::CaptureOutput::_proxy::CORE:unlink; # opcode