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

[Amos Jeffries]

On 21/07/2016 2:44 a.m., Eduard Bagdasaryan wrote:
>>   2016-07-20 7:36 GMT+03:00 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. :-)
> 
> Amos,
> just to clarify: any more touches from my side?

There are the bits where Alex and I agreed on a change. I think that was
all cosmetic documentation stuff.

Also, if you agree - I'd prefer the getter method for receivedFirstByte_
was used instead of the member itself. Just so we can more easily move
the bits around as Server is cleaned up.

If you have time to re-check the thread since last patch submission and
make a new final one it would help making sure everything matched your
name as author and your design. Otherwise I can do it when committing
tomorrow.

Amos