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

[Amos Jeffries]

On 16/07/2016 2:40 a.m., Eduard Bagdasaryan wrote:
> Hello,
> 
> There are situations when Squid logs nothing to access.log after an
> [abnormal] transaction termination. Such "stealthy" transactions may be
> a security risk and an accounting problem.
> 
> ClientHttpRequest is responsible for logging most transactions but that
> object is created only after the HTTP request headers are successfully
> parsed. Request header parsing errors may be detected and logged
> appropriately, but the job handling the incoming transaction may
> terminate for reasons outside the parsing code control (e.g., a job-
> killing exception thrown when there are no request headers to start
> parsing yet or when the job waits for more request headers to finishing
> parsing).
> 
> This change adds access logging for two cases:
> 
> 1. accept(2) system call errors (before ConnStateData job is created);
> 
> 2. unexpected ConnStateData job termination, when there is no
>    ClientHttpRequest to log the failure.
> 
> TODO: Squid still logs nothing when the connection closes before reading
> request header data. We should probably make that behavior configurable
> because such connections drain Squid resources (and, hence, should be
> logged) but some browsers are known to routinely create them (and,
> hence, logging them by default may create too much noise).

IMO these should be logged by default (with option to ignore). We have
often enough queries about what all the open but never-used connections
listed by netstat are about.


Now the audit:

** A release notes mention about these changes is needed. Nothing major,
just an entry for access_log under 'changes to existing squid.conf
options', and line for each affected transaction type saying what its
logged as.

 + Something like:

    <tag>access_log</tag>
    <p>TCP accept(2) errors logged in access.log with URI <em>error:...</em>
    <p>Unused connections received in <em>http_port</em> or
<em>https_port</em> logged with URI <em>error:...</em>

 - can these URI be logged with url_regex ACLs on access_log lines?
   If so, theres the answer to people wanting to hide any frequently
occuring ones. ie the TODO is already implememented in a good way.


in src/client_side.cc:

* thanks for identifying the ConnStateData::clientParseRequests()
redundant code. I have applied that to trunk separately as rev.14747.,
it seems out of scope for this patch.


* ConnStateData::checkLogging()

 - why is pipeline.back() being checked instead of pipeline.front() ?
  [not saying its wrong yet, just asking for a good reason.]

 - the if (inBuf.isEmpty()) check is not right for "connections that
sent us no bytes". Squid can reach that test on an idle connection
between HTTP requests (quite common situation). That case also proves
the XXX assumption is wrong.

I think the condition needs to be changed to:
  if (receivedFirstByte() && inBuf.isEmpty())
      return;

  + the case of !receivedFirstByte() is the "connections that sent us no
bytes". Which will now fall through to do the logging.

  + which still leaves not-logging at least the cases where TLS bytes or
such layered things have occured but no HTTP bytes yet (and the inBuf
empty right now). That needs an explicit mention, and deserves an XXX or
TODO (different than the "assumes ..." one.)



in src/comm/TcpAcceptor.cc:

* logAcceptError needs to use Squid coding style of the return-type on
line above the function name. Same as the other surrounding functions
and methods.

* logAcceptError() should use a distinct "error:" URI labeling this as a
TCP accept error, since it has nothing to do with HTTP state.


Thank you
Amos