| line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
|
1
|
|
|
|
|
|
|
package IPC::Run3::ProfReporter; |
|
2
|
|
|
|
|
|
|
|
|
3
|
|
|
|
|
|
|
$VERSION = 0.048; |
|
4
|
|
|
|
|
|
|
|
|
5
|
|
|
|
|
|
|
=head1 NAME |
|
6
|
|
|
|
|
|
|
|
|
7
|
|
|
|
|
|
|
IPC::Run3::ProfReporter - base class for handling profiling data |
|
8
|
|
|
|
|
|
|
|
|
9
|
|
|
|
|
|
|
=head1 SYNOPSIS |
|
10
|
|
|
|
|
|
|
|
|
11
|
|
|
|
|
|
|
=head1 DESCRIPTION |
|
12
|
|
|
|
|
|
|
|
|
13
|
|
|
|
|
|
|
See L and for an example subclass. |
|
14
|
|
|
|
|
|
|
|
|
15
|
|
|
|
|
|
|
This class just notes and accumulates times; subclasses use methods like |
|
16
|
|
|
|
|
|
|
"handle_app_call", "handle_run_exit" and "handle_app_exit" to emit reports on |
|
17
|
|
|
|
|
|
|
it. The default methods for these handlers are noops. |
|
18
|
|
|
|
|
|
|
|
|
19
|
|
|
|
|
|
|
If run from the command line, a reporter will be created and run on |
|
20
|
|
|
|
|
|
|
each logfile given as a command line parameter or on run3.out if none |
|
21
|
|
|
|
|
|
|
are given. |
|
22
|
|
|
|
|
|
|
|
|
23
|
|
|
|
|
|
|
This allows reports to be run like: |
|
24
|
|
|
|
|
|
|
|
|
25
|
|
|
|
|
|
|
perl -MIPC::Run3::ProfPP -e1 |
|
26
|
|
|
|
|
|
|
perl -MIPC::Run3::ProfPP -e1 foo.out bar.out |
|
27
|
|
|
|
|
|
|
|
|
28
|
|
|
|
|
|
|
Use "-" to read from STDIN (the log file format is meant to be moderately |
|
29
|
|
|
|
|
|
|
greppable): |
|
30
|
|
|
|
|
|
|
|
|
31
|
|
|
|
|
|
|
grep "^cvs " run3.out perl -MIPC::Run3::ProfPP -e1 - |
|
32
|
|
|
|
|
|
|
|
|
33
|
|
|
|
|
|
|
Use --app to show only application level statistics (ie don't emit |
|
34
|
|
|
|
|
|
|
a report section for each command run). |
|
35
|
|
|
|
|
|
|
|
|
36
|
|
|
|
|
|
|
=cut |
|
37
|
|
|
|
|
|
|
|
|
38
|
2
|
|
|
2
|
|
5984
|
use strict; |
|
|
2
|
|
|
|
|
5
|
|
|
|
2
|
|
|
|
|
1715
|
|
|
39
|
|
|
|
|
|
|
|
|
40
|
|
|
|
|
|
|
my $loaded_by; |
|
41
|
|
|
|
|
|
|
|
|
42
|
|
|
|
|
|
|
sub import { |
|
43
|
2
|
|
|
2
|
|
55
|
$loaded_by = shift; |
|
44
|
|
|
|
|
|
|
} |
|
45
|
|
|
|
|
|
|
|
|
46
|
|
|
|
|
|
|
END { |
|
47
|
2
|
|
|
2
|
|
504
|
my @caller; |
|
48
|
2
|
|
|
|
|
4
|
for ( my $i = 0;; ++$i ) { |
|
49
|
6
|
|
|
|
|
26
|
my @c = caller $i; |
|
50
|
6
|
100
|
|
|
|
15
|
last unless @c; |
|
51
|
4
|
|
|
|
|
14
|
@caller = @c; |
|
52
|
|
|
|
|
|
|
} |
|
53
|
|
|
|
|
|
|
|
|
54
|
2
|
50
|
33
|
|
|
23
|
if ( $caller[0] eq "main" |
|
55
|
|
|
|
|
|
|
&& $caller[1] eq "-e" |
|
56
|
|
|
|
|
|
|
) { |
|
57
|
0
|
|
|
|
|
0
|
require IPC::Run3::ProfLogReader; |
|
58
|
0
|
|
|
|
|
0
|
require Getopt::Long; |
|
59
|
0
|
|
|
|
|
0
|
my ( $app, $run ); |
|
60
|
|
|
|
|
|
|
|
|
61
|
0
|
|
|
|
|
0
|
Getopt::Long::GetOptions( |
|
62
|
|
|
|
|
|
|
"app" => \$app, |
|
63
|
|
|
|
|
|
|
"run" => \$run, |
|
64
|
|
|
|
|
|
|
); |
|
65
|
|
|
|
|
|
|
|
|
66
|
0
|
0
|
0
|
|
|
0
|
$app = 1, $run = 1 unless $app || $run; |
|
67
|
|
|
|
|
|
|
|
|
68
|
0
|
0
|
|
|
|
0
|
for ( @ARGV ? @ARGV : "" ) { |
|
69
|
0
|
|
|
|
|
0
|
my $r = IPC::Run3::ProfLogReader->new( |
|
70
|
|
|
|
|
|
|
Source => $_, |
|
71
|
|
|
|
|
|
|
Handler => $loaded_by->new( |
|
72
|
|
|
|
|
|
|
Source => $_, |
|
73
|
|
|
|
|
|
|
app_report => $app, |
|
74
|
|
|
|
|
|
|
run_report => $run, |
|
75
|
|
|
|
|
|
|
), |
|
76
|
|
|
|
|
|
|
); |
|
77
|
0
|
|
|
|
|
0
|
$r->read_all; |
|
78
|
|
|
|
|
|
|
} |
|
79
|
|
|
|
|
|
|
} |
|
80
|
|
|
|
|
|
|
} |
|
81
|
|
|
|
|
|
|
|
|
82
|
|
|
|
|
|
|
=head1 METHODS |
|
83
|
|
|
|
|
|
|
|
|
84
|
|
|
|
|
|
|
=over |
|
85
|
|
|
|
|
|
|
|
|
86
|
|
|
|
|
|
|
=item C<< IPC::Run3::ProfReporter->new >> |
|
87
|
|
|
|
|
|
|
|
|
88
|
|
|
|
|
|
|
Returns a new profile reporting object. |
|
89
|
|
|
|
|
|
|
|
|
90
|
|
|
|
|
|
|
=cut |
|
91
|
|
|
|
|
|
|
|
|
92
|
|
|
|
|
|
|
sub new { |
|
93
|
2
|
50
|
|
2
|
1
|
1103
|
my $class = ref $_[0] ? ref shift : shift; |
|
94
|
2
|
|
|
|
|
7
|
my $self = bless { @_ }, $class; |
|
95
|
2
|
50
|
33
|
|
|
33
|
$self->{app_report} = 1, $self->{run_report} = 1 |
|
96
|
|
|
|
|
|
|
unless $self->{app_report} || $self->{run_report}; |
|
97
|
|
|
|
|
|
|
|
|
98
|
2
|
|
|
|
|
8
|
return $self; |
|
99
|
|
|
|
|
|
|
} |
|
100
|
|
|
|
|
|
|
|
|
101
|
|
|
|
|
|
|
=item C<< $reporter->handle_app_call( ... ) >> |
|
102
|
|
|
|
|
|
|
|
|
103
|
|
|
|
|
|
|
=item C<< $reporter->handle_app_exit( ... ) >> |
|
104
|
|
|
|
|
|
|
|
|
105
|
|
|
|
|
|
|
=item C<< $reporter->handle_run_exit( ... ) >> |
|
106
|
|
|
|
|
|
|
|
|
107
|
|
|
|
|
|
|
These methods are called by the handled events (see below). |
|
108
|
|
|
|
|
|
|
|
|
109
|
|
|
|
|
|
|
=cut |
|
110
|
|
|
|
|
|
|
|
|
111
|
1
|
|
|
1
|
1
|
3
|
sub handle_app_call {} |
|
112
|
1
|
|
|
1
|
1
|
3
|
sub handle_app_exit {} |
|
113
|
|
|
|
|
|
|
|
|
114
|
1
|
|
|
1
|
1
|
2
|
sub handle_run_exit {} |
|
115
|
|
|
|
|
|
|
|
|
116
|
|
|
|
|
|
|
=item C<< $reporter->app_call(\@cmd, $time) >> |
|
117
|
|
|
|
|
|
|
|
|
118
|
|
|
|
|
|
|
=item C<< $reporter->app_exit($time) >> |
|
119
|
|
|
|
|
|
|
|
|
120
|
|
|
|
|
|
|
=item C<< $reporter->run_exit(@times) >> |
|
121
|
|
|
|
|
|
|
|
|
122
|
|
|
|
|
|
|
$self->app_call( $time ); |
|
123
|
|
|
|
|
|
|
my $time = $self->get_app_call_time; |
|
124
|
|
|
|
|
|
|
|
|
125
|
|
|
|
|
|
|
Sets the time (in floating point seconds) when the application, run3(), |
|
126
|
|
|
|
|
|
|
or system() was called or exited. If no time parameter is passed, uses |
|
127
|
|
|
|
|
|
|
IPC::Run3's time routine. |
|
128
|
|
|
|
|
|
|
|
|
129
|
|
|
|
|
|
|
Use get_...() to retrieve these values (and _accum values, too). This |
|
130
|
|
|
|
|
|
|
is a separate method to speed the execution time of the setters just a |
|
131
|
|
|
|
|
|
|
bit. |
|
132
|
|
|
|
|
|
|
|
|
133
|
|
|
|
|
|
|
=cut |
|
134
|
|
|
|
|
|
|
|
|
135
|
|
|
|
|
|
|
sub app_call { |
|
136
|
2
|
|
|
2
|
1
|
1178
|
my $self = shift; |
|
137
|
2
|
|
|
|
|
10
|
( $self->{app_cmd}, $self->{app_call_time} ) = @_; |
|
138
|
2
|
50
|
|
|
|
23
|
$self->handle_app_call if $self->{app_report}; |
|
139
|
|
|
|
|
|
|
} |
|
140
|
|
|
|
|
|
|
|
|
141
|
|
|
|
|
|
|
sub app_exit { |
|
142
|
2
|
|
|
2
|
1
|
87
|
my $self = shift; |
|
143
|
2
|
|
|
|
|
5
|
$self->{app_exit_time} = shift; |
|
144
|
2
|
50
|
|
|
|
14
|
$self->handle_app_exit if $self->{app_report}; |
|
145
|
|
|
|
|
|
|
} |
|
146
|
|
|
|
|
|
|
|
|
147
|
|
|
|
|
|
|
sub run_exit { |
|
148
|
2
|
|
|
2
|
1
|
42
|
my $self = shift; |
|
149
|
2
|
|
|
|
|
6
|
@{$self}{qw( |
|
|
2
|
|
|
|
|
9
|
|
|
150
|
|
|
|
|
|
|
run_cmd run_call_time sys_call_time sys_exit_time run_exit_time |
|
151
|
|
|
|
|
|
|
)} = @_; |
|
152
|
|
|
|
|
|
|
|
|
153
|
2
|
|
|
|
|
5
|
++$self->{run_count}; |
|
154
|
2
|
|
|
|
|
25
|
$self->{run_cumulative_time} += $self->get_run_time; |
|
155
|
2
|
|
|
|
|
12
|
$self->{sys_cumulative_time} += $self->get_sys_time; |
|
156
|
2
|
50
|
|
|
|
14
|
$self->handle_run_exit if $self->{run_report}; |
|
157
|
|
|
|
|
|
|
} |
|
158
|
|
|
|
|
|
|
|
|
159
|
|
|
|
|
|
|
=item C<< $reporter->get_run_count() >> |
|
160
|
|
|
|
|
|
|
|
|
161
|
|
|
|
|
|
|
=item C<< $reporter->get_app_call_time() >> |
|
162
|
|
|
|
|
|
|
|
|
163
|
|
|
|
|
|
|
=item C<< $reporter->get_app_exit_time() >> |
|
164
|
|
|
|
|
|
|
|
|
165
|
|
|
|
|
|
|
=item C<< $reporter->get_app_cmd() >> |
|
166
|
|
|
|
|
|
|
|
|
167
|
|
|
|
|
|
|
=item C<< $reporter->get_app_time() >> |
|
168
|
|
|
|
|
|
|
|
|
169
|
|
|
|
|
|
|
=cut |
|
170
|
|
|
|
|
|
|
|
|
171
|
4
|
|
|
4
|
1
|
15
|
sub get_run_count { shift->{run_count} } |
|
172
|
8
|
|
|
8
|
1
|
39
|
sub get_app_call_time { shift->{app_call_time} } |
|
173
|
8
|
|
|
8
|
1
|
30
|
sub get_app_exit_time { shift->{app_exit_time} } |
|
174
|
1
|
|
|
1
|
1
|
7
|
sub get_app_cmd { shift->{app_cmd} } |
|
175
|
|
|
|
|
|
|
sub get_app_time { |
|
176
|
1
|
|
|
1
|
1
|
41
|
my $self = shift; |
|
177
|
1
|
|
|
|
|
2
|
$self->get_app_exit_time - $self->get_app_call_time; |
|
178
|
|
|
|
|
|
|
} |
|
179
|
|
|
|
|
|
|
|
|
180
|
|
|
|
|
|
|
=item C<< $reporter->get_app_cumulative_time() >> |
|
181
|
|
|
|
|
|
|
|
|
182
|
|
|
|
|
|
|
=cut |
|
183
|
|
|
|
|
|
|
|
|
184
|
|
|
|
|
|
|
sub get_app_cumulative_time { |
|
185
|
6
|
|
|
6
|
1
|
37
|
my $self = shift; |
|
186
|
6
|
|
|
|
|
15
|
$self->get_app_exit_time - $self->get_app_call_time; |
|
187
|
|
|
|
|
|
|
} |
|
188
|
|
|
|
|
|
|
|
|
189
|
|
|
|
|
|
|
=item C<< $reporter->get_run_call_time() >> |
|
190
|
|
|
|
|
|
|
|
|
191
|
|
|
|
|
|
|
=item C<< $reporter->get_run_exit_time() >> |
|
192
|
|
|
|
|
|
|
|
|
193
|
|
|
|
|
|
|
=item C<< $reporter->get_run_time() >> |
|
194
|
|
|
|
|
|
|
|
|
195
|
|
|
|
|
|
|
=cut |
|
196
|
|
|
|
|
|
|
|
|
197
|
5
|
|
|
5
|
1
|
21
|
sub get_run_call_time { shift->{run_call_time} } |
|
198
|
4
|
|
|
4
|
1
|
14
|
sub get_run_exit_time { shift->{run_exit_time} } |
|
199
|
|
|
|
|
|
|
sub get_run_time { |
|
200
|
4
|
|
|
4
|
1
|
6
|
my $self = shift; |
|
201
|
4
|
|
|
|
|
13
|
$self->get_run_exit_time - $self->get_run_call_time; |
|
202
|
|
|
|
|
|
|
} |
|
203
|
|
|
|
|
|
|
|
|
204
|
|
|
|
|
|
|
=item C<< $reporter->get_run_cumulative_time() >> |
|
205
|
|
|
|
|
|
|
|
|
206
|
|
|
|
|
|
|
=cut |
|
207
|
|
|
|
|
|
|
|
|
208
|
5
|
|
|
5
|
1
|
13
|
sub get_run_cumulative_time { shift->{run_cumulative_time} } |
|
209
|
|
|
|
|
|
|
|
|
210
|
|
|
|
|
|
|
=item C<< $reporter->get_sys_call_time() >> |
|
211
|
|
|
|
|
|
|
|
|
212
|
|
|
|
|
|
|
=item C<< $reporter->get_sys_exit_time() >> |
|
213
|
|
|
|
|
|
|
|
|
214
|
|
|
|
|
|
|
=item C<< $reporter->get_sys_time() >> |
|
215
|
|
|
|
|
|
|
|
|
216
|
|
|
|
|
|
|
=cut |
|
217
|
|
|
|
|
|
|
|
|
218
|
6
|
|
|
6
|
1
|
60
|
sub get_sys_call_time { shift->{sys_call_time} } |
|
219
|
5
|
|
|
5
|
1
|
20
|
sub get_sys_exit_time { shift->{sys_exit_time} } |
|
220
|
|
|
|
|
|
|
sub get_sys_time { |
|
221
|
5
|
|
|
5
|
1
|
7
|
my $self = shift; |
|
222
|
5
|
|
|
|
|
15
|
$self->get_sys_exit_time - $self->get_sys_call_time; |
|
223
|
|
|
|
|
|
|
} |
|
224
|
|
|
|
|
|
|
|
|
225
|
|
|
|
|
|
|
=item C<< $reporter->get_sys_cumulative_time() >> |
|
226
|
|
|
|
|
|
|
|
|
227
|
|
|
|
|
|
|
=cut |
|
228
|
|
|
|
|
|
|
|
|
229
|
5
|
|
|
5
|
1
|
12
|
sub get_sys_cumulative_time { shift->{sys_cumulative_time} } |
|
230
|
|
|
|
|
|
|
|
|
231
|
|
|
|
|
|
|
=item C<< $reporter->get_run_cmd() >> |
|
232
|
|
|
|
|
|
|
|
|
233
|
|
|
|
|
|
|
=cut |
|
234
|
|
|
|
|
|
|
|
|
235
|
1
|
|
|
1
|
1
|
6
|
sub get_run_cmd { shift->{run_cmd} } |
|
236
|
|
|
|
|
|
|
|
|
237
|
|
|
|
|
|
|
=back |
|
238
|
|
|
|
|
|
|
|
|
239
|
|
|
|
|
|
|
=head1 LIMITATIONS |
|
240
|
|
|
|
|
|
|
|
|
241
|
|
|
|
|
|
|
=head1 COPYRIGHT |
|
242
|
|
|
|
|
|
|
|
|
243
|
|
|
|
|
|
|
Copyright 2003, R. Barrie Slaymaker, Jr., All Rights Reserved |
|
244
|
|
|
|
|
|
|
|
|
245
|
|
|
|
|
|
|
=head1 LICENSE |
|
246
|
|
|
|
|
|
|
|
|
247
|
|
|
|
|
|
|
You may use this module under the terms of the BSD, Artistic, or GPL licenses, |
|
248
|
|
|
|
|
|
|
any version. |
|
249
|
|
|
|
|
|
|
|
|
250
|
|
|
|
|
|
|
=head1 AUTHOR |
|
251
|
|
|
|
|
|
|
|
|
252
|
|
|
|
|
|
|
Barrie Slaymaker |
|
253
|
|
|
|
|
|
|
|
|
254
|
|
|
|
|
|
|
=cut |
|
255
|
|
|
|
|
|
|
|
|
256
|
|
|
|
|
|
|
1; |