Things n' Stuff Thoughts about the universe in general

As system administrators we often want to list the last few lines from a log file in order to track problems and see system reports. The UNIX command tail is very useful for that purpose and lets you display an arbitrary number of lines from the bottom of any file.

But often this is not really what you want – an administrator might want to see what happens in the last X minutes and the common practice to do this is to run tail with a guessed number of lines, see if you get what you want and if its not enough increase the number and try again.

Here’s another approach that works well if the log file you want to trace has time stamps for its lines – use UNIX date command to format the earliest time stamp you want to see and then filter on that.

For example, to list the last 10 minutes of logs from an Apache log file, one can use this command:


# grep "$(date -d "10 minutes ago" +"%d/%b/%Y:%H:%M:%S")" -A 999999 /var/log/httpd/access_log


Here we take advantage of the fact that date is very user friendly about interpreting date definitions to format an easy to understand relative time stamp – You can use almost any plain English time definition to tell date what time you need¹. After formatting a time stamp according to your log convention ( “%d/%b/%Y:%H:%M:%S” is for Apache’s access log time stamp. Syslog logs or other logs will need different format specifications), we use grep to find a line that matches and show as many lines after that as we need (hopefully all of them – choose a -A large enough for your purposes).

The one major caveat of this approach is that it relies on your log to have at least one message every second, otherwise the exact second that date computed may not have a corresponding message in the log and then grep will not find it and will not output anything. Working around that problem is not that simple though – we’d have to read every line in the log, actually parse the time stamp in the log and compare it to the time stamp we provide and if the log time stamp is later – only then display the line. grep is useless for this because it can’t do any comparison other then comparing texts to check that they are identical.

My solution for this is to use date again to parse the date format in the log file (maybe with some modifications so date won’t get too confused) and then simply compare epoch time values:


# cat /var/log/httpd/balancer-access_log | (
date=$(date -d "10 minutes ago" +"%s")
while read line; do
[ "$(date -d"$(echo $line | cut -d']' -f1 | sed -e 's/.*\[//;s/\// /g;s/:/ /;')" +"%s")" -ge "$date" ] && echo $line
done)


What I do here is to pipe the log file through a while read loop – this will read each line into the $line variable, consuming all the log lines until the end of the file is reached. Each line is then put through some sed to extract the time stamp in a way that date will like it (again – the code above works for Apache access logs. Other log types may need more or less massaging to get at a parsable time values, but either way a different code will be needed). We then put the time stamp through date and use the format code +"%s" to get an epoch time stamp and compare it to the epoch time stamp we generated at the beginning from our “free language” time specification. If the parsed time value is greater (or equal) then we display the line.

The one major disadvantage of giving up on grep is the performance that will be orders of magnitude worse when you actually have to do some processing of data :-).

1. for example, compare date -d "12:45 monday" +"%d/%b/%Y:%H:%M:%S" and date -d "12:45 last monday" +"%d/%b/%Y:%H:%M:%S" [↩]

This entry was posted on Thursday, April 8th, 2010 at 10:28 and is filed under Articles, Script Day, Software. You can follow any responses to this entry through the RSS 2.0 feed. You can leave a response, or trackback from your own site.