flori / file-tail

File::Tail for Ruby
http://flori.github.com/file-tail
Apache License 2.0
160 stars 19 forks source link

fix: don't skip over lines during file rotation #14

Open kanseiishikawa opened 2 years ago

kanseiishikawa commented 2 years ago

The Problem

I found a bug in file-tail in which it occasionally fails to pick up newly added lines when the target file is rotated. When file-tail reaches EOF while reading a file, it re-stats the file path to ensure that it's still operating against the same file. If it detects that the original file is no longer there, it reopens the file and resumes reading from the beginning of the file. This way, file-tail can keep tail-ing files that are periodically rotated.

However, depending on the timing of events, file-tail resumes reading from the end of the new file instead of the beginning. If the target file doesn't exist when stat-ing the file but is recreated just before it's reopened, file-tail reads the new file from the end. When this happens, file-tail skips over the existing contents of the new file that are written before it's opened. Here's an example timeline:

  1. Make file-tail watch file.txt.
  2. file.txt is moved to file.txt.bak.
  3. file-tail stats file.txt and gets an ENOENT resposne.
  4. file.txt is newly created.
  5. New contents are written to the newly created file.
  6. file-tail reopens file.txt and resumes reading from the end of the file.

Reproduction Steps

The problem can be triggered using two separate processes. I'll refer to them as the reader and writer processes.

The writer process counts numbers starting from 0 and appends those numbers line by line to file.txt. When the count reaches 99, it rotates the file by renaming file.txt to file.txt.bak and creating a new file.txt. It then repeats the process by counting again from 0.

The reader process, on the other hand, uses file-tail to tail file.txt. It tracks the numbers written to the file and verifies that it counts up from 0 through 99 in a loop. If it finds a missing number, it will stop running. If the reader process stops running, that means it skipped over some lines during file rotation.

Reliable reproduction might be difficult because execution timing is key to triggering the bug.

Here are the code for both the reader and writer processes:

reader:

require 'file-tail'
require 'time'
require 'timeout'

start_time = Time.now
wf = File.open( 'result.log', mode = 'w' )
count = 1

File.open('sample.log', File::RDONLY | File::CREAT) do |f|
  f.extend(File::Tail)
  f.backward(0)
  f.tail do |line|
    if count % 100 != line.to_i then
      puts line
      puts "finish!!!"
      break
    else
      puts count
      count += 1
    end
  end
end

writer:

#include <chrono>
#include <cstdio>
#include <iostream>
#include <fstream>
#include <ostream>
#include <string>
#include <thread>

int main() {
    std::string file_name = "sample.log";
    std::string rewrite_file_name = "sample_rewrite.log";

    int count = 0;

    while( 1 ) {
        std::fstream file;
        file.open( file_name, std::ios::out );

        for( int r = 0; r < 100; r++ ) {
            count += 1;
            file << count % 100 << std::endl;
        }

        file.close();

        std::rename( file_name.c_str(), rewrite_file_name.c_str() );
        std::this_thread::sleep_for( std::chrono::milliseconds( 100 ) );
    }
}

The fix

Always make file-tail read the reopened file from the beginning.