[squid-users] logformat odd values

[Moti Berger]

Hi

It's possible that in some cases they will run concurrently, however not in
my setup. The ICAPs are chained. If the chain doesn't guarantee it please
let me know since I rely on it.

Regarding what you said about things that can happen in parallel, I'm OK
with it since what I care the most is the extra time my ICAPs add to the
user latency and this is what I would like to measure.

Thanks

On Wed, Sep 15, 2021, 20:47 Alex Rousskov <rousskov at measurement-factory.com>
wrote:

> On 9/14/21 3:04 PM, Moti Berger wrote:
>
> > I have the followings in squid.conf:
> >
> >     logformat metrics %icap::tt %adapt::all_trs %adapt::sum_trs
> >     %{service_req_a}adapt::sum_trs %{service_resp_a}adapt::sum_trs
> >     %{service_req_b}adapt::sum_trs %{service_resp_b}adapt::sum_trs
> >     access_log daemon:/var/log/squid/metrics.log metrics
> >
> >
> >
> >     icap_service service_req_a reqmod_precache bypass=1 on-overload=wait
> >     routing=1 icap://a.y:12345/request
> >     icap_service service_req_b reqmod_precache bypass=1 on-overload=wait
> >     icap://b.y:10101/request
> >     adaptation_service_chain svcRequest service_req_a service_req_b
> >     adaptation_access svcRequest deny manager
> >     adaptation_access svcRequest allow all
> >     icap_service service_resp_a respmod_precache bypass=1
> >     on-overload=wait routing=1 icap://a.y:12345/response
> >     icap_service service_resp_b respmod_precache bypass=1
> >     on-overload=wait icap://b.y:10101/response
> >     adaptation_service_chain svcResponse service_resp_a service_resp_b
> >     adaptation_access svcResponse deny manager
> >     adaptation_access svcResponse allow all
> >
> >
> >  I see in metrics.log lines like this:
> >
> >     4 4,180 4,180 4 180 - -
> >
> >
> > Now I wonder how come the value of %icap:tt isn't at least as the sum of
> > all the numbers appear on %adapt::all_trs or %adapt::sum_trs (assuming
> > no failed transactions)?
>
> There is probably a bug somewhere, but please note that %icap:tt may not
> be the sum of individual transaction response times (in _some_ cases)
> even after that bug is fixed because those individual transactions may
> run _concurrently_ (i.e. partially overlap in time).
>
>
> > If %icap:tt isn't at least the sum of all ICAPs processing time, what is?
>
> Bugs notwithstanding, it is approximate time a master transaction spent
> doing adaptation (including checking whether adaptation is necessary).
> This stopwatch ticks when adaptation_access ACLs are checked and also
> when at least one adaptation transaction associated with that master
> transaction is in progress.
>
> Please note that a master transaction can do a lot of different things
> at once or in parallel. For example, it can communicate with an HTTP
> client while communicating with an FTP server while communicating with
> an eCAP REQMOD adaptation service while communicating with a DNS server
> to decide whether to start communicating with an ICAP RESPMOD service.
>
>
> HTH,
>
> Alex.
> _______________________________________________
> squid-users mailing list
> squid-users at lists.squid-cache.org
> http://lists.squid-cache.org/listinfo/squid-users
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20210917/ec91367e/attachment.htm>