Associating accesses with cache.log entries

From: Mark Nottingham <mnot_at_yahoo-inc.com>
Date: Thu, 27 Nov 2008 14:21:10 +1100

I've been playing around with associating specific requests with the
debug output they generate, with a simple patch to _db_print along
these lines:

     if (Config.Log.accesslogs && Config.Log.accesslogs->logfile) {
       seqnum = LOGFILE_SEQNO(Config.Log.accesslogs->logfile);
     }
     snprintf(f, BUFSIZ, "%s %i| %s",
        debugLogTime(squid_curtime),
        seqnum,
        format);

This leverages the sequence number that's available in custom access
logs (%sn).

It's really useful for debugging requests that are causing problems,
etc; rather than having to correlate times and URLs, you can just
correlate sequence numbers. It also makes it possible to automate
debug output (which is the direction I want to take this in).

beyond the obvious cleanup that needs to happen (e.g., outputting '-'
or blank instead of 0 if there isn't an access log line associated, a
few questions;

* How do people feel about putting this in cache.log all the time? I
don't think it'll break any scripts (there aren't many, and those that
are tend to grep for specific phrases, rather than do an actual parse,
AFAICT). Is the placement above appropriate?

* The sequence number mechanism doesn't guarantee uniqueness in the
log file; if squid is started between rotates, it will reset the
counters. Has fixing this been discussed?

* Is it reasonable to hardcode this to associate the numbers with the
first configured access_log?

* To make this really useful, it would be necessary to be able to
trigger debug_options (or just all debugging) based upon an ACL match.
However, this looks like it would require changing how debug is
#defined. Any comments on this?

Cheers,

--
Mark Nottingham       mnot_at_yahoo-inc.com
Received on Thu Nov 27 2008 - 03:21:25 MST

This archive was generated by hypermail 2.2.0 : Fri Nov 28 2008 - 12:00:06 MST