neb has asked for the wisdom of the Perl Monks concerning the following question:

The following program returns strange results. It will tail along fine. But then suddenly it will read multiple lines from one of the sources files. Lines that are fairly old. Code below, and sample output even lower( notice the time-date stamps)
---Source --- #!/usr/bin/perl -w use strict; use File::Tail; $|=1; my @ports = (10290,10291,10292,10293,10294,10295,10298); my @logs; foreach my $port (@ports) { my $file = "/usr/local/qpxlocal/log/act*" . $port . ".log"; my @files = `/bin/ls -r $file`; if($files[0] ne "") { chomp $files[0]; push(@logs,$files[0]); print "Push $files[0]\n"; }else{ print "Log file for $port is missing!\n"; } } my @files_to_tail; my $debug; foreach (@logs) { push(@files_to_tail,File::Tail->new(name=>"$_",debug=>"1",maxinter +val=>"1",i nterval=>"1", errmode=>"warn",reset_tail=>"-1")); } while(1) { my ($nfound,$timeleft,@pending)=File::Tail::select(undef,undef,und +ef,2,@file s_to_tail); unless($nfound) { my @ints; foreach(@files_to_tail) { push(@ints,$_->interval); } print "Nothing new in the past 1 seconds (" . join(",",@ints) +. ")\n"; } foreach (@pending) { my $file_name = $_->{'input'}; my $read_data = $_->read; $file_name =~ /.+(\d{5})\.log/; my $port = $1; print "$port: $read_data";# unless $_->predict; } }
---End Source---

--Begin output---

>perl big_log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10290.log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10291.log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10292.log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10293.log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10294.log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10295.log Push /usr/local/qpxlocal/log/activity-200104192022-av2J15-10298.log Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) 10290: [20010419 20:22z] AVS started on port 10290 of av2J15.eg.orbitz +.com [av2J15:10290] 10291: [20010419 20:22z] AVS started on port 10291 of av2J15.eg.orbitz +.com [av2J15:10291] 10298: [20010419 20:23z] ERROR: zero-length command received, or timeo +ut (ignored) 10298: [20010419 20:23z] an error occurred processing the last command +: return code -1. 10298: [20010419 20:25z] [987711918182] Flight V0 Cache count= 941 tim +eout= 1000 local= 0 remote= 941 returned= 522 elapsed= 106.61 Nothing new in the past 1 seconds (1,1,1,1,1,1,1) 10290: [20010419 20:27z] [987712053494] Flight V0 Cache count= 712 tim +eout= 1000 local= 0 remote= 712 returned= 336 elapsed= 95.03 Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) 10290: [20010419 20:27z] [987712057676] Flight V0 Cache count= 712 tim +eout= 1000 local= 0 remote= 712 returned= 264 elapsed= 118.06 Nothing new in the past 1 seconds (1,1,1,1,1,1,1) 10290: [20010419 20:27z] [987712061014] Flight V0 Cache count= 712 tim +eout= 1000 local= 0 remote= 712 returned= 376 elapsed= 92.58 Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1) Nothing new in the past 1 seconds (1,1,1,1,1,1,1)

Replies are listed 'Best First'.
Re (tilly) 1: File::Tail Issue
by tilly (Archbishop) on Apr 20, 2001 at 05:57 UTC
    I am not familiar with that module, but I notice two interesting things.

    First of all the documentation says that select is relatively new. Secondly a little later it says that if a file is not updated for a while, that it has logic for checking whether it got truncated, renamed, etc. (Think of log rotation here.)

    I would guess that either this is a bug with its select method, or else someone is moving files from under it, and it is not handling that well...

Re: File::Tail Issue
by neb (Initiate) on Apr 20, 2001 at 17:37 UTC
    The interesting part, is that the file in question is not growing, and is not being rotated.
      In that case I suspect a logic in the "suspicious" code's test. In other words it sees no changes for a long time, then tries to check for change, thinks it sees one, and returns a few lines, waits more and repeats.

      Almost certainly a bug, report it to the module author and/or try to debug yourself. (Putting a debug statement in File::Tail to test when it enters that code will verify my guess, though it won't fix it.)