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

[Amos Jeffries]

On 20/07/2016 5:01 a.m., Alex Rousskov wrote:
> 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?
> 

Hmm. Good point.

The 'problem' with ACLs was not the lack of checks, it is that the URL
ones we already have use exclusively the HttpRequest URL and complain
when one is not existing. It might be easier to extend those to use the
error:* URL, in the same way the log itself is getting it for display.

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

Agreed. User is a specific subset of client. That 'does it require a
person' is the first filter I am applying whenever anyone suggests
"user" for anything.


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

My inbox(es) contain no mention of these annotate_client / annotate_user
you speak of being discussed. And my memory is also drawing a bank right
now.

The latest proposed patch of this thread failed the filter mentioned
above for me. I'm asking for "error:accept-client-connection", which
would be (2) or (3) of your offered list.


> 
>> +    // 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;
> 

That works for me. +1.

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

Nod. I had exactly that same thought. :-)

PS. Eduard; Its out of scope though. In case you mistake that for a
request from both of use.

Amos