starting from last line processed when processing log file several times

Question

I am designing a logging and reporting system for a web application.
Within the web application some events can happen ("user logged in", "user performed action X", etc..).
I would like the application to log these events in a flat log file.
Then I would like to write another program that would periodically get run and extract data from this file to maintain a running aggregate report in a database table (like "how many events of type X happen per hour", or "get the daily total of event X").

One of the challenges is to make sure that the reporting program doesn't process the same line twice.

Is there a Unix way to design this type of system or to deal with the "keep track of lines already processed" kind of problem?

I already thought about rotating the logs just before processing them and assigning unique line numbers to each line, but they both seem hacky.

Thank you.

Answer 1

Rotating the logs before parsing them sounds like a good idea really, as long as your applications don't keep the log file open permanently. If they do, rotating them wont work - but since you're writing the logging framework, you can deal with this.

If you want a simple scripted thing, you could use something like the following (could be done in pretty much any scripting language):

#! /bin/bash

process_line() {
    # do the work here
    echo "== $1 =="
}

logfile=$1
statefile=${logfile}.state

if [ -f ${statefile} ] ; then
    processed=$(cat $statefile)
else
    processed=0
fi

curline=0
IFS='
'

while read line ; do
    if [ $curline -ge $processed ] ; then
        echo processing $line
        process_line "$line"
    fi
    curline=$(($curline+1))
done < ${logfile}

echo $curline > $statefile

Basically, it saves up to where it processed input in a separate file ($statefile), and processes the input line by line from that point (skipping the already processed ones).

This would need a bit more error handling obviously, and if the input is large, it's not optimal. (Could be made better by saving a byte offset and seeking, or using dd bs=1 skip=$already_read count=$(($size-$already_read)) to pipe out to another process rather than doing things line by line, but I'd go with perl if that kind of optimization is necessary.)

As it is, the script will process lines twice if it's interrupted. You can limit the amount of "replay" by updating the state file after each line rather than once at the end.

If you both process the logs and rotate them, you'll need to be careful with those state files. They would need to be rotated too, and the script run once after rotation to process the last lines of output.

There is one thing that this approach does not deal with easily: partial lines. If the application is writing while the script runs, there is a chance that the script will see a partial last line. It won't be able to tell the difference, so it will record it as having been processed. (This is a problem you'll need to deal with with pretty much any approach.)

This could be avoided by having an EOL marker in your log file format, and checking for that before processing the line. But that's not very pretty.

Rather than doing the processing in bash in the script itself, you could use it like this (replace process_line with a plain echo):

$ ./logger /var/log/app12.log | ./analyzer --logtype=app12

./analyzer will get the data as input.