| line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
|
1
|
|
|
|
|
|
|
package RHP::Timer; |
|
2
|
|
|
|
|
|
|
|
|
3
|
1
|
|
|
1
|
|
21601
|
use strict; |
|
|
1
|
|
|
|
|
2
|
|
|
|
1
|
|
|
|
|
34
|
|
|
4
|
1
|
|
|
1
|
|
5
|
use warnings; |
|
|
1
|
|
|
|
|
1
|
|
|
|
1
|
|
|
|
|
31
|
|
|
5
|
|
|
|
|
|
|
|
|
6
|
|
|
|
|
|
|
=head1 NAME |
|
7
|
|
|
|
|
|
|
|
|
8
|
|
|
|
|
|
|
RHP::Timer - A high resolution timer abstraction |
|
9
|
|
|
|
|
|
|
|
|
10
|
|
|
|
|
|
|
=head1 SYNOPSIS |
|
11
|
|
|
|
|
|
|
|
|
12
|
|
|
|
|
|
|
use RHP::Timer (); |
|
13
|
|
|
|
|
|
|
use My::Logger (); |
|
14
|
|
|
|
|
|
|
|
|
15
|
|
|
|
|
|
|
$logger = My::Logger->new; |
|
16
|
|
|
|
|
|
|
$timer = RHP::Timer->new(); |
|
17
|
|
|
|
|
|
|
|
|
18
|
|
|
|
|
|
|
# timing data from the point of the caller |
|
19
|
|
|
|
|
|
|
$timer->start('fizzbin'); |
|
20
|
|
|
|
|
|
|
fizzbin(); # how fast is fizzbin? |
|
21
|
|
|
|
|
|
|
$logger->info( |
|
22
|
|
|
|
|
|
|
sprintf("Timing caller: %s %s %d, timer_name: %s, time: %s", |
|
23
|
|
|
|
|
|
|
@{$timer->checkpoint})); |
|
24
|
|
|
|
|
|
|
|
|
25
|
|
|
|
|
|
|
# or simpler |
|
26
|
|
|
|
|
|
|
$timer->start('foobin'); |
|
27
|
|
|
|
|
|
|
foobin(); |
|
28
|
|
|
|
|
|
|
$logger->info("pid $$ timer " . $timer->current . |
|
29
|
|
|
|
|
|
|
" took " . $timer->stop . " seconds"); |
|
30
|
|
|
|
|
|
|
|
|
31
|
|
|
|
|
|
|
# what was the last timing block? |
|
32
|
|
|
|
|
|
|
$logger->info("Last timing block " . $timer->current . |
|
33
|
|
|
|
|
|
|
" took " . $timer->last_interval . " seconds"); |
|
34
|
|
|
|
|
|
|
|
|
35
|
|
|
|
|
|
|
=head1 DESCRIPTION |
|
36
|
|
|
|
|
|
|
|
|
37
|
|
|
|
|
|
|
RHP::Timer is a wrapper around Time::HiRes. I wrote it because I |
|
38
|
|
|
|
|
|
|
needed some simple abstractions for timing programs to |
|
39
|
|
|
|
|
|
|
determine bottlenecks in running programs. |
|
40
|
|
|
|
|
|
|
|
|
41
|
|
|
|
|
|
|
The goals of RHP::Timer is to be easy to use, accurate, and simple. |
|
42
|
|
|
|
|
|
|
|
|
43
|
|
|
|
|
|
|
=cut |
|
44
|
|
|
|
|
|
|
|
|
45
|
1
|
|
|
1
|
|
875
|
use Time::HiRes (); |
|
|
1
|
|
|
|
|
1703
|
|
|
|
1
|
|
|
|
|
126
|
|
|
46
|
|
|
|
|
|
|
|
|
47
|
|
|
|
|
|
|
our $VERSION = 0.1; |
|
48
|
|
|
|
|
|
|
|
|
49
|
|
|
|
|
|
|
=head1 METHODS |
|
50
|
|
|
|
|
|
|
|
|
51
|
|
|
|
|
|
|
=over 4 |
|
52
|
|
|
|
|
|
|
|
|
53
|
|
|
|
|
|
|
=item new() |
|
54
|
|
|
|
|
|
|
|
|
55
|
|
|
|
|
|
|
$timer = RHP::Timer->new(); |
|
56
|
|
|
|
|
|
|
|
|
57
|
|
|
|
|
|
|
Constructor which takes no arguments and returns a timer object |
|
58
|
|
|
|
|
|
|
|
|
59
|
|
|
|
|
|
|
=cut |
|
60
|
|
|
|
|
|
|
|
|
61
|
|
|
|
|
|
|
sub new { |
|
62
|
2
|
|
|
2
|
1
|
936
|
my ($class) = @_; |
|
63
|
2
|
|
|
|
|
5
|
my $self = {}; |
|
64
|
2
|
|
|
|
|
7
|
bless $self, $class; |
|
65
|
2
|
|
|
|
|
7
|
return $self; |
|
66
|
|
|
|
|
|
|
} |
|
67
|
|
|
|
|
|
|
|
|
68
|
|
|
|
|
|
|
=item start() |
|
69
|
|
|
|
|
|
|
|
|
70
|
|
|
|
|
|
|
$timer->start('fizzbin'); |
|
71
|
|
|
|
|
|
|
|
|
72
|
|
|
|
|
|
|
Starts the timer for 'fizzbin' |
|
73
|
|
|
|
|
|
|
|
|
74
|
|
|
|
|
|
|
=cut |
|
75
|
|
|
|
|
|
|
|
|
76
|
|
|
|
|
|
|
sub start { |
|
77
|
3
|
|
|
3
|
1
|
396
|
my ($self, $name) = @_; |
|
78
|
3
|
|
|
|
|
33
|
$self->{$name}->{_start} = [Time::HiRes::gettimeofday]; |
|
79
|
3
|
|
|
|
|
6
|
$self->{_current} = $name; |
|
80
|
3
|
|
|
|
|
9
|
return 1; |
|
81
|
|
|
|
|
|
|
} |
|
82
|
|
|
|
|
|
|
|
|
83
|
|
|
|
|
|
|
=item stop() |
|
84
|
|
|
|
|
|
|
|
|
85
|
|
|
|
|
|
|
$interval = $timer->stop; |
|
86
|
|
|
|
|
|
|
|
|
87
|
|
|
|
|
|
|
Stops the last timer started, and returns the number of seconds between |
|
88
|
|
|
|
|
|
|
start and stop. |
|
89
|
|
|
|
|
|
|
|
|
90
|
|
|
|
|
|
|
=cut |
|
91
|
|
|
|
|
|
|
|
|
92
|
|
|
|
|
|
|
sub stop { |
|
93
|
4
|
|
|
4
|
1
|
1000144
|
my ($self) = @_; |
|
94
|
1
|
|
|
1
|
|
5
|
no strict 'refs'; |
|
|
1
|
|
|
|
|
1
|
|
|
|
1
|
|
|
|
|
180
|
|
|
95
|
4
|
|
|
|
|
62
|
$self->{$self->{_current}}->{_stop} = [Time::HiRes::gettimeofday]; |
|
96
|
4
|
|
|
|
|
31
|
$self->{$self->{_current}}->{interval} = |
|
97
|
|
|
|
|
|
|
Time::HiRes::tv_interval($self->{$self->{_current}}->{_start}, |
|
98
|
|
|
|
|
|
|
$self->{$self->{_current}}->{_stop}); |
|
99
|
4
|
|
|
|
|
71
|
return $self->{$self->{_current}}->{interval}; |
|
100
|
|
|
|
|
|
|
} |
|
101
|
|
|
|
|
|
|
|
|
102
|
|
|
|
|
|
|
=item current() |
|
103
|
|
|
|
|
|
|
|
|
104
|
|
|
|
|
|
|
$timer_name = $timer->current(); |
|
105
|
|
|
|
|
|
|
# $timer_name is 'fizzbin' from previous pod |
|
106
|
|
|
|
|
|
|
|
|
107
|
|
|
|
|
|
|
Returns the name of the most recent timer started. |
|
108
|
|
|
|
|
|
|
|
|
109
|
|
|
|
|
|
|
=cut |
|
110
|
|
|
|
|
|
|
|
|
111
|
|
|
|
|
|
|
sub current { |
|
112
|
2
|
|
|
2
|
1
|
10
|
my $self = shift; |
|
113
|
2
|
|
|
|
|
23
|
return $self->{_current}; |
|
114
|
|
|
|
|
|
|
} |
|
115
|
|
|
|
|
|
|
|
|
116
|
|
|
|
|
|
|
=item checkpoint() |
|
117
|
|
|
|
|
|
|
|
|
118
|
|
|
|
|
|
|
[ caller(), $timer_name, $interval ] = $timer->checkpoint(); |
|
119
|
|
|
|
|
|
|
|
|
120
|
|
|
|
|
|
|
Stops the current timer and returns an array reference containing caller() |
|
121
|
|
|
|
|
|
|
information, the name of the timer stopped, and the interval of the last |
|
122
|
|
|
|
|
|
|
timing run. Useful for passing to a logfile in sprintf or other format. |
|
123
|
|
|
|
|
|
|
|
|
124
|
|
|
|
|
|
|
=cut |
|
125
|
|
|
|
|
|
|
|
|
126
|
|
|
|
|
|
|
sub checkpoint { |
|
127
|
1
|
|
|
1
|
1
|
5
|
my $self = shift; |
|
128
|
1
|
|
|
|
|
10
|
my $stop = $self->stop; |
|
129
|
1
|
|
|
|
|
11
|
my @summary = ( caller, $self->current, $self->stop); |
|
130
|
1
|
|
|
|
|
8
|
return \@summary; |
|
131
|
|
|
|
|
|
|
} |
|
132
|
|
|
|
|
|
|
|
|
133
|
|
|
|
|
|
|
=item last_interval() |
|
134
|
|
|
|
|
|
|
|
|
135
|
|
|
|
|
|
|
$last_interval = $timer->last_interval; |
|
136
|
|
|
|
|
|
|
|
|
137
|
|
|
|
|
|
|
Returns the last timing interval recorded by the timer object. |
|
138
|
|
|
|
|
|
|
|
|
139
|
|
|
|
|
|
|
=cut |
|
140
|
|
|
|
|
|
|
|
|
141
|
|
|
|
|
|
|
sub last_interval { |
|
142
|
2
|
|
|
2
|
1
|
3515
|
my $self = shift; |
|
143
|
2
|
|
|
|
|
18
|
return $self->{$self->{_current}}->{interval}; |
|
144
|
|
|
|
|
|
|
} |
|
145
|
|
|
|
|
|
|
|
|
146
|
|
|
|
|
|
|
=pod |
|
147
|
|
|
|
|
|
|
|
|
148
|
|
|
|
|
|
|
=back |
|
149
|
|
|
|
|
|
|
|
|
150
|
|
|
|
|
|
|
=cut |
|
151
|
|
|
|
|
|
|
|
|
152
|
|
|
|
|
|
|
1; |
|
153
|
|
|
|
|
|
|
|
|
154
|
|
|
|
|
|
|
__END__ |