[Logcheck-devel] Bug#406973: Bug#406973: logtail misses lines in rotated file
Anthony Thyssen
anthony at griffith.edu.au
Tue Aug 14 02:07:39 UTC 2007
Nicolas Boullis on wrote...
| Christoph Berg wrote:
| > Re: Nicolas Boullis 2007-01-15 <20070115110250.GA1867 at kheops.system.ecp.fr>
| >
| >>The attached patch allows to set an alternate logfile that logtail tries
| >>to use as the old logfile if the inode has changed.
| >>It can be used as:
| >> logtail -f /var/log/syslog -a /var/log/syslog.1
| >
| > It would be nice if the "other" filename could be figured out
| > automatically, for example with logrotate's "dateext" or savelog's -d
| > option, the filename is not predictable. (Just scan the whole dir and
| > look for the file with the right inode.)
|
| Sounds like a good idea. But my knowledge of Perl is so limited that I
| probably can't implement it myself. I also think it might be a better
| idea to use a different option for scanning.
| AN other way to solve your problem might be to use a hardlink:
| /var/log/syslog.last would be the /var/log/syslog you last read. If they
| differ (different inodes), read the end of syslog.last, then all syslog
| and then create a new hardlink. Note that this would even work if the
| logfile gets compressed.
|
That works, but I can see problems...
Generally what happens is that when log files get rolled, it is only
after rolling that they THEN is compressed. While it is being
compressed, the compressed form is NOT valid for reading, but the
uncompressed form is still present on disk, and has the right inode
number.
That is you could have two alturnatives, one of which may be invalid
as it is currently being compressed!
My logtail version (still under test) WILL handle this...
First it trys to open {logfile}, then checks the open file's inode.
Second it tries opening {logfile}.1 thne checks the open file's inode.
Note that the files is "helded open", the open being an atomic
operation, that both tests the presence of the file AND opens it.
Once a file is opened it will not just 'dissapear' due to other
processes (like compress) reading it.
Only the file handle is used for the inode checking, not the filesystem
(where the file may not exist any more).
Only when the inode of the first alturnative fails.. does it go to
Third try opening {logfile}.1.gz via 'gzcat'.
Now that can not be checked for consistancy using the i-node test.
However my version saves tha last X (typically 5) lines reported, which
presumably contains a unique enough set of strings (date stamps) to be a
good check that this file is really the log file it last read from (at
that offset).
When it finally found (or reports not finding) the last read point, does
it finish read the alturnative log, then move on to the main log file,
which it previously opened at the start, to complete the job.
The format of the "offset_file" is consistant with the old logtail
offset file, but with extra, posibily binary data appended.
--
I'll include a copy of my logtail script (testing is complete, no
gurantees). Basically too many other matters have been pressing for me
to get back to the testing phase.
Comments and suggestions (or complete re-writes) are welcome.
--
One final thing I thought of since I created this version. logtail when
it finishes, should probably attempt to re-open the original {logfile}
to check is a log roll occurred DURING its log file reading.
My version (still under test) is not doing that yet.
Alturnativeally it could exec itself, if the current inode of the
original {logfile} that was opened changed during its processing.
Remember I am trying to make logfile robust in the face of log rolls
by other processes that could be running in parallel to the logtail
script.
Also it was me that submitted the original bug report about logtail
missing log data in the face of rolled logs.
I do not claim this is the best or nicest way to handle the programming
but I did it before theg the new logtail script was released, which
looks like it is still not robust enough to handle log rolls, happening
in parellel.
Anthony Thyssen ( System Programmer ) <A.Thyssen at griffith.edu.au>
-----------------------------------------------------------------------------
Always choose a bigger enemy. It makes him easier to hit!
--- Terry Pratchett ``The Carpet People''
-----------------------------------------------------------------------------
Anthony's Home is his Castle http://www.cit.gu.edu.au/~anthony/
-------------- next part --------------
#!/usr/bin/perl
#
# logtail log_file offset_file
# logtail [-t] -f log_file -o offset_file
#
# Read the end of the given log file, starting from the last position read.
#
# Expanded to also try to locate a single rolled (and compressed) copy of the
# log file, so that no lines are lost because of automatic system log rolling.
#
# The offset file also saves a copy of the last few log file lines returned.
# This presents a check of a log file, and the last position read, especially
# for gzipped rolled log that nolonger has the same inode as previously.
#
# This check assumes logged lines contains time and date stamp in any form,
# (which is very common practice) making the lines unique enough to be a valid
# check.
#
# Future To Do...
#
# * Look back through even earlier log files, to locate the last rolled log
# that we returned entries from This allows log checks to be more widely
# spaced, yet still not miss logged data due to automatic system log
# rolling.
#
# * checks for other forms of log file compression, such as bzip2
# compression (.bz2), and the UNIX compress (.Z)
#
# * final check to see is a 'roll' happened during log file reading.
#
# History and Copyright.
#
# This command is still under test, and has no gurantees, and programmers
# except no responsibility for the consequences of its use, or mis-use.
#
# Copyright (C) 2007 Anthony Thyssen <A.Thyssen_AT_griffith.edu.au>
# Handle rolled (and gziped) logfiles, with 'last lines' validity check
#
# Copyright (C) 2003 Jonathan Middleton <jjm at ixtab.org.uk>
# Copyright (C) 2001 Paul Slootman <paul at debian.org>
#
# Basied on a C program of same name by Craig H Rowland.
# Which was basied on the utility "retail" (c) Trusted Information Systems
#
##########
use strict;
use warnings;
use FindBin;
use Getopt::Std;
# --- major variables ---
my $prog = $FindBin::Script;
my $max_last_lines = 5; # Number of last lines from logfile to save
my @last_lines; # Array of th elast lines returned
my ($inode, $offset) = (0, 0); # last read logfile inode, and offset
my $last_lines; # The last lines from the logfile just before the offset
my ($logfile, $offsetfile, $rolledlog); # log and offset file names
# --- process arguments ---
my ($TEST_MODE) = 0;
my %opts = ();
getopts("f:o:t", \%opts);
# Try to detect plain logtail invocation without switches
if (!$opts{f} && $#ARGV != 0 && $#ARGV != 1) {
die("$prog: No logfile to read. Use -f [LOGFILE].\n");
} elsif ($#ARGV == 0) {
$logfile = $ARGV[0];
} elsif ($#ARGV == 1) {
($logfile, $offsetfile) = ($ARGV[0], $ARGV[1]);
} else {
($logfile, $offsetfile) = ($opts{f}, $opts{o});
}
if ($opts{t}) {
$TEST_MODE = 1;
}
unless ($offsetfile) {
# offsetfile not given, use .offset/$logfile in the same directory
$offsetfile = $logfile . '.offset';
}
# --- sanity check ---
# Try to open logfile directly
# Try to prevent a posible race condition with log roller and compressor
open(LOGFILE, $logfile)
or die("$prog: File $logfile cannot be read.\n");
# Try to open rolled logfile directly.
# Note the file may be getting compressed at this moment
if ( open(ROLLEDLOG, "$logfile.0" ) ) {
$rolledlog = "$logfile.1";
}
elsif ( -f "$logfile.0.gz" ) {
# Don't worry about opening a compressed log now
$rolledlog = "$logfile.0.gz";
}
elsif ( -f "$logfile.gz" ) {
# Don't worry about opening a compressed log now
$rolledlog = "$logfile.gz";
}
# else - no rolled logfile was seen -- problem?
# --- Read Offset Info ---
# The inode, offset and lines that was last returned.
# Note the offset defines the
# behind the actual real position.
unless (not $offsetfile) {
if (open(OFFSET, $offsetfile)) {
$_ = <OFFSET>;
unless (! defined $_) {
chomp $_;
$inode = $_;
$_ = <OFFSET>;
unless (! defined $_) {
chomp $_;
$offset = $_;
local $/ = undef; # read in rest of file as a 'last lines' check
$last_lines = <OFFSET>;
}
}
}
}
$last_lines = '' unless defined $last_lines;
if ( length($last_lines) < 2 ) {
# The size of the number of last lines output previously
# is too small to be of consequence.
$last_lines = '';
}
if ( length($last_lines) > $offset ) {
print STDERR "$prog: Offset in offset file for $logfile is larger than",
" the 'last lines'!\n";
exit 68;
}
# --- Find last logfile we read from ---
# Check if the current logfile (now open) is the last one we read from.
my $found;
my($log_inode,$log_size) = (stat LOGFILE)[1,7];
if ( $inode == $log_inode ) {
$found = "$logfile";
}
elsif ( $rolledlog =~ /\.gz/ ) {
# This is harder as a compressed log's inode is invalid
# Assume it is OK, and double check using 'last_lines'
$found = $rolledlog;
}
else {
($log_inode,$log_size) = (stat ROLLEDLOG)[1,7];
if ( $inode == $log_inode ) {
$found = $rolledlog;
}
}
if ( ! defined $found ) {
# we did not find any posible matching log file
print "********************** WARNING ************************\n",
"No matching log file $logfile found!\n",
"Too many log roll may have occured, some data may be lost.\n",
"*******************************************************\n"
if $inode != 0;
# as saved inode isn't zero -- start recovery with the rolled log file
$offset = 0;
$last_lines = '';
}
# --- Read a rolled log file (if needed) ---
if ( $inode == 0 ) {
# we have not done any initial logfile read
# so don't bother output a rolled log
}
elsif ( $found eq $rolledlog ) {
if ( $found eq /\.gz/ ) {
# read and output a gzip compressed logfile.
open ( ROLLEDLOG, "gzip -dc '$rolledlog' |")
or die("$prog: Open gzip $rolledlog: $!\n");
# Assume file is the rolled log and just all data up to the 'offset
my $left = $offset-length($last_lines);
# Read output in a maximum of 10 Kbyte blocks
while ($left > 0) {
my $data;
my $n = read( ROLLEDLOG, $data, ($left > 10240 ? 10240 : $left) );
die ("$prog: Read from Gziped Rolled log \"$rolledlog\" failed :$!\n")
unless defined $n;
last if $n == 0; # at EOF
$left -= $n; # number of characters still to read
}
die("$prog: Assertion Failure: read too many bytes from \"$rolledlog\"\n")
if $left < 0;
if ( $left > 0 ) {
# the gziped log file was not long enough!
print "********************** WARNING ************************\n",
"Gzipped Rolled Log $rolledlog is smaller than expected.\n",
"This could mean too many log rolls may have occured,\n",
"or file has been tampered with! Recovering\n",
"*******************************************************\n";
# recover by outputing the whole rolled log found
close( ROLLEDLOG );
open ( ROLLEDLOG, "gzip -dc '$rolledlog' |")
or die("$prog: Open gzip $rolledlog: $!\n");
$last_lines = '';
}
}
elsif ($offset > $log_size) {
print "********************** WARNING ************************\n",
"Log file $found is smaller than expected!\n",
"This could indicate tampering by intruders or rootkit.\n",
"*******************************************************\n";
# recover by outputing the whole rolled log found (no seek)
$last_lines = '';
}
else {
# a uncompressed rolled log
seek(ROLLEDLOG, $offset-length($last_lines), 0);
}
# Check that the 'last lines' are present.
if ( length($last_lines) ) {
my $data;
my $n = read( ROLLEDLOG, $data, length($last_lines) );
die ("$prog: Read from rolled log \"$rolledlog\" failed :$!\n")
unless defined $n;
if ( $data ne $last_lines ) {
print "********************** WARNING ************************\n",
"Rolled Log $rolledlog line do not match saved 'last lines'\n",
"This could mean too many log rolls may have occured,\n",
"or file has been tampered with! Recovering!\n",
"*******************************************************\n";
seek(ROLLEDLOG, 0, 0);
}
}
# Output lines from the rolled log file
init_last_lines( $last_lines );
output_log_lines( $_ ) while <ROLLEDLOG>;
$inode = 0;
}
# --- Read the main log file ---
($log_inode,$log_size) = (stat LOGFILE)[1,7];
if ( $inode == 0 || $offset == 0 ) {
# just read and output the log file as a whole
$offset = 0;
$last_lines = '';
}
elsif ($offset > $log_size) {
print "********************** WARNING ************************\n",
"Log file $found is smaller than expected!\n",
"This could indicate tampering by intruders or rootkit.\n",
"*******************************************************\n";
# recover by outputing the whole rolled log found (no seek)
$last_lines = '';
$offset = 0;
}
else {
seek(LOGFILE, $offset-length($last_lines), 0);
}
if ( length($last_lines) ) {
my $data;
my $n = read( LOGFILE, $data, length($last_lines) );
die ("$prog: Read from rolled log \"$rolledlog\" failed :$!\n")
unless defined $n;
if ( $data ne $last_lines ) {
print "********************** WARNING ************************\n",
"Log file $logfile lines do not match saved 'last lines'.\n",
"This could indicate tampering by intruders or rootkit.\n",
"*******************************************************\n";
seek(LOGFILE, 0, 0);
}
}
# Output lines from the rolled log file
init_last_lines( $last_lines );
output_log_lines( $_ ) while ( <LOGFILE> );
$log_size = tell LOGFILE;
close LOGFILE;
# update offset, unless test mode
unless ($TEST_MODE) {
open(OFFSET, ">$offsetfile")
or die("$prog: File $offsetfile cannot be created. Check permissions.\n");
chmod(0600, $offsetfile)
or die("$prog: Cannot set permissions on file $offsetfile\n");
print OFFSET "$log_inode\n$log_size\n at last_lines";
close OFFSET;
}
exit 0;
# -----------------------------------------------------------
# Save the last lines of the logfile as it is output
#
sub init_last_lines {
# The array always has $max_last_lines elements,
# but some of these may be empty (undefined) strings.
@last_lines = ();
$#last_lines = $max_last_lines-1;
push(@last_lines, spilt(/^/m, @_));
splice(@last_lines, -$max_last_lines );
}
sub output_log_lines {
# print the next log file entry found
# but also note the line for the offset file 'last lines'
print;
push(@last_lines, @_);
splice(@last_lines, -$max_last_lines );
}
# -----------------------------------------------------------
More information about the Logcheck-devel
mailing list