Filename | /usr/share/perl5/IO/CaptureOutput.pm |
Statements | Executed 223864 statements in 152s |
Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
---|---|---|---|---|---|
2284 | 1 | 1 | 149s | 149s | CORE:system (opcode) | IO::CaptureOutput::
4568 | 1 | 1 | 1.37s | 1.37s | CORE:unlink (opcode) | IO::CaptureOutput::_proxy::
4568 | 1 | 1 | 373ms | 2.48s | DESTROY | IO::CaptureOutput::_proxy::
2284 | 1 | 1 | 344ms | 154s | _capture | IO::CaptureOutput::
18272 | 4 | 1 | 306ms | 306ms | CORE:open (opcode) | IO::CaptureOutput::_proxy::
4568 | 2 | 1 | 262ms | 2.32s | new | IO::CaptureOutput::_proxy::
4568 | 1 | 1 | 254ms | 254ms | CORE:close (opcode) | IO::CaptureOutput::_proxy::
2284 | 1 | 1 | 204ms | 149s | __ANON__[:74] | IO::CaptureOutput::
4568 | 1 | 1 | 148ms | 148ms | CORE:readline (opcode) | IO::CaptureOutput::_proxy::
2284 | 7 | 3 | 99.8ms | 154s | capture_exec | IO::CaptureOutput::
4568 | 1 | 1 | 56.6ms | 56.6ms | CORE:ftis (opcode) | IO::CaptureOutput::_proxy::
9136 | 1 | 1 | 30.1ms | 30.1ms | CORE:select (opcode) | IO::CaptureOutput::_proxy::
4568 | 1 | 1 | 19.7ms | 19.7ms | _is_wperl | IO::CaptureOutput::_proxy::
2284 | 1 | 1 | 15.8ms | 15.8ms | _validate | IO::CaptureOutput::
4568 | 1 | 1 | 14.0ms | 14.0ms | CORE:seek (opcode) | IO::CaptureOutput::_proxy::
2284 | 1 | 1 | 7.77ms | 7.77ms | __ANON__[:94] | IO::CaptureOutput::
1 | 1 | 1 | 6.62ms | 9.38ms | BEGIN@138 | IO::CaptureOutput::_proxy::
1 | 1 | 1 | 11µs | 14µs | BEGIN@1.4 | RBM::
1 | 1 | 1 | 10µs | 62µs | BEGIN@9 | IO::CaptureOutput::
1 | 1 | 1 | 10µs | 53µs | BEGIN@11 | IO::CaptureOutput::
1 | 1 | 1 | 8µs | 34µs | BEGIN@2.5 | RBM::
1 | 1 | 1 | 8µs | 25µs | BEGIN@154 | IO::CaptureOutput::_proxy::
1 | 1 | 1 | 8µs | 72µs | BEGIN@139 | IO::CaptureOutput::_proxy::
1 | 1 | 1 | 7µs | 143µs | BEGIN@141 | IO::CaptureOutput::_proxy::
1 | 1 | 1 | 7µs | 46µs | BEGIN@140 | IO::CaptureOutput::_proxy::
1 | 1 | 1 | 6µs | 18µs | BEGIN@10 | IO::CaptureOutput::
1 | 1 | 1 | 6µs | 13µs | BEGIN@178 | IO::CaptureOutput::_proxy::
1 | 1 | 1 | 1µs | 1µs | CORE:match (opcode) | IO::CaptureOutput::
0 | 0 | 0 | 0s | 0s | __ANON__[:85] | IO::CaptureOutput::
0 | 0 | 0 | 0s | 0s | _shell_quote_win32 | IO::CaptureOutput::
0 | 0 | 0 | 0s | 0s | capture | IO::CaptureOutput::
0 | 0 | 0 | 0s | 0s | capture_exec_combined | IO::CaptureOutput::
Line | State ments |
Time on line |
Calls | Time in subs |
Code |
---|---|---|---|---|---|
1 | 2 | 48µs | 2 | 18µ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 # spent 14µs making 1 call to RBM::BEGIN@1.4
# spent 3µs making 1 call to strict::import |
2 | 2 | 43µs | 2 | 61µ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 # spent 34µs making 1 call to RBM::BEGIN@2.5
# spent 26µs making 1 call to warnings::import |
3 | |||||
4 | package IO::CaptureOutput; | ||||
5 | # ABSTRACT: capture STDOUT and STDERR from Perl code, subprocesses or XS | ||||
6 | |||||
7 | 1 | 1µs | our $VERSION = '1.1104'; | ||
8 | |||||
9 | 2 | 27µs | 2 | 115µ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 # spent 62µs making 1 call to IO::CaptureOutput::BEGIN@9
# spent 52µs making 1 call to vars::import |
10 | 2 | 20µs | 2 | 30µ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 # spent 18µs making 1 call to IO::CaptureOutput::BEGIN@10
# spent 12µs making 1 call to Exporter::import |
11 | 2 | 607µs | 2 | 96µ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 # spent 53µs making 1 call to IO::CaptureOutput::BEGIN@11
# spent 43µs making 1 call to Exporter::import |
12 | 1 | 9µs | @ISA = 'Exporter'; | ||
13 | 1 | 1µs | @EXPORT_OK = qw/capture capture_exec qxx capture_exec_combined qxy/; | ||
14 | 1 | 2µs | %EXPORT_TAGS = (all => \@EXPORT_OK); | ||
15 | 1 | 300ns | $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 | ||||
18 | 2284 | 1.86ms | my ($code, $output, $error, $output_file, $error_file) = @_; | ||
19 | |||||
20 | # check for valid combinations of input | ||||
21 | { | ||||
22 | 4568 | 4.61ms | local $Carp::CarpLevel = 1; | ||
23 | 2284 | 8.22ms | 2284 | 15.8ms | my $error = _validate($output, $error, $output_file, $error_file); # spent 15.8ms making 2284 calls to IO::CaptureOutput::_validate, avg 7µs/call |
24 | 2284 | 1.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 | ||||
29 | 2284 | 2.32ms | if ( defined $output || defined $error ) { | ||
30 | 2284 | 2.77ms | for ($output, $error) { | ||
31 | 4568 | 1.90ms | $_ = \do { my $s; $s = ''} unless ref $_; | ||
32 | 4568 | 7.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 | ||||
40 | 2284 | 4.56ms | my $should_merge = | ||
41 | (defined $error && defined $output && $output == $error) || | ||||
42 | ( !defined $output && !defined $error ) || | ||||
43 | 0; | ||||
44 | |||||
45 | 2284 | 669µ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 | ||||
49 | 2284 | 20.5ms | 2284 | 1.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 | } | ||||
54 | 2284 | 7.41ms | 2284 | 731ms | 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 | ||||
62 | 2284 | 210ms | 6852 | 152s | &$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 | ||||
67 | sub 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 | ||||
72 | 2284 | 3.72ms | my @args = @_; | ||
73 | 2284 | 825µs | my ($output, $error); | ||
74 | 4568 | 149s | 6852 | 303s | # 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 # 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 |
75 | 2284 | 2.60ms | my $success = ($exit == 0 ) ? 1 : 0 ; | ||
76 | 2284 | 3.34ms | $? = $exit; | ||
77 | 2284 | 34.8ms | return wantarray ? ($output, $error, $success, $exit) : $output; | ||
78 | } | ||||
79 | |||||
80 | 1 | 1µs | *qxx = \&capture_exec; | ||
81 | |||||
82 | sub 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 | |||||
91 | 1 | 900ns | *qxy = \&capture_exec_combined; | ||
92 | |||||
93 | # extra quoting required on Win32 systems | ||||
94 | 2285 | 31.3ms | 1 | 1µ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 # spent 1µs making 1 call to IO::CaptureOutput::CORE:match |
95 | sub _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 | ||||
110 | 2284 | 1.62ms | my ($output, $error, $output_file, $error_file) = @_; | ||
111 | |||||
112 | # default to "ok" | ||||
113 | 2284 | 1.89ms | my $msg = q{}; | ||
114 | |||||
115 | # \$out, \$out, $outfile, $errfile | ||||
116 | 2284 | 5.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 | |||||
132 | 2284 | 10.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 | ||||
137 | package IO::CaptureOutput::_proxy; | ||||
138 | 3 | 248µs | 3 | 9.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 # 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 |
139 | 2 | 29µs | 2 | 136µ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 # spent 72µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@139
# spent 64µs making 1 call to Exporter::import |
140 | 2 | 23µs | 2 | 84µ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 # spent 46µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@140
# spent 39µs making 1 call to Exporter::import |
141 | 2 | 86µs | 2 | 279µ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 # spent 143µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@141
# spent 136µs making 1 call to Exporter::import |
142 | |||||
143 | 4568 | 34.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 | ||
144 | |||||
145 | sub new { | ||||
146 | 4568 | 2.38ms | my $class = shift; | ||
147 | 4568 | 3.29ms | my ($orig_fh, $capture_var, $merge_fh, $capture_file) = @_; | ||
148 | 4568 | 12.8ms | 4568 | 84.3ms | $orig_fh = qualify($orig_fh); # e.g. main::STDOUT # spent 84.3ms making 4568 calls to Symbol::qualify, avg 18µs/call |
149 | 4568 | 10.1ms | 4568 | 55.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 | ||||
152 | 4568 | 846µs | my $saved_fh; | ||
153 | { | ||||
154 | 4570 | 2.51ms | 2 | 42µ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 # spent 25µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@154
# spent 17µs making 1 call to strict::unimport |
155 | 4568 | 16.9ms | 4568 | 19.7ms | if ( defined fileno($orig_fh) && ! _is_wperl() ) { # spent 19.7ms making 4568 calls to IO::CaptureOutput::_proxy::_is_wperl, avg 4µs/call |
156 | 4568 | 10.2ms | 4568 | 50.2ms | $saved_fh = gensym; # spent 50.2ms making 4568 calls to Symbol::gensym, avg 11µs/call |
157 | 4568 | 123ms | 4568 | 97.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 | ||||
162 | 4568 | 1.41ms | my ($newio_fh, $newio_file); | ||
163 | 4568 | 4.18ms | if ( ! $merge_fh ) { | ||
164 | 4568 | 4.59ms | 4568 | 24.6ms | $newio_fh = gensym; # spent 24.6ms making 4568 calls to Symbol::gensym, avg 5µs/call |
165 | 4568 | 42.2ms | if ($capture_file) { | ||
166 | $newio_file = $capture_file; | ||||
167 | } else { | ||||
168 | 4568 | 12.7ms | 4568 | 1.62s | (undef, $newio_file) = tempfile; # spent 1.62s making 4568 calls to File::Temp::tempfile, avg 355µs/call |
169 | } | ||||
170 | 4568 | 90.5ms | 4568 | 74.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 | { | ||||
178 | 4570 | 2.22ms | 2 | 20µ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 # spent 13µs making 1 call to IO::CaptureOutput::_proxy::BEGIN@178
# spent 7µs making 1 call to strict::unimport |
179 | 4568 | 39.2ms | 4568 | 24.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 | |||||
182 | 4568 | 53.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 | ||||
186 | 4568 | 6.08ms | my $self = shift; | ||
187 | |||||
188 | 4568 | 24.9ms | my ($pid, $orig_fh, $saved_fh, $capture_var, $newio_fh, | ||
189 | $newio_file, $capture_file) = @$self; | ||||
190 | 4568 | 26.6ms | return unless $pid eq $$; # only cleanup in the process that is capturing | ||
191 | |||||
192 | # restore the original filehandle | ||||
193 | 4568 | 13.0ms | 4568 | 123ms | my $fh_ref = Symbol::qualify_to_ref($orig_fh); # spent 123ms making 4568 calls to Symbol::qualify_to_ref, avg 27µs/call |
194 | 4568 | 66.3ms | 9136 | 30.1ms | select((select ($fh_ref), $|=1)[0]); # spent 30.1ms making 9136 calls to IO::CaptureOutput::_proxy::CORE:select, avg 3µs/call |
195 | 4568 | 166ms | 4568 | 109ms | 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 | ||||
204 | 4568 | 4.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 | ||||
208 | 4568 | 21.9ms | local $^W; | ||
209 | 4568 | 33.6ms | 4568 | 14.0ms | seek $newio_fh, 0, 0; # spent 14.0ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:seek, avg 3µs/call |
210 | 13704 | 202ms | 4568 | 148ms | $$capture_var = do {local $/; <$newio_fh>}; # spent 148ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:readline, avg 32µs/call |
211 | } | ||||
212 | 4568 | 273ms | 4568 | 254ms | close $newio_fh if $newio_file; # spent 254ms making 4568 calls to IO::CaptureOutput::_proxy::CORE:close, avg 56µs/call |
213 | |||||
214 | # Cleanup | ||||
215 | 4568 | 85.1ms | 4568 | 56.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 |
216 | 4568 | 1.65ms | return if $capture_file; # the "temp" file was explicitly named | ||
217 | 4568 | 1.44s | 4568 | 1.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 | |||||
220 | 1 | 11µs | 1; | ||
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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 |