Log monitoring with pythonic tail -f and process killing

Question

The purpose of this cluster of functions is to tail the log file and kill/restart processes from shell (the latter is not yet implemented).

import sys
import time
import datetime
import os
import re


def read_log(f):
    """
    Basically tail -f
    """
    logfile = open(f)
    logfile.seek(0, os.SEEK_END)
    while True:
        new_line = logfile.readline()
        if new_line:
            yield new_line
        else:
            time.sleep(0.1)


def find_error(line, base_time, line_time):
    """
    Search for ERROR keyword in log line. Return True if found, False if not.
    """
    match = re.search('.*ERROR.*', line)
    if match and line_time < base_time:
        return True
    return False


def parse_time(line):
    """
    Parse string to datetime
    """
    date_regex = r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}'
    date_string = re.search(date_regex, line).group(0)
    return datetime.datetime.strptime(date_string, "%Y-%m-%d %H:%M:%S")


def increase_base_time(line_time):
    """
    Return a datetime that is line_time plus one minute
    """
    return line_time + datetime.timedelta(minutes=1)


def monitor(filename):
    """
    Read from a log file.
    For each line check if log line time is later than base comparison time.
    If so, update the base time and set error count to 0.
    Check for errors in line. Increment error count if any are found.
    Check the total error count. If it's greater than five, restart the logged 
    process. 
    Check if process has been restarted before. If so, kill the logged process.
    """
    count = 0
    base_time = datetime.datetime.min
    log = read_log(filename)
    restarted = False
    for line in log:
        line_time = parse_time(line)
        if line_time > base_time:
            base_time = increase_base_time(line_time)
            count = 0
        if find_error(line, base_time, line_time):
            count += 1
        if count >= 5:
            if restarted:
                print("Kill the process") # A placeholder, sorry
            else: 
                print("Restart the process") # Also a placeholder, sorry
                count = 0
                restarted = True


monitor(sys.argv[1])

There are a lot of if-statement for doing checks. I thought about making this class based, but it really doesn't make sense to do it (functions don't need to share states and it is a rather small program). Is the number of if's acceptable? How could I refactor the code to make it flow a bit better?

EDIT: As this was brought up, is it necessary that the tailing function would be non blocking? As I understand I wont be doing nothing until a line is yielded. What would be the benefits of going one way or the other?

Answer 1

Using regex for such a simple task as finding if a line contains a string is not worth it. The built-in str.__contains__, being called by the keyword in is faster in this case.

Here are some worst case (i.e. a string that does not contain the string "ERROR") timings for the two functions:

import re

def using_in(s):
    return "ERROR" in s

def using_re(s):
    return bool(re.search('.*ERROR.*', s))

Using re is always slower in this case. It does, of course, have its uses for more complex patterns. Note that the re module also compiles the regex automatically (and caches it), so that is not a way to make it faster in this case, since it is always the same regex being used.

Let's just hope your lines are less than 10,000 characters long.

---

In general, I think you still have to find a good balance between not having enough functions and having too many. IMO, instead of having a increase_base_time function, I would have a global constant and inline the call:

INCREMENT = datetime.timedelta(minutes=1)

...

for line in log:
    ...
    if line_time > base_time:
        base_time = line_time + INCREMENT
        ...

---

If read_log is a tail -f equivalent, you could just call it tail_f. In any case, I would make the sleep time an optional parameter.

Note that your function does not ensure that the file is properly closed, which might cause issues. You should always use the with keyword to avoid this.

def read_log(f, sleep=0.1):
    """
    Basically tail -f with a configurable sleep
    """
    with open(f) as logfile:
        logfile.seek(0, os.SEEK_END)
        while True:
            new_line = logfile.readline()
            if new_line:
                yield new_line
            else:
                time.sleep(sleep)

This way the file is closed even if the user presses Ctrl+C.

---

You should only call your function under a if __name__ == "__main__": guard to allow importing from this script without it (trying and failing to) run:

if __name__ == "__main__":
    monitor(sys.argv[1])

Answer 2

... about making this class based, but it really doesn't make sense to do it ...

I'd not agree with that, because:

• same arguments filename/f and line are passed around across multiple functions
• with custom class approach the things can be initialized/defined at once (on class definition or instantiation phase)
• with OOP approach I'm confident that functions like parse_time(line) or find_error(line, ...) are not passed with undesirable or "tricky" line argument, as the line being currently read can be encapsulated.

---

List of issues (with support of OOP approach):

• pattern date_regex = r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}'.
  Instead of generating regex pattern on each call of parse_time function - we'll just make it a class LogMonitor constant called DATE_REGEX.
  Furthermore, we can precompile the regex pattern with re.complie function:

using re.compile() and saving the resulting regular expression object for reuse is more efficient when the expression will be used several times in a single program

    DATE_REGEX = re.compile(r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}')

• increase_base_time function.
  datetime.timedelta(minutes=1) is easily extracted to another constant:

  INC_MINUTE = datetime.timedelta(minutes=1)
  

• find_error(line, base_time, line_time) function.
  Besides of simplifying ERROR pattern search (as @Graipher mentioned) the function has another issue as it introduces an unnecessary coupling/dependency on two external identifiers base_time and line_time - whereas the sufficient function's responsibility is "check if ERROR occurs within the current log line" (returning boolean result)
  That dependency should be eliminated.
  To "beat" that, the crucial conditional within monitor function that calls the find_error function can be restructured to present a natural order of mutually exclusive conditions:

      ...
      if line_time > base_time:
          base_time = self.increase_base_time(line_time)
          count = 0
      elif self.find_error():
          count += 1
  

---

In below OOP implementation the input filename is passed at once to LogMonitor constructor as LogMonitor(sys.argv[1]), the functions are logically renamed, the needed state/behavior is encapsulated, the above mentioned OOP benefits/arguments included.

import sys
import time
import datetime
import os
import re


class LogMonitor:
    DATE_REGEX = re.compile(r'\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}')
    INC_MINUTE = datetime.timedelta(minutes=1)

    def __init__(self, filename):
        self._fname = filename
        self._log = self._read_log()    # generator
        self._curr_line = ''

    def _read_log(self):
        """Basically tail -f"""
        with open(self._fname) as logfile:
            logfile.seek(0, os.SEEK_END)
            while True:
                new_line = logfile.readline()
                if new_line:
                    self._curr_line = new_line
                    yield self._curr_line
                else:
                    time.sleep(0.1)

    def _has_error(self):
        """
        Search for ERROR keyword in log line. Returns boolean result"""
        return 'ERROR' in self._curr_line

    def _parse_datetime(self):
        """Parse string to datetime"""
        date_string = self.DATE_REGEX.search(self._curr_line).group(0)
        return datetime.datetime.strptime(date_string, "%Y-%m-%d %H:%M:%S")

    def increase_base_time(self, line_time):
        """Return a datetime that is line_time plus one minute"""
        return line_time + self.INC_MINUTE

    def run(self):
        """
        Read from a log file.
        For each line check if log line time is later than base comparison time.
        If so, update the base time and set error count to 0.
        Check for errors in line. Increment error count if any are found.
        Check the total error count. If it's greater than five, restart the logged
        process.
        Check if process has been restarted before. If so, kill the logged process.
        """
        count = 0
        base_time = datetime.datetime.min
        restarted = False

        for line in self._log:
            line_time = self._parse_datetime()
            if line_time > base_time:
                base_time = self.increase_base_time(line_time)
                count = 0
            elif self._has_error():
                count += 1

            if count >= 5:
                if restarted:
                    print("Kill the process")  # A placeholder, sorry
                else:
                    print("Restart the process")  # Also a placeholder, sorry
                    count = 0
                    restarted = True


if __name__ == "__main__":
    monitor = LogMonitor(sys.argv[1])
    monitor.run()

Answer 3

Here is my contribution.

You should not make the while True loop, instead of that you should use inotify in order to been notify only when changes happen on the file that you are monitoring, here is a short code.

import inotify.adapters

def _read_log(self):
    i = inotify.adapters.Inotify()

    i.add_watch(f)

    with open(f, 'w'):
        pass

    for event in i.event_gen(yield_nones=False):
        (_, type_names, path, filename) = event

        do_work()

Basically your process will be only unblock until there are some changes on the file that you are monitoring.