Re: [PATCH] Enhanced access logging, added ICAP logging, bug #2495 fix.

From: Alex Rousskov <rousskov_at_measurement-factory.com>
Date: Thu, 09 Jul 2009 22:57:00 -0600

On 07/09/2009 12:06 AM, Amos Jeffries wrote:
> Tsantilas Christos wrote:
>> This is the second part of the 3p1-plus patch. This patch include:
>>
>> - Enhanced access logging
>> (<Hs, <sh, >sh, <pt, <tt, icap::total_time, and icap::<last_h)
>>
>> - ICAP logging
>> (see icap_log and log_icap in squid.conf as well as
>> http://wiki.squid-cache.org/Features/AdaptationLog).
>>
>> - ICAP retries based on the ICAP responses status code
>> (see icap_retry and icap_retry_limit in squid.conf).
>>
>> - Support logging resp. times of adaptation transactions to access.log
>> (%adaptation::sum_trs and %adaptation::all_trs)
>>
>
> IMO full 'adaptation' is too long. Opinions on using the abbreviation
> 'adapt::' here?

Either way is fine with me. If Christos does not prefer the full
version, let's change to adapt::

>> - Support logging of total DNS wait time to access.log
>> (%dt)
>>
>
> +1.
>
> The only sightly better but harder way is to make this DnsLookupDetails
> object the DNS cbdata object itself, and contain the RR being fetched as
> a sub-field. That would keep the error per-fetch not per transaction.
> If someone wants to simplify the code later theres a project.
>
> Meanwhile go with this.

I think I have started with something similar but then realized that
different parts of the code (e.g., IP cache and FQDN cache) need
different objects to store the actual lookup result. They also use
pointers into caches that may not survive across async calls (because
the cache may change) so storing the result would require allocating
memory or locking cache entries for a "long" time.

At some point, I made DnsLookupResult store and then forget the RR-level
details when crossing the async boundary. That code looked somewhat
over-engineered to me.

This is why I eventually limited the DnsLookupDetails object to the
details that need to cross the async call boundaries and are common to
all lookup users.

I do not mean to discourage others from trying to add RR or derivative
results to DnsLookupDetails. Just keep the above in mind.

>> - Bug #2495 fix
>
> Oops; bug is: 2459: dns_error_message global does not work...

My fault. I had it backwards in some of the notes that Christos inherited.

> ** Please make fqdncache_entry / ipcache_entry public classes instead
> of functional structs. Some gcc complain and doxygen won't document
> their functions properly.

Sorry, I am not sure what you mean. What is a "functional struct"? Do
you want us to replace "struct fqdncache_entry" with "class
fqdncache_entry" and add "public:"?

No objections, of course, just wanted to minimize merging headaches by
keeping out-of-scope changes to the minimum...

>> I also have some questions to developers:
>> - In squid.conf documentation I prepend each
>> HTTP format code with [http::]
>> Is it OK?
>
> Most of them yes.
>
> There are a few where http:: does not make sense at all:
> ts Seconds since epoch
> tu subsecond time (milliseconds)
> tl Local time. Optional strftime format argument
> tg GMT time. Optional strftime format argument

Definitely.

> dt Total time spent making DNS lookups (milliseconds)
> ui User name from ident
> us User name from SSL

Yeah, at least for now.

> These are also borderline:
> >a Client source IP address
> >A Client FQDN
> >p Client source port
> la Local IP address (http_port)
> lp Local port number (http_port)
> <A Server IP address or peer name

Agreed.

> I'm fine with ignoring http:: for now if people do enter it for these,
> so no coding change. But I don't think we should document them that way.

Agreed.

> I'd shift the clearly HTTP ones out to a section like you have ICAP.
> Leaving the rest prefix-ambiguous until something is done properly.

Or at least remove the http:: prefix in the documentation from those
mentioned above.

>>
>> - Should we replace icap::Hs with icap::<Hs ? Any opinion?
>> (My opinion is we should not because the icap::>Hs does not make
>> sense)
>
> Agreed. Makes no sense at this time.

OK.

> In src/AccessLogEntry.h:
> struct IpAddress => remove the "struct", it's a class in 3.1+.

OK.

> Where an existing short measure tag I don't think we need to add a new
> long one yet:
> icap::total_time / icap::tt
> icap::>size / icap::>st
> icap::<size / icap::<st

OK.

> adaptation::sum_trs / adaptation::tt

These are very different! Tt is a single value while adapt::sum_trs is a
list (of individual tr's). Adapt::sum_trs is also symmetric with
adapt::all_trs (also a list, but possibly with more entries).

> Yes they are not ideal, but they are there and what people are used to
> for now. We can minimize confusion a bit.

OK.

> I think at the point you do:
> + case LFT_HTTP_SENT_STATUS_CODE_OLD_30:
> + debugs(46, 0, "WARNING: the \"Hs\" formating code is deprecated
> use the \">Hs\" instead");
> + break;
>
> you could also set
> "lt->type = LFT_HTTP_SENT_STATUS_CODE;" to reduce the need for that
> OLD_30 type being used outside the parse. Particularly during the config
> dump later it is useful to display what its supposed to be.

Sounds good.

> I spy a goto that can die...
> case CLF_NONE:
> goto last;
> @@ -1458,7 +1863,15 @@
> last:
> (void)0; /* NULL statement for label */
> +}
>
> ==> equates to "return;". Please check for others in that same function.

Sounds kind of out of scope but no objections if Christos agrees.

> I see: "// TODO: should we disable unneeded _parts_ of the history?"
> the glib answer is yes. By appearances there was some disabling of the
> logging code already done. If thats all I think the TODO can go. If
> there is more to be done towards that, leave it and the rest for 3.2+

There is more to be done. IIRC, the current code enables [whole] history
if it is needed by at least one of the history users. In some (but not
all) contexts, this will cause other users to update the history even if
the part they are updating may never be used. I do not think I managed
to kill all such cases -- the inter-dependencies and multiple levels of
users/updaters make that relatively complex.

IMO, it is not a big problem for now, but if the history grows, we may
have to do better. I would leave that TODO.

> most icap file:
> Anything including acl/FilledChecklist.h does not need to also
> include acl/Checklist.h.

OK.

Thanks a lot for reviewing this large patch!

Alex.
Received on Fri Jul 10 2009 - 04:57:11 MDT

This archive was generated by hypermail 2.2.0 : Fri Jul 10 2009 - 12:00:04 MDT