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

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?

> - 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.

> - Bug #2495 fix

Oops; bug is: 2459: dns_error_message global does not work...

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

>
>
> Moreover it includes the following changes which requested by Amos:
> - the "Hs" formating code renamed to "<Hs"
> - The user still can use the "Hs" formating code but will see a
> warning in his logs
> - s/LFT_LAST_MATCHED_ICAP_/LFT_ICAP_LAST_MATCHED/g
> - s/icap_/icap::/ in access log format codes only.
> - s/LFT_SENT_HTTP_CODE/LFT_HTTP_SENT_STATUS_CODE/ and
> s/LFT_RECEIVED_HTTP_CODE/LFT_HTTP_RECEIVED_STATUS_CODE/

> - Add support for "http::" prefix for access log format codes

Good idea. Bit more polish to it though ....

>
> 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
        dt Total time spent making DNS lookups (milliseconds)
        ui User name from ident
        us User name from SSL

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

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.

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.

>
> - 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.

>
> I hope it is OK.
> ouf...
> Christos

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

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
   adaptation::sum_trs / adaptation::tt

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

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.

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.

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+

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

Okay thats the logging done. phew!

Amos

-- 
Please be using
   Current Stable Squid 2.7.STABLE6 or 3.0.STABLE16
   Current Beta Squid 3.1.0.9