[squid-dev] [PATCH] Some failed transactions are not logged

[Alex Rousskov]

On 07/19/2016 08:10 AM, Amos Jeffries wrote:
> On 20/07/2016 1:44 a.m., Eduard Bagdasaryan wrote:
>> 2016-07-19 16:17 GMT+03:00 Amos Jeffries:
>>> Is this patch going to include the new config option to prevent logging
>>> the new things? or do it in a followup?
>>
>> For now we are not planning to add this option(that is why initially the
>> patch did not perform logging for "no-bytes" connections).
>> Probably there should be a (new?) ACL, controlling number of received
>> bytes(instead of separate option). If so, implementing this requires
>> solving non-trivial separate task.

> Okay. I was just thinking an on/off directive for now. So people could
> restore the old behaviour, or go ahead with the new logs. 

An ACL is the right way to control what gets logged -- this is the
access_log configuration interface we already support. If no existing
ACL(s) can match the transactions we want users to be able to match,
then we need to add more ACL(s). I suspect those new ACL(s) would be
useful for more than logging.

A new config directive is not something we can add "for now" -- it would
have to be maintained for a long time while the overlap between the
existing ACL-driven interface and the new directive will cause pains for
developers, documentation writers, and admins.


Which ACL(s) to add depends on the final version of the new logging
code, requires careful thinking, and may require non-trivial
development. We want to keep all of that outside this project scope.
Amos, if we assume that this patch does not add new ACLs or directives,
are you happy with what it logs now or do you want Eduard to exclude
something?


> I'll give Alex another day to point out any issues, with intention to
> apply this in ~24hrs.

Thank you.


> error:accept-user-connection

vs. recently discussed

> annotate_client or annotate_client_connection

All of these are about the same kind of connection to a Squid
protocol_port. Should we use "user" or "client"? I do not think just
"annotate_user" works because folks will think it is about the
[authenticated] user [agent] as a whole. Thus, we have the following
naming options:

1) error:accept-user-connection and annotate_user_connection

2) error:accept-client-connection and annotate_client

3) error:accept-client-connection and annotate_client_connection


FYI: I found a few references to "user" and ~30 references to "client"
in squid.conf directives and ACLS:

* user_max_ip, user_cert, ext_user, ftp_user, and cache_effective_user;

* client_dst_passthru, client_delay_*, *_uses_indirect_client,
client_db, client_idle_pconn_timeout, client_ip_max_connections,
client_lifetime, client_netmask, client_persistent_connections, and
client_request_buffer_max_size.

Given the above, (2) or (3) seems like a better choice. Amos, please
pick one or confirm that you still want (1).


> +    // do not log connections that closed after a transaction (it is normal)
...
> +    // XXX: TLS bytes are consumed without going through inBuf
> +    // XXX: PROXY protocol bytes are consumed without going through inBuf
> +    if (receivedFirstByte_ && inBuf.isEmpty())
> +        return;

Given the new condition, I would do:

> // do not log connections that closed after a transaction (it is normal)
> // TODO: access_log needs ACLs to match received-no-bytes connections
> // XXX: TLS may return here even though we got no transactions yet
> // XXX: PROXY protocol may return here even though we got no transactions yet
> if (receivedFirstByte_ && inBuf.isEmpty())
>     return;


I have not checked PROXY, but TLS is tricky because, AFAICT, it sets
receivedFirstByte_ to true but may later _reset_ it back to false:

> // Also reset receivedFirstByte_ flag to allow this timeout work in the case we 
> // a bumbed "connect" request on non transparent port.
> receivedFirstByte_ = false;

I would keep those XXXs vague until somebody investigates and addresses
them completely. I suspect we will need to split receivedFirstByte_ into
receivedFirstTransactionByte_ and receivedFirstRawByte_ or perhaps byte
counters for each (and ACLs that can match their ranges).


Thank you,

Alex.