Re^2: Using binary search to get the last 15 minutes of httpd access log

[mcdave]

Very minor quibble, and not about Perl. But Apache creates the the timestamp from when the request is received yet writes to the file when the request is served. So, if you've got requests that take a long time to return, or lots of requests that take a very short time, you logs won't be ordered by time.

So, if it's 12:00, and A is a long-running request that started at 11:44 and B is a short-running request, the order of events could be

11:44:00...
 A received
11:45:10...
 B receievd
11:45:11...
 B served
11:46:00...
 A served

and the log will read

11:45:11 B
11:44:00 A

in that order, so your backward search would stop at A.

If "last 15 minutes" means "approximately last 15 minutes" and your server is relatively zippy, you're fine. I have sometimes needed 15 minutes to mean "exactly 15 minutes", though, so I happen to know this trivial about Apache.

[davido]

That being the case there's virtually no way to assure a slow request isn't lurking in the past without scanning back 15 minutes plus some known timeout interval. Still reading backward, plus a timeout interval is probably more reliable than doing a binary search on a file that may not be in correct order. Binary searches aren't too good with fuzzy sortedness. ;)

[mhearse]

That is a valid point which I considered too. But this script will run on a loghost. And if I remember correctly... the timestamp will be applied to the messages as they arrive to the loghost.

[mhearse]

Here is the code I ended up using to search the ordered apache logs for a specific time block.

#!/usr/bin/env perl

use strict;
use Search::Dict;

open my $fh, "/var/log/http/access_log";
my $start = 'Oct  2 10:21:';
my $end = 'Oct  2 10:2[1-2]:';
look $fh, $start;

while (my $line = <$fh>) {
    last if ($line !~ /$end/);
    print $line;
}

Also, looks like I should have done a more thorough search