Tail'ing a log that frequently rolls over

[frd1963]

I have written a script to look for a specific string occurring within a log on a windows system. The log fills up very quickly and therefore rolls over (rotates) often. For some reason though, while my script is running, the file will not roll-over, presumably because the rolling mechanism cannot get a suitable lock on the file. I have tried using File::Tail and POE::Wheel::FollowTail and both work fine except for not allowing the file to roll-over.

As an experiment, I have tried using SFU's "tail -f" and that doesn't keep the rollover from occurring, but of course also doesn't follow the new file when a roll-over does occur.

I can think of several ways to periodically release and re-open the file, but it is too easy to miss an occurrance of the issue that way.

I will paste the applicable code from both methods I have tried below.

Any enlightenment would be greatly appreciated,
-Frd

File::Tail code:

    my $file=File::Tail->new(name=>"$SEARCH_LOG", maxinterval=>10);
    LogIt("Initiated 'tail' ... reading file '$SEARCH_LOG':\n");
    LogIt("    ... Looking for '$STRING'\n");

    while (defined(my $line=$file->read)) {
        LogIt("Read line: $line");
        next unless ( $line =~ /$STRING/ );
        LogIt("That Line MATCHES SEARCH STRING: '$STRING'\n");
        lock($occurred);
        $occurred ++;
        LogIt("$line");
        LogIt("Increasing OCCURRED flag to '$occurred'");
    }

POE code:

POE::Session->create(
    inline_states => {
        _start => sub {
            $_[HEAP]{tailor} = POE::Wheel::FollowTail->new(
                Filename   => "$SEARCH_LOG",
                InputEvent => "got_log_line",
                ResetEvent => "got_log_rollover",
            );
        },
        got_log_line => sub {
            my $line = $_[ARG0];
            LogIt("Read line: $line");
            return unless ( $line =~ /$STRING/ );
            LogIt("That Line MATCHES SEARCH STRING: '$STRING'\n");
            lock($occurred);
            $occurred++;
            LogIt("$line");
            LogIt("Increasing OCCURRED flag to '$occurred'");
        },
        got_log_rollover => sub {
            LogIt("Log rolled over.\n");
        },
    }
);

[BrowserUk]

The native port, tail.exe that comes with UnxUtils supports the -F switch (follow the name, not the descriptor) and that seems to work for this. I use it this way:

my $pid = open LOG, "tail -F theLog |" or die $!;

while( <LOG> ) {
    ###
}

[frd1963]

Great idea!
I am a unix guy in general and knew that the GNU tail had the functionality I was looking for, but I didn't know there were individual, standalone native ports.
I am Downloading that now and will let you know how it works out.

Thanks!
-Frd

[frd1963]

Well it seems there are bugs with the UnxUtils version of tail as well. When using it in a perl script with any form of the "follow" options (e.g., "tail -f", "tail --follow", etc.) it never gives anything and the tail.exe process needs to be maually killed. "tail -f" works OK on the commandline except when its output is piped to another process (even "cat".) When run without the '-f' however, it works as one would expect.
Still looking for a better solution and will update this thread once I find one.

$fh->open("tail.exe --follow=name tls.log|") || die $!;
print("opened: '$fh'\n");
while(my $c = $fh->getc) {  # hangs here. tried getline also
    print("$c");
}
print("closing: '$fh'\n");
close($fh);

[BrowserUk]

any form of the "follow" options (e.g., "tail -f", "tail --follow", etc.) it never gives anything

Hm. It's possible you have a newer version that is fundementally broken and nobody has noticed, but I seriously doubt it. It is more likely to be how you are using it. The following two scripts demonstrate that it works:

A simulated high speed, rotating logger:

#! perl -slw
use strict;

my $logname = 'theLog';

while( 1 ) {
    open LOG, '>', $logname or die $!;
    for( 1 .. 1000 ) {
        print LOG "Line $_ of the log with some superfluous extra text
+ as filler";
    }
    close LOG;
    my $n = 0;
    $n++ while -e "$logname.$n";
    rename $logname, "$logname.$n";
}

A tail -F script:

#! perl -sw
use strict;

my $pid = open LOG, "tail -F theLog |" or die $!;

$SIG{ INT } = sub{
    close LOG;
    kill 3, $pid;
    exit;
};
$SIG{ BREAK } = $SIG{ INT };

while( <LOG> ) {
    print;
}

the tail.exe process needs to be maually killed.

Methinks you have unreal expectations. Any version of tail on any platform when used with -F (--follow=name) will have to be explicitly terminated, whether manually or programmically, by some external influence. It could not be any other way.

When following a rotating named file, there will always be a short but real period between the renaming of the old log and the creation of the new one. Sp tail has to be written to ignore any 'file not found' errors from open and retry. There is therefore, no reasonable condition for it to self terminate.

So your script would have to decide the conditions under which tail should be terminated and call kill to do so using the $pid returned by the open. (See the signal handler above.)

So then it falls to your script to decide when it should terminate. Whether because

• the user interrupted it from the keyboard or via some other action;
• or because (for example,) it is monitoring the program that is producing the log and detects that it has terminated.

If the latter, it will be necessary for you to detect the demise of the log producer in a timely manner, before re-entering the read state.

You appear to be under the impression that tail will be able to know when the program producing the logs isn't going to create another new one, and self-terminate, but that simply cannot be the case.

Perhaps that is the source of your problems with File::Tail and the POE solutions. Ie. Your expectations are wrong.

[zentara]

Tk tail -f - How? may have some ideas for you.

[hbm]

I've been tail'ing this thread with great interest! I currently monitor a log with this daemon. Notable differences from OP's environment - I'm on Unix and I rotate the log myself, monthly.

use strict;
use warnings;
use POSIX;
use IO::Handle;

my $appLog    = '/tmp/t.txt';
my $error     = 'Fatal Error';

exit            if (my $pid = fork);
defined($pid)   or die "Can't fork: $!";
POSIX:setsid()  or die "Can't setsid: $!";

$SIG{TERM} = sub {
   close LOG;
   exit;
};
$SIG{INT}  = $SIG{TERM};
$SIG{PIPE} = 'IGNORE';
$SIG{HUP}  = \&readLog;

sub readLog {
   open(LOG,"<$appLog")    or die("Unable to open $appLog: $!");
   while (<LOG>) { ;; }    # read to the end of the log
   LOG->clearerr();        # and clear EOF flag
}
&readLog;
for (;;) {
   while (<LOG>) {
      #&pageMe  if /$error/;
      print;
   }
   sleep 2;
   LOG->clearerr();   # clear EOF flag
}

This works pretty well for me. On the downside, it quietly stops working if the log is truncated or created anew. But I work around that by HUP'ing it after I rotate the log.

But hello, -F! (Who knew about it? Not my, um, man tail.) So I've tried this:

use strict;
use warnings;
use POSIX;

my $appLog    = '/tmp/t.txt';
my $error     = 'Fatal Error';

exit            if (my $pid = fork);
defined($pid)   or die "Can't fork: $!";
POSIX:setsid()  or die "Can't setsid: $!";

my $tail      = open(LOG,"/usr/local/bin/tail -F $appLog|") or die "Ca
+n't tail: $!";

$SIG{INT}     = sub {
   close LOG;
   kill 3, $tail;
   exit;
};
$SIG{TERM}    = $SIG{INT};
$SIG{PIPE}    = 'IGNORE';
$SIG{HUP}     = 'IGNORE';

while (<LOG>) {
   #&pageMe   if /$error/;
   print;
}

This seems a bit more succinct; and it gracefully handles a truncated or recreated file. A downside, perhaps, is that it creates a second process; but more importantly if I kill the daemon, the tail process doesn't receive the signal until the log is next written-to.

Any thoughts on getting my original daemon to internally handle the truncated/recreated log?

Or how the second daemon can kill the tail -F immediately?

[BrowserUk]

You could try this:

use strict;
use warnings;
use POSIX;
use Perl::Unsafe::Signals;

my $appLog    = '/tmp/t.txt';
my $error     = 'Fatal Error';

exit            if (my $pid = fork);
defined($pid)   or die "Can't fork: $!";
POSIX:setsid()  or die "Can't setsid: $!";

my $tail      = open(LOG,"/usr/local/bin/tail -F $appLog|") 
        or die "Can't tail: $!";

$SIG{INT}     = sub {
   close LOG;
   kill 3, $tail;
   exit;
};
$SIG{TERM}    = $SIG{INT};
$SIG{PIPE}    = 'IGNORE';
$SIG{HUP}     = 'IGNORE';

UNSAFE_SIGNALS {
    while (<LOG>) {
       #&pageMe   if /$error/;
       print;
    }
};

[hbm]

Some day, but I'm stalled at Perl 5.8.0 and it requires 5.8.1. Thanks for all your suggestions on this topic!