File Coverage

blib/lib/Log/Agent/File/Rotate.pm
Criterion Covered Total %
statement 173 204 84.8
branch 67 120 55.8
condition 10 15 66.6
subroutine 23 25 92.0
pod 3 19 15.7
total 276 383 72.0


line stmt bran cond sub pod time code
1             ###########################################################################
2             #
3             # File/Rotate.pm
4             #
5             # Copyright (c) 2000 Raphael Manfredi.
6             # Copyright (c) 2002-2015 Mark Rogaski, mrogaski@cpan.org;
7             # all rights reserved.
8             #
9             # See the README file included with the
10             # distribution for license information.
11             #
12             ###########################################################################
13            
14 6     6   4510 use strict;
  6         10  
  6         226  
15            
16             ###########################################################################
17             package Log::Agent::File::Rotate;
18            
19             #
20             # A rotating logfile set
21             #
22            
23 6     6   4687 use File::stat;
  6         42748  
  6         28  
24 6     6   344 use Fcntl;
  6         13  
  6         2222  
25 6     6   4571 use Symbol;
  6         5398  
  6         411  
26 6     6   5623 use Compress::Zlib;
  6         11201887  
  6         1954  
27             require LockFile::Simple;
28            
29 6     6   62 use Log::Agent; # We're using logerr() ourselves when safe to do so
  6         13  
  6         15884  
30            
31             my $DEBUG = 0;
32            
33             #
34             # ->make
35             #
36             # Creation routine.
37             #
38             # Attributes initialized by parameters:
39             # path file path
40             # config rotating configuration (a Log::Agent::Rotate object)
41             #
42             # Other attributes:
43             # fd currently opened file descriptor
44             # handle symbol used for Perl handle
45             # warned records calls made to hardwired warn() to only do them once
46             # written total amount written since opening
47             # size logfile size
48             # opened time when opening occurred
49             # dev device holding logfile
50             # ino inode number of logfile
51             # lockmgr lockfile manager
52             # rotating within the rotate() routine
53             #
54             sub make {
55 12     12 1 60546 my $self = bless {}, shift;
56 12         31 my ($path, $config) = @_;
57 12         60 $self->{'path'} = $path;
58 12         33 $self->{'config'} = $config;
59 12         121 $self->{'fd'} = undef;
60 12         52 $self->{'handle'} = gensym;
61 12         174 $self->{'warned'} = {};
62 12         29 $self->{'rotating'} = 0;
63 12         96 $self->{'lockmgr'} = LockFile::Simple->make(
64             -autoclean => 1,
65             -delay => 1, # until sleep(.25) is supported
66             -efunc => undef,
67             -hold => 60,
68             -max => 5,
69             -nfs => !$config->single_host,
70             -stale => 1,
71             -warn => 0,
72             -wfunc => undef
73             );
74 12         8709 return $self;
75             }
76            
77             #
78             # Attribute access
79             #
80            
81 75     75 0 160 sub path { $_[0]->{'path'} }
82 130     130 1 301 sub config { $_[0]->{'config'} }
83 135     135 0 277 sub fd { $_[0]->{'fd'} }
84 34     34 0 57 sub handle { $_[0]->{'handle'} }
85 34     34 0 176 sub warned { $_[0]->{'warned'} }
86 0     0 0 0 sub written { $_[0]->{'written'} }
87 0     0 0 0 sub opened { $_[0]->{'opened'} }
88 65     65 0 238 sub size { $_[0]->{'size'} }
89 8     8 0 231 sub dev { $_[0]->{'dev'} }
90 8     8 0 86 sub ino { $_[0]->{'ino'} }
91 31     31 0 127 sub lockmgr { $_[0]->{'lockmgr'} }
92 31     31 0 85 sub rotating { $_[0]->{'rotating'} }
93            
94             #
95             # ->print
96             #
97             # Print to file.
98             # This is where all the monitoring is performed:
99             #
100             # . If the file was renamed underneath us, re-open it.
101             # This costs a stat() system call each time a log is to be emitted
102             # and can be avoided by setting config->is_alone.
103             #
104             sub print {
105 65     65 1 19209 my $self = shift;
106 65         178 my $str = join('', @_);
107            
108 65         151 my $fd = $self->fd;
109 65         155 my $cf = $self->config;
110            
111             #
112             # If the file was renamed underneath us, re-open it.
113             # This costs a stat() system call each time a log is to be emitted
114             # and can be avoided by setting config->is_alone when appropriate.
115             #
116            
117 65 100 100     304 if (defined $fd && !$cf->is_alone) {
118 10         24 my $st = stat($self->path);
119 10 50 66     1142 if (!$st || $st->dev != $self->dev || $st->ino != $self->ino) {
      66        
120 2         7 $self->close;
121 2         5 undef $fd; # Will be re-opened below
122             }
123             }
124            
125             #
126             # Open file if not already done.
127             #
128            
129 65 100       162 unless (defined $fd) {
130 34         90 $fd = $self->open;
131 34 50       104 return unless defined $fd;
132             }
133            
134             #
135             # Write to logfile
136             #
137            
138 65 50       1969 return unless syswrite($fd, $str, length $str);
139            
140             #
141             # If the overall logfile size is monitored, update it.
142             # Unless we're alone, we have to fstat() the file descriptor.
143             #
144            
145 65 50       264 if ($cf->max_size) {
146 65 100       178 if ($cf->is_alone) {
147 47         94 $self->{'size'} += length $str;
148             } else {
149 18         47 my $st = stat($fd);
150 18 50       1809 if ($st) {
151 18         375 $self->{'size'} = $st->size; # Paranoid test
152             } else {
153 0         0 $self->{'size'} += length $str;
154             }
155             }
156 65 100       279 if ($self->size > $cf->max_size) {
157 31         85 $self->rotate;
158 31         94 return;
159             }
160             }
161            
162             #
163             # If the amount of bytes written exceeds the threshold,
164             # rotate the files.
165             #
166            
167 34 50       108 if ($cf->max_write) {
168 0         0 $self->{'written'} += length $str;
169 0 0       0 if ($self->written > $cf->max_write) {
170 0         0 $self->rotate;
171 0         0 return;
172             }
173             }
174            
175             #
176             # If the opening time is exceeded, rotate the files.
177             #
178            
179 34 50       113 if ($cf->max_time) {
180 0 0       0 if (time - $self->opened > $cf->max_time) {
181 0         0 $self->rotate;
182 0         0 return;
183             }
184             }
185            
186             # Did not rotate anything
187 34         101 return;
188             }
189            
190             #
191             # ->open
192             #
193             # Open current logfile.
194             # Returns opened handle, or nothing if error.
195             #
196             sub open {
197 34     34 0 142 my $self = shift;
198 34         91 my $fd = $self->handle;
199 34         87 my $path = $self->path;
200 34         50 my $mode = O_CREAT|O_APPEND|O_WRONLY;
201 34         81 my $perm = ($self->config)->file_perm;
202 34 50       93 warn "opening $path\n" if $DEBUG;
203            
204 34 50       2361 unless (sysopen($fd, $path, $mode, $perm)) {
205             #
206             # Can't log errors via Log::Agent since we might recurse down here.
207             # Therefore, use warn(), but only once, and clear condition when
208             # opening is successful.
209             #
210            
211             warn "$0: can't open logfile \"$path\": $!\n"
212 0 0       0 unless $self->warned->{$path}++;
213 0         0 return;
214             }
215            
216 34         153 my $st = stat($fd); # An fstat(), really
217 34         4405 $self->warned->{$path} = 0; # Clear warning condition
218 34         64 $self->{'fd'} = $fd; # Records: file opened
219 34         70 $self->{'written'} = 0; # Amount written
220 34         70 $self->{'opened'} = time; # Opening time
221 34 50       869 $self->{'size'} = $st ? $st->size : 0; # Current size
222 34         825 $self->{'dev'} = $st->dev;
223 34         811 $self->{'ino'} = $st->ino;
224            
225 34         321 return $fd;
226             }
227            
228             #
229             # ->close
230             #
231             # Close current logfile.
232             #
233             sub close {
234 39     39 0 1184 my $self = shift;
235 39         99 my $fd = $self->fd;
236 39 100       126 return unless defined $fd; # Already closed
237 34 50       86 warn "closing logfile\n" if $DEBUG;
238 34         269 close($fd);
239 34         84 $self->{'fd'} = undef; # Mark as closed
240             }
241            
242             #
243             # ->rotate
244             #
245             # Perform logfile rotation, as configured, and log any returned error
246             # to the error channel.
247             #
248             sub rotate {
249 31     31 0 48 my $self = shift;
250 31 50       73 return if $self->rotating; # no recusion if error & limits too small
251 31         57 $self->{'rotating'} = 1;
252            
253 31         76 my @errors = $self->do_rotate;
254 31 50       92 unless (@errors) {
255 31         66 $self->{'rotating'} = 0;
256 31         59 return;
257             }
258            
259             #
260             # Errors are logged using logerr(). There's no danger we could
261             # recurse down here since we're protected by the `rotating' flag.
262             #
263            
264 0 0       0 my $error = @errors == 1 ? "error" : sprintf("%d errors", scalar @errors);
265 0         0 logerr "the following $error occurred while rotating logfiles:";
266 0         0 foreach my $err (@errors) {
267 0         0 logerr $err;
268 0 0       0 warn "ERROR: $err\n" if $DEBUG;
269             }
270            
271 0         0 $self->{'rotating'} = 0;
272             }
273            
274             #
275             # ->do_rotate
276             #
277             # Perform logfile rotation, as configured.
278             # Returns nothing if OK, an array of error messages otherwise.
279             #
280             sub do_rotate {
281 31     31 0 43 my $self = shift;
282 31         70 my $path = $self->path;
283 31         70 my $cf = $self->config;
284 31         82 my $lock = $self->lockmgr->lock($path);
285            
286             #
287             # Emission of errors has to be delayed, since we're in the middle of
288             # logfile rotation, which could be the error channel.
289             #
290            
291 31         8934 my @errors = ();
292            
293 31 50       99 push(@errors, "proceeded with rotation of $path without lock")
294             unless defined $lock;
295            
296             #
297             # We're unix-centric in the following code fragment, but I don't know
298             # how to do the same thing on non-unix operating systems. Sorry.
299             #
300            
301 31         181 my ($dir, $file) = ($path =~ m|^(.*)/(.*)|);
302 31 50       81 ($dir, $file) = (".", $path) unless $dir;
303            
304 31         78 local *DIR;
305 31 50       629 unless (opendir(DIR, $dir)) {
306 0         0 my $error = "can't open directory \"$dir\" to rotate $path: $!";
307 0 0       0 $lock->release if defined $lock;
308 0         0 return ($error);
309             }
310 31         1179 my @files = readdir DIR;
311 31         320 closedir DIR;
312            
313             #
314             # Identify the logfiles already present.
315             #
316             # We use the common convention of renaming un-compressed logfiles
317             # as "path.0", "path.1", etc... the .0 being the more recent file,
318             # and use "path.0.gz", "path.1.gz", etc... for compressed logfiles.
319             #
320            
321 31         59 my @logfiles = (); # Logfiles to rotate
322 31         50 my @unlink = (); # Logfiles to unlink
323 31         71 my $lookfor = "$file.";
324 31         117 my $unlink_at = $cf->backlog - 1;
325            
326 31 50       87 warn "unlink_at=$unlink_at\n" if $DEBUG;
327            
328 31         70 foreach my $f (@files) {
329 420 100       1045 next unless substr($f, 0, length $lookfor) eq $lookfor;
330 110         422 my ($idx) = ($f =~ /\.(\d+)(?:\.gz)?$/);
331 110 50       252 warn "f=$f, idx=$idx\n" if $DEBUG;
332 110 100       243 next unless defined $idx;
333 79 50       370 $f = $1 if $f =~ /^(.*)$/; # untaint
334 79 100       194 if ($idx >= $unlink_at) {
335 8         18 push(@unlink, $f);
336             } else {
337 71         160 $logfiles[$idx] = $f;
338             }
339             }
340            
341 31 50       79 if ($DEBUG) {
342 0         0 warn "unlink=@unlink\n";
343 0         0 warn "logfiles=@logfiles\n";
344             }
345            
346             #
347             # Delete old files, if any.
348             #
349            
350 31         58 foreach my $f (@unlink) {
351 8 50       514 unlink("$dir/$f") or push(@errors, "can't unlink $dir/$f: $!");
352             }
353            
354             #
355             # File rotation section...
356             #
357             # If backlog=5 and unzipped=2, then, when things have stabilized,
358             # we have the following logfiles:
359             #
360             # path.4.gz was unlinked above
361             # path.3.gz renamed as path.4.gz
362             # path.2.gz renamed as path.3.gz
363             # path.1 compressed as path.2.gz
364             # path.0 renamed as path.1
365             # path current logfile, closed and renamed path.0
366             #
367             # The code below is prepared to deal with missing files, or policy
368             # changes. Compressed file are not uncompressed though.
369             #
370            
371 31         105 my $last = $cf->backlog - 2; # Oldest logfile already deleted
372 31         104 my $gz_limit = $cf->unzipped; # Files up to that index are .gz
373            
374 31 50       85 warn "last=$last, gz_limit=$gz_limit\n" if $DEBUG;
375            
376             #
377             # Handle renaming of compressed files
378             #
379            
380 31         90 for (my $i = $last; $i >= $gz_limit; $i--) {
381 99 100       289 next unless defined $logfiles[$i]; # Not that much backlog yet?
382 27         72 my $old = "$dir/$logfiles[$i]";
383 27         66 my $new = "$path." . ($i+1) . ".gz";
384 27 50       67 warn "compressing old=$old, new=$new\n" if $DEBUG;
385 27 100       121 if ($old =~ /\.gz$/) {
386 24 50       995 rename($old, $new) or
387             push(@errors, "can't rename $old to $new: $!");
388             } else {
389             # Compression policy changed?
390 3         9 my $err = $self->mv_gzip($old, $new);
391 3 50       232 push(@errors, $err) if defined $err;
392             }
393             }
394            
395             #
396             # Handle compression and renaming of the oldest uncompressed file
397             #
398            
399 31 100 66     191 if ($gz_limit > 0 && defined $logfiles[$gz_limit-1]) {
400 14         39 my $old = "$dir/$logfiles[$gz_limit-1]";
401 14         33 my $new = "$path.$gz_limit.gz";
402 14 50       33 warn "rename and compress old=$old, new=$new\n" if $DEBUG;
403 14 100       41 if ($old !~ /\.gz$/) {
404 13         41 my $err = $self->mv_gzip($old, $new);
405 13 50       781 push(@errors, $err) if defined $err;
406             } else {
407             # Compression policy changed?
408 1 50       41 rename($old, $new) or
409             push(@errors, "can't rename $old to $new: $!");
410             }
411             }
412            
413             #
414             # Handle renaming of uncompressed files
415             #
416            
417 31         112 for (my $i = $gz_limit - 2; $i >= 0; $i--) {
418 39 100       119 next unless defined $logfiles[$i]; # Not that much backlog yet?
419 30         74 my $old = "$dir/$logfiles[$i]";
420 30         69 my $new = "$path." . ($i+1);
421 30 50       73 warn "rename old=$old, new=$new\n" if $DEBUG;
422 30 100       86 $new .= ".gz" if $old =~ /\.gz$/; # Compression policy changed?
423 30 50       1288 rename($old, $new) or
424             push(@errors, "can't rename $old to $new: $!");
425             }
426            
427             #
428             # Mark rotation, in case they "tail -f" on it.
429             #
430            
431 31         105 my $fd = $self->fd;
432 31         1141 syswrite($fd, "*** LOGFILE ROTATED ON " . scalar(localtime) . "\n");
433            
434             #
435             # Finally, close current logfile and rename it.
436             #
437            
438 31         94 $self->close;
439 31 50       72 if ($gz_limit) {
440 31 50       1334 rename($path, "$path.0") or
441             push(@errors, "can't rename $path to $path.0: $!");
442             } else {
443 0         0 my $err = $self->mv_gzip($path, "$path.0.gz");
444 0 0       0 push(@errors, $err) if defined $err;
445             }
446            
447             #
448             # Unlock logfile and propagate errors to be logged in new current file.
449             #
450            
451 31 50       202 $lock->release if defined $lock;
452 31 50       5918 return @errors if @errors;
453 31         279 return;
454             }
455            
456             #
457             # ->mv_gzip
458             #
459             # Compress old file into new file and unlink old file, propagating mtime.
460             # Returns error string, nothing if OK.
461             #
462             sub mv_gzip {
463 16     16 0 27 my $self = shift;
464 16         29 my ($old, $new) = @_;
465            
466 16         40 local *FILE;
467 16         49 my $st = stat($old);
468 16 50 33     2306 unless (defined $st && CORE::open(FILE, $old)) {
469 0         0 return "can't open $old to compress into $new: $!";
470             }
471 16         73 my $gz = gzopen($new, "wb9");
472 16 50       24422 unless (defined $gz) {
473 0         0 CORE::close FILE;
474 0         0 return "can't write into $new: $gzerrno";
475             }
476            
477 16         30 local $_;
478 16         20 my $error;
479 16         228 while () {
480 48 50       11641 unless ($gz->gzwrite($_)) {
481 0         0 $error = "error while compressing $old in $new: $gzerrno";
482 0         0 last;
483             }
484             }
485 16         1343 CORE::close FILE;
486 16         70 $gz->gzclose();
487            
488 16         4036 utime $st->atime, $st->mtime, $new; # don't care if it fails
489 16 50       1670 unlink $old or do { $error = "can't unlink $old: $!" };
  0         0  
490            
491 16 50       54 return $error if defined $error;
492 16         178 return;
493             }
494            
495             1; # for require
496            
497             __END__