On 30/07/2014 5:18 a.m., pe...@pshankland.co.uk wrote:
Hi, I have configured a new install of Squid on CentOS 6.5 via yum. I
have followed some of the guides on the Squid wiki to get AD group
authentication working but am getting some strange results when looking
within the access.log.
As you can see from the following log entries, the server, with an
authentication user logged in and browsing to www.google.com, gets a
couple of TCP_MISS/200 entries and then TCP_DENIED/407 before going back
to TCP_MISS/200 again:
1406653633.180220 172.29.94.15 TCP_MISS/200 3863 CONNECT
ssl.gstatic.com:443 admin_pete DIRECT/74.125.230.119 -
1406653633.180 78 172.29.94.15 TCP_MISS/200 3524 CONNECT
www.google.com:443 admin_pete DIRECT/173.194.41.116 -
1406653633.182 0 172.29.94.15 TCP_DENIED/407 3951 CONNECT
www.google.com:443 - NONE/- text/html
1406653633.185 0 172.29.94.15 TCP_DENIED/407 4280 CONNECT
www.google.com:443 - NONE/- text/html
1406653633.194 0 172.29.94.15 TCP_DENIED/407 3955 CONNECT
ssl.gstatic.com:443 - NONE/- text/html
1406653633.196 0 172.29.94.15 TCP_DENIED/407 4284 CONNECT
ssl.gstatic.com:443 - NONE/- text/html
1406653633.247 72 172.29.94.15 TCP_MISS/200 3862 CONNECT
www.gstatic.com:443 admin_pete DIRECT/74.125.230.127 -
1406653633.249 0 172.29.94.15 TCP_DENIED/407 3955 CONNECT
www.gstatic.com:443 - NONE/- text/html
1406653633.252 0 172.29.94.15 TCP_DENIED/407 4284 CONNECT
www.gstatic.com:443 - NONE/- text/html
1406653633.394 0 172.29.94.15 TCP_DENIED/407 3955 CONNECT
apis.google.com:443 - NONE/- text/html
It is a bit confusing as the web page loads but I get all these denied
logs within access.log.
Could someone help me understand what this means?
Since you mention AD group authentication I asume you have used NTLM
or Negotiate authentication.
Two things to be aware of when reading these logs:
1) the entries are logged at time of transaction completion. So the
admin_pete CONNECT requests that got a MISS/200 actually started far
earlier than the denied ones. eg the one 1406653633 (logged) - 72ms
(duration) == started 1406653561.
... that helps you read the log for identifying #2 ...
2) Authentication requires multiple HTTP transactions to perform an
authentication handshake. Both NTLM and Negotiate have mandatory fresh
handshakes on every new connection. NTLM always has an extra transaction
in the middle of the handshake.
So you get a denied first then a success. This shows up worst of all
with HTTPS like above where every tunnnel attempt requires a new connection.
3) browsers also have a tendency to open multiple connections at a time.
Sometimes this can be attributed to happy eyeballs sometimes they are
just grabbing more for future performance. That (or NTLM) is probably
the case for these attempts which are only 3ms apart.
Amos
