Detect log file rotation (while watching log file

Question

I use the following code to track ssh log-ins:

def follow(thefile):
  thefile.seek(0,2)
  while True:
    line = thefile.readline()
    if not line:
      time.sleep(0.1)
      continue
    yield line

if __name__ == '__main__':
  logfile = open('/var/log/auth.log', 'r')
  loglines = follow(logfile)
  for line in loglines:
    print 'do something here'

I've noticed that this script suddenly stops working after a couple of days. I don't get any error, it doesn't terminate, it just stops working, as if readline() would never return.

So I executed a echo 'test' >> auth.log.1 and this indeed ends up getting processed by the script, because sometime ago auth.log got renamed to auth.log.1

How can I track when such a log rotation happens and adjust accordingly?

Answer 1

you can have a look at the inode, of the file.

import os
inode = os.stat('/var/log/auth.log').st_ino

When the inode changes, the file has been rotated.

Answer 2

Apparently, I can't comment until I have >= 50 reputation.

@daniel-f has a GREAT example! Only edge case I ran into is that, when the service creating the rotating log files I am reading restarts, it deletes the old files and creates new ones.

This causes the 'notifier' to lose visibility into the log file (since it is different).

Since the service writes to the log file every 60 seconds, I did a quick modification to the for loop, shown below:

last_pull = datetime.datetime.now()
while True:
...
...

            for event in notifier.event_gen():
                if event is not None:
                    last_pull = datetime.datetime.now()
                    (header, type_names, watch_path, filename) = event
                    if set(type_names) & set(['IN_MOVE_SELF']): # moved
                        notifier.remove_watch(file_watcher.intput_logfile)
                        file.close()
                        time.sleep(1)
                        break
                    elif set(type_names) & set(['IN_MODIFY']): # modified
                        lines = file.readlines()
                        for line in lines:
                            process(line, file_watcher, history=False)
                else:
                    if (datetime.datetime.now() - last_pull).total_seconds() >= time_to_refresh:
                        last_pull = datetime.datetime.now()
                        notifier.remove_watch(file_watcher.intput_logfile)
                        file.close()
                        break

This re-watches the file after 75 seconds without an update.

Answer 3

Using e4c5's answer I ended up with this code, which also solves the issue of calling readline() multiple times per second.

During the first invocation it skips to the end of the file and waits for modifications. When the file is moved, it reopens the file and reads the entire content, then starts to wait.

import os
import time
import traceback
import threading
import inotify.adapters

logfile = b'/var/log/auth.log'
#logfile = b'logfile.log'

##################################################################

def process(line, history=False):
  if history:
    print '=', line.strip('\n')
  else:
    print '>', line.strip('\n')

##################################################################

from_beginning = False
notifier = inotify.adapters.Inotify()
while True:
  try:
    #------------------------- check
    if not os.path.exists(logfile):
      print 'logfile does not exist'
      time.sleep(1)
      continue
    print 'opening and starting to watch', logfile
    #------------------------- open
    file = open(logfile, 'r')
    if from_beginning:
      for line in file.readlines():
        process(line, history=True)
    else:
      file.seek(0,2)
      from_beginning = True
    #------------------------- watch
    notifier.add_watch(logfile)
    try:
      for event in notifier.event_gen():
        if event is not None:
          (header, type_names, watch_path, filename) = event
          if set(type_names) & set(['IN_MOVE_SELF']): # moved
            print 'logfile moved'
            notifier.remove_watch(logfile)
            file.close()
            time.sleep(1)
            break
          elif set(type_names) & set(['IN_MODIFY']): # modified
            for line in file.readlines():
              process(line, history=False)
    except (KeyboardInterrupt, SystemExit):
      raise
    except:
      notifier.remove_watch(logfile)
      file.close()
      time.sleep(1)
    #-------------------------
  except (KeyboardInterrupt, SystemExit):
    break
  except inotify.calls.InotifyError:
    time.sleep(1)
  except IOError:
    time.sleep(1)
  except:
    traceback.print_exc()
    time.sleep(1)

##################################################################

Answer 4

This is best done with inotify you don't want to keep polling the file system to ask if things have changed during each iteration of the loop. That's a lot of wasted IO. inotify will notify you when a change occurs. There is an example right from the manual which shows it's usage with log file.