| line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
|
1
|
|
|
|
|
|
|
################################################## |
|
2
|
|
|
|
|
|
|
################################################## |
|
3
|
|
|
|
|
|
|
|
|
4
|
|
|
|
|
|
|
use 5.006; |
|
5
|
70
|
|
|
70
|
|
985
|
use strict; |
|
|
70
|
|
|
|
|
195
|
|
|
6
|
70
|
|
|
70
|
|
316
|
use warnings; |
|
|
70
|
|
|
|
|
155
|
|
|
|
70
|
|
|
|
|
1393
|
|
|
7
|
70
|
|
|
70
|
|
345
|
use Log::Log4perl::Util; |
|
|
70
|
|
|
|
|
177
|
|
|
|
70
|
|
|
|
|
1736
|
|
|
8
|
70
|
|
|
70
|
|
382
|
use Carp; |
|
|
70
|
|
|
|
|
154
|
|
|
|
70
|
|
|
|
|
2818
|
|
|
9
|
70
|
|
|
70
|
|
392
|
|
|
|
70
|
|
|
|
|
155
|
|
|
|
70
|
|
|
|
|
6994
|
|
|
10
|
|
|
|
|
|
|
our $TIME_HIRES_AVAILABLE; |
|
11
|
|
|
|
|
|
|
|
|
12
|
|
|
|
|
|
|
BEGIN { |
|
13
|
|
|
|
|
|
|
# Check if we've got Time::HiRes. If not, don't make a big fuss, |
|
14
|
|
|
|
|
|
|
# just set a flag so we know later on that we can't have fine-grained |
|
15
|
|
|
|
|
|
|
# time stamps |
|
16
|
|
|
|
|
|
|
$TIME_HIRES_AVAILABLE = 0; |
|
17
|
70
|
|
|
70
|
|
255
|
if(Log::Log4perl::Util::module_available("Time::HiRes")) { |
|
18
|
70
|
50
|
|
|
|
350
|
require Time::HiRes; |
|
19
|
70
|
|
|
|
|
337
|
$TIME_HIRES_AVAILABLE = 1; |
|
20
|
70
|
|
|
|
|
31779
|
} |
|
21
|
|
|
|
|
|
|
} |
|
22
|
|
|
|
|
|
|
|
|
23
|
|
|
|
|
|
|
################################################## |
|
24
|
|
|
|
|
|
|
################################################## |
|
25
|
|
|
|
|
|
|
my $class = shift; |
|
26
|
|
|
|
|
|
|
$class = ref ($class) || $class; |
|
27
|
215
|
|
|
215
|
0
|
427
|
|
|
28
|
215
|
|
33
|
|
|
781
|
my $self = { |
|
29
|
|
|
|
|
|
|
reset_time => undef, |
|
30
|
215
|
|
|
|
|
918
|
@_, |
|
31
|
|
|
|
|
|
|
}; |
|
32
|
|
|
|
|
|
|
|
|
33
|
|
|
|
|
|
|
$self->{time_function} = \&_gettimeofday unless |
|
34
|
|
|
|
|
|
|
defined $self->{time_function}; |
|
35
|
|
|
|
|
|
|
|
|
36
|
215
|
100
|
|
|
|
762
|
bless $self, $class; |
|
37
|
|
|
|
|
|
|
|
|
38
|
215
|
|
|
|
|
419
|
$self->reset(); |
|
39
|
|
|
|
|
|
|
|
|
40
|
215
|
|
|
|
|
625
|
return $self; |
|
41
|
|
|
|
|
|
|
} |
|
42
|
215
|
|
|
|
|
748
|
|
|
43
|
|
|
|
|
|
|
################################################## |
|
44
|
|
|
|
|
|
|
################################################## |
|
45
|
|
|
|
|
|
|
return $TIME_HIRES_AVAILABLE; |
|
46
|
|
|
|
|
|
|
} |
|
47
|
|
|
|
|
|
|
|
|
48
|
4
|
|
|
4
|
0
|
16
|
################################################## |
|
49
|
|
|
|
|
|
|
################################################## |
|
50
|
|
|
|
|
|
|
# Return secs and optionally msecs if we have Time::HiRes |
|
51
|
|
|
|
|
|
|
if($TIME_HIRES_AVAILABLE) { |
|
52
|
|
|
|
|
|
|
return (Time::HiRes::gettimeofday()); |
|
53
|
|
|
|
|
|
|
} else { |
|
54
|
|
|
|
|
|
|
return (time(), 0); |
|
55
|
363
|
50
|
|
363
|
|
816
|
} |
|
56
|
363
|
|
|
|
|
1558
|
} |
|
57
|
|
|
|
|
|
|
|
|
58
|
0
|
|
|
|
|
0
|
################################################## |
|
59
|
|
|
|
|
|
|
################################################## |
|
60
|
|
|
|
|
|
|
my($self) = @_; |
|
61
|
|
|
|
|
|
|
|
|
62
|
|
|
|
|
|
|
my($seconds, $microseconds) = $self->{time_function}->(); |
|
63
|
|
|
|
|
|
|
|
|
64
|
|
|
|
|
|
|
$microseconds = 0 if ! defined $microseconds; |
|
65
|
377
|
|
|
377
|
0
|
645
|
return($seconds, $microseconds); |
|
66
|
|
|
|
|
|
|
} |
|
67
|
377
|
|
|
|
|
1151
|
|
|
68
|
|
|
|
|
|
|
################################################## |
|
69
|
377
|
100
|
|
|
|
915
|
################################################## |
|
70
|
377
|
|
|
|
|
1026
|
my($self) = @_; |
|
71
|
|
|
|
|
|
|
|
|
72
|
|
|
|
|
|
|
my $current_time = [$self->gettimeofday()]; |
|
73
|
|
|
|
|
|
|
$self->{reset_time} = $current_time; |
|
74
|
|
|
|
|
|
|
$self->{last_call_time} = $current_time; |
|
75
|
|
|
|
|
|
|
|
|
76
|
215
|
|
|
215
|
0
|
467
|
return $current_time; |
|
77
|
|
|
|
|
|
|
} |
|
78
|
215
|
|
|
|
|
589
|
|
|
79
|
215
|
|
|
|
|
387
|
################################################## |
|
80
|
215
|
|
|
|
|
404
|
################################################## |
|
81
|
|
|
|
|
|
|
my($time_from, $time_to) = @_; |
|
82
|
215
|
|
|
|
|
395
|
|
|
83
|
|
|
|
|
|
|
my $seconds = $time_to->[0] - |
|
84
|
|
|
|
|
|
|
$time_from->[0]; |
|
85
|
|
|
|
|
|
|
|
|
86
|
|
|
|
|
|
|
my $milliseconds = int(( $time_to->[1] - |
|
87
|
|
|
|
|
|
|
$time_from->[1] ) / 1000); |
|
88
|
61
|
|
|
61
|
0
|
101
|
|
|
89
|
|
|
|
|
|
|
if($milliseconds < 0) { |
|
90
|
61
|
|
|
|
|
86
|
$milliseconds = 1000 + $milliseconds; |
|
91
|
|
|
|
|
|
|
$seconds--; |
|
92
|
|
|
|
|
|
|
} |
|
93
|
61
|
|
|
|
|
123
|
|
|
94
|
|
|
|
|
|
|
return($seconds, $milliseconds); |
|
95
|
|
|
|
|
|
|
} |
|
96
|
61
|
50
|
|
|
|
110
|
|
|
97
|
0
|
|
|
|
|
0
|
################################################## |
|
98
|
0
|
|
|
|
|
0
|
################################################## |
|
99
|
|
|
|
|
|
|
my($self, $current_time) = @_; |
|
100
|
|
|
|
|
|
|
|
|
101
|
61
|
|
|
|
|
96
|
$current_time = [ $self->gettimeofday() ] unless |
|
102
|
|
|
|
|
|
|
defined $current_time; |
|
103
|
|
|
|
|
|
|
|
|
104
|
|
|
|
|
|
|
my($seconds, $milliseconds) = time_diff( |
|
105
|
|
|
|
|
|
|
$self->{reset_time}, |
|
106
|
|
|
|
|
|
|
$current_time); |
|
107
|
53
|
|
|
53
|
0
|
83
|
|
|
108
|
|
|
|
|
|
|
return $seconds*1000 + $milliseconds; |
|
109
|
53
|
50
|
|
|
|
91
|
} |
|
110
|
|
|
|
|
|
|
|
|
111
|
|
|
|
|
|
|
################################################## |
|
112
|
|
|
|
|
|
|
################################################## |
|
113
|
|
|
|
|
|
|
my($self, $current_time) = @_; |
|
114
|
53
|
|
|
|
|
85
|
|
|
115
|
|
|
|
|
|
|
$current_time = [ $self->gettimeofday() ] unless |
|
116
|
53
|
|
|
|
|
139
|
defined $current_time; |
|
117
|
|
|
|
|
|
|
|
|
118
|
|
|
|
|
|
|
my($seconds, $milliseconds) = time_diff( |
|
119
|
|
|
|
|
|
|
$self->{last_call_time}, |
|
120
|
|
|
|
|
|
|
$current_time); |
|
121
|
|
|
|
|
|
|
|
|
122
|
8
|
|
|
8
|
0
|
14
|
$self->{last_call_time} = $current_time; |
|
123
|
|
|
|
|
|
|
|
|
124
|
8
|
50
|
|
|
|
13
|
return $seconds*1000 + $milliseconds; |
|
125
|
|
|
|
|
|
|
} |
|
126
|
|
|
|
|
|
|
|
|
127
|
|
|
|
|
|
|
1; |
|
128
|
|
|
|
|
|
|
|
|
129
|
8
|
|
|
|
|
14
|
|
|
130
|
|
|
|
|
|
|
=encoding utf8 |
|
131
|
8
|
|
|
|
|
15
|
|
|
132
|
|
|
|
|
|
|
=head1 NAME |
|
133
|
8
|
|
|
|
|
17
|
|
|
134
|
|
|
|
|
|
|
Log::Log4perl::Util::TimeTracker - Track time elapsed |
|
135
|
|
|
|
|
|
|
|
|
136
|
|
|
|
|
|
|
=head1 SYNOPSIS |
|
137
|
|
|
|
|
|
|
|
|
138
|
|
|
|
|
|
|
use Log::Log4perl::Util::TimeTracker; |
|
139
|
|
|
|
|
|
|
|
|
140
|
|
|
|
|
|
|
my $timer = Log::Log4perl::Util::TimeTracker->new(); |
|
141
|
|
|
|
|
|
|
|
|
142
|
|
|
|
|
|
|
# equivalent to Time::HiRes::gettimeofday(), regardless |
|
143
|
|
|
|
|
|
|
# if Time::HiRes is present or not. |
|
144
|
|
|
|
|
|
|
my($seconds, $microseconds) = $timer->gettimeofday(); |
|
145
|
|
|
|
|
|
|
|
|
146
|
|
|
|
|
|
|
# reset internal timer |
|
147
|
|
|
|
|
|
|
$timer->reset(); |
|
148
|
|
|
|
|
|
|
|
|
149
|
|
|
|
|
|
|
# return milliseconds since last reset |
|
150
|
|
|
|
|
|
|
$msecs = $timer->milliseconds(); |
|
151
|
|
|
|
|
|
|
|
|
152
|
|
|
|
|
|
|
# return milliseconds since last call |
|
153
|
|
|
|
|
|
|
$msecs = $timer->delta_milliseconds(); |
|
154
|
|
|
|
|
|
|
|
|
155
|
|
|
|
|
|
|
=head1 DESCRIPTION |
|
156
|
|
|
|
|
|
|
|
|
157
|
|
|
|
|
|
|
This utility module helps tracking time elapsed for PatternLayout's |
|
158
|
|
|
|
|
|
|
date and time placeholders. Its accuracy depends on the availability |
|
159
|
|
|
|
|
|
|
of the Time::HiRes module. If it's available, its granularity is |
|
160
|
|
|
|
|
|
|
milliseconds, if not, seconds. |
|
161
|
|
|
|
|
|
|
|
|
162
|
|
|
|
|
|
|
The most common use of this module is calling the gettimeofday() |
|
163
|
|
|
|
|
|
|
method: |
|
164
|
|
|
|
|
|
|
|
|
165
|
|
|
|
|
|
|
my($seconds, $microseconds) = $timer->gettimeofday(); |
|
166
|
|
|
|
|
|
|
|
|
167
|
|
|
|
|
|
|
It returns seconds and microseconds of the current epoch time. If |
|
168
|
|
|
|
|
|
|
Time::HiRes is installed, it will simply defer to its gettimeofday() |
|
169
|
|
|
|
|
|
|
function, if it's missing, time() will be called instead and $microseconds |
|
170
|
|
|
|
|
|
|
will always be 0. |
|
171
|
|
|
|
|
|
|
|
|
172
|
|
|
|
|
|
|
To measure time elapsed in milliseconds, use the reset() method to |
|
173
|
|
|
|
|
|
|
reset the timer to the current time, followed by one or more calls to |
|
174
|
|
|
|
|
|
|
the milliseconds() method: |
|
175
|
|
|
|
|
|
|
|
|
176
|
|
|
|
|
|
|
# reset internal timer |
|
177
|
|
|
|
|
|
|
$timer->reset(); |
|
178
|
|
|
|
|
|
|
|
|
179
|
|
|
|
|
|
|
# return milliseconds since last reset |
|
180
|
|
|
|
|
|
|
$msecs = $timer->milliseconds(); |
|
181
|
|
|
|
|
|
|
|
|
182
|
|
|
|
|
|
|
On top of the time span between the last reset and the current time, |
|
183
|
|
|
|
|
|
|
the module keeps track of the time between calls to delta_milliseconds(): |
|
184
|
|
|
|
|
|
|
|
|
185
|
|
|
|
|
|
|
$msecs = $timer->delta_milliseconds(); |
|
186
|
|
|
|
|
|
|
|
|
187
|
|
|
|
|
|
|
On the first call, this will return the number of milliseconds since the |
|
188
|
|
|
|
|
|
|
last reset(), on subsequent calls, it will return the time elapsed in |
|
189
|
|
|
|
|
|
|
milliseconds since the last call to delta_milliseconds() instead. Note |
|
190
|
|
|
|
|
|
|
that reset() also resets the time of the last call. |
|
191
|
|
|
|
|
|
|
|
|
192
|
|
|
|
|
|
|
The internal timer of this module gets its time input from the POSIX time() |
|
193
|
|
|
|
|
|
|
function, or, if the Time::HiRes module is available, from its |
|
194
|
|
|
|
|
|
|
gettimeofday() function. To figure out which one it is, use |
|
195
|
|
|
|
|
|
|
|
|
196
|
|
|
|
|
|
|
if( $timer->hires_available() ) { |
|
197
|
|
|
|
|
|
|
print "Hooray, we get real milliseconds!\n"; |
|
198
|
|
|
|
|
|
|
} else { |
|
199
|
|
|
|
|
|
|
print "Milliseconds are just bogus\n"; |
|
200
|
|
|
|
|
|
|
} |
|
201
|
|
|
|
|
|
|
|
|
202
|
|
|
|
|
|
|
For testing purposes, a different time source can be provided, so test |
|
203
|
|
|
|
|
|
|
suites can simulate time passing by without actually having to wait: |
|
204
|
|
|
|
|
|
|
|
|
205
|
|
|
|
|
|
|
my $start_time = time(); |
|
206
|
|
|
|
|
|
|
|
|
207
|
|
|
|
|
|
|
my $timer = Log::Log4perl::Util::TimeTracker->new( |
|
208
|
|
|
|
|
|
|
time_function => sub { |
|
209
|
|
|
|
|
|
|
return $start_time++; |
|
210
|
|
|
|
|
|
|
}, |
|
211
|
|
|
|
|
|
|
); |
|
212
|
|
|
|
|
|
|
|
|
213
|
|
|
|
|
|
|
Every call to $timer->epoch() will then return a time value that is one |
|
214
|
|
|
|
|
|
|
second ahead of the value returned on the previous call. This also means |
|
215
|
|
|
|
|
|
|
that every call to delta_milliseconds() will return a value that exceeds |
|
216
|
|
|
|
|
|
|
the value returned on the previous call by 1000. |
|
217
|
|
|
|
|
|
|
|
|
218
|
|
|
|
|
|
|
=head1 LICENSE |
|
219
|
|
|
|
|
|
|
|
|
220
|
|
|
|
|
|
|
Copyright 2002-2013 by Mike Schilli E<lt>m@perlmeister.comE<gt> |
|
221
|
|
|
|
|
|
|
and Kevin Goess E<lt>cpan@goess.orgE<gt>. |
|
222
|
|
|
|
|
|
|
|
|
223
|
|
|
|
|
|
|
This library is free software; you can redistribute it and/or modify |
|
224
|
|
|
|
|
|
|
it under the same terms as Perl itself. |
|
225
|
|
|
|
|
|
|
|
|
226
|
|
|
|
|
|
|
=head1 AUTHOR |
|
227
|
|
|
|
|
|
|
|
|
228
|
|
|
|
|
|
|
Please contribute patches to the project on Github: |
|
229
|
|
|
|
|
|
|
|
|
230
|
|
|
|
|
|
|
http://github.com/mschilli/log4perl |
|
231
|
|
|
|
|
|
|
|
|
232
|
|
|
|
|
|
|
Send bug reports or requests for enhancements to the authors via our |
|
233
|
|
|
|
|
|
|
|
|
234
|
|
|
|
|
|
|
MAILING LIST (questions, bug reports, suggestions/patches): |
|
235
|
|
|
|
|
|
|
log4perl-devel@lists.sourceforge.net |
|
236
|
|
|
|
|
|
|
|
|
237
|
|
|
|
|
|
|
Authors (please contact them via the list above, not directly): |
|
238
|
|
|
|
|
|
|
Mike Schilli <m@perlmeister.com>, |
|
239
|
|
|
|
|
|
|
Kevin Goess <cpan@goess.org> |
|
240
|
|
|
|
|
|
|
|
|
241
|
|
|
|
|
|
|
Contributors (in alphabetical order): |
|
242
|
|
|
|
|
|
|
Ateeq Altaf, Cory Bennett, Jens Berthold, Jeremy Bopp, Hutton |
|
243
|
|
|
|
|
|
|
Davidson, Chris R. Donnelly, Matisse Enzer, Hugh Esco, Anthony |
|
244
|
|
|
|
|
|
|
Foiani, James FitzGibbon, Carl Franks, Dennis Gregorovic, Andy |
|
245
|
|
|
|
|
|
|
Grundman, Paul Harrington, Alexander Hartmaier David Hull, |
|
246
|
|
|
|
|
|
|
Robert Jacobson, Jason Kohles, Jeff Macdonald, Markus Peter, |
|
247
|
|
|
|
|
|
|
Brett Rann, Peter Rabbitson, Erik Selberg, Aaron Straup Cope, |
|
248
|
|
|
|
|
|
|
Lars Thegler, David Viner, Mac Yang. |
|
249
|
|
|
|
|
|
|
|