Re: [squid-users] mysterious TCP_DENIED messages in log

From: <equinox_at_atw.hu>
Date: Thu, 28 Feb 2013 17:15:19 +0100

On 2/28/2013 1:19 AM, Amos Jeffries wrote:
> On 28/02/2013 7:53 a.m., equinox_at_atw.hu wrote:
>>
>> Hi,
>>
>>
>> Look at this log snippet.
>>
>> Can you see that TCP_DENIED/403 is immediately followed by TCP_REDIRECT?
>>
>> Is that not illogical?
>
> No. You cannot tell from this log what relationship any two log lines
> may have.
>
> * HTTP is stateless
> * the log indicates only the order HTTP transactions were completed.
> * you are cropping the query-string off URLs, any two
> seeming-identical log lines MAY be for extremely different resources
>
>
>>
>> Can you explain it? Why are there TCP_DENIED messages?
>>
>
> Your config DENIED the transaction. Without details of your config and
> the full URLs it is impossible to say more.
>
>
> Amos
>
The urls are the same.
I retested it. It was a test. There is not much traffic.

Marton

#
# Recommended minimum configuration:
#

# ziproxy stuff...
# "Hooks" Squid to Ziproxy LINK running in 'localhost', port '8081'.
# Note: Ziproxy does not support ICP nor cache querying
# since it is not a caching proxy.
# cache_peer 31.222.160.30 parent 8081 0 no-query no-digest
#debug_options ALL,9
debug_options ALL,1 33,2 28,9 82,9

#url_rewrite_program /usr/local/squid/lib/status.pl

visible_hostname gb01ds

cache deny all

#acl manager proto cache_object
#acl localhost src 127.0.0.1/32 ::1
#acl to_localhost dst 127.0.0.0/8 0.0.0.0/32 ::1

#external_acl_type myAclType ttl=10 %SRC %MYPORT %>{User-Agent} %{Host}
/usr/local/squid/lib/authuser.pl
external_acl_type myAclType ttl=1 %SRC %MYPORT %>{User-Agent} %{Host}
%URI /usr/local/squid/lib/authuser2.pl

acl MyAcl external myAclType
acl comp1 tag comp1
acl comp2 tag comp2
acl comp3 tag comp3
acl comp4 tag comp4
acl comp5 tag comp5
acl comp6 tag comp6
acl comp7 tag comp7
acl comp8 tag comp8
acl comp9 tag comp9
acl comp10 tag comp10
acl comp11 tag comp11
acl comp12 tag comp12
acl comp13 tag comp13
acl comp14 tag comp14
acl comp15 tag comp15
acl comp16 tag comp16
acl comp17 tag comp17
acl comp18 tag comp18
acl comp19 tag comp19
acl comp20 tag comp20
acl comp21 tag comp21
acl comp22 tag comp22
acl comp23 tag comp23
acl comp24 tag comp24

acl status tag status

#acl standardComp tag standard myAclType
http_access allow comp1
http_access allow comp2
http_access allow comp3
http_access allow comp4
http_access allow comp5
http_access allow comp6
http_access allow comp7
http_access allow comp8
http_access allow comp9
http_access allow comp10
http_access allow comp11
http_access allow comp12
http_access allow comp13
http_access allow comp14
http_access allow comp15
http_access allow comp16
http_access allow comp17
http_access allow comp18
http_access allow comp19
http_access allow comp20
http_access allow comp21
http_access allow comp22
http_access allow comp23
http_access allow comp24

http_access allow status

http_access allow MyAcl

http_access allow all

cache_peer 127.0.0.1 parent 3000 0 no-query no-digest login=PASS
name=compServer1
cache_peer 127.0.0.1 parent 3001 0 no-query no-digest login=PASS
name=compServer2
cache_peer 127.0.0.1 parent 3002 0 no-query no-digest login=PASS
name=compServer3
cache_peer 127.0.0.1 parent 3003 0 no-query no-digest login=PASS
name=compServer4
cache_peer 127.0.0.1 parent 3004 0 no-query no-digest login=PASS
name=compServer5
cache_peer 127.0.0.1 parent 3005 0 no-query no-digest login=PASS
name=compServer6
cache_peer 127.0.0.1 parent 3006 0 no-query no-digest login=PASS
name=compServer7
cache_peer 127.0.0.1 parent 3007 0 no-query no-digest login=PASS
name=compServer8
cache_peer 127.0.0.1 parent 3008 0 no-query no-digest login=PASS
name=compServer9
cache_peer 127.0.0.1 parent 3009 0 no-query no-digest login=PASS
name=compServer10
cache_peer 127.0.0.1 parent 3010 0 no-query no-digest login=PASS
name=compServer11
cache_peer 127.0.0.1 parent 3011 0 no-query no-digest login=PASS
name=compServer12
cache_peer 127.0.0.1 parent 3012 0 no-query no-digest login=PASS
name=compServer13
cache_peer 127.0.0.1 parent 3013 0 no-query no-digest login=PASS
name=compServer14
cache_peer 127.0.0.1 parent 3014 0 no-query no-digest login=PASS
name=compServer15
cache_peer 127.0.0.1 parent 3015 0 no-query no-digest login=PASS
name=compServer16
cache_peer 127.0.0.1 parent 3016 0 no-query no-digest login=PASS
name=compServer17
cache_peer 127.0.0.1 parent 3017 0 no-query no-digest login=PASS
name=compServer18
cache_peer 127.0.0.1 parent 3018 0 no-query no-digest login=PASS
name=compServer19
cache_peer 127.0.0.1 parent 3019 0 no-query no-digest login=PASS
name=compServer20
cache_peer 127.0.0.1 parent 3020 0 no-query no-digest login=PASS
name=compServer21
cache_peer 127.0.0.1 parent 3021 0 no-query no-digest login=PASS
name=compServer22
cache_peer 127.0.0.1 parent 3022 0 no-query no-digest login=PASS
name=compServer23
cache_peer 127.0.0.1 parent 3023 0 no-query no-digest login=PASS
name=compServer24

cache_peer_access compServer1 allow comp1
cache_peer_access compServer1 deny !comp1
cache_peer_access compServer2 allow comp2
cache_peer_access compServer2 deny !comp2
cache_peer_access compServer3 allow comp3
cache_peer_access compServer3 deny !comp3
cache_peer_access compServer4 allow comp4
cache_peer_access compServer4 deny !comp4
cache_peer_access compServer5 allow comp5
cache_peer_access compServer5 deny !comp5
cache_peer_access compServer6 allow comp6
cache_peer_access compServer6 deny !comp6
cache_peer_access compServer7 allow comp7
cache_peer_access compServer7 deny !comp7
cache_peer_access compServer8 allow comp8
cache_peer_access compServer8 allow status

cache_peer_access compServer8 deny !comp8

cache_peer_access compServer9 allow comp9
cache_peer_access compServer9 deny !comp9
cache_peer_access compServer10 allow comp10
cache_peer_access compServer10 deny !comp10
cache_peer_access compServer11 allow comp11
cache_peer_access compServer11 deny !comp11
cache_peer_access compServer12 allow comp12
cache_peer_access compServer12 deny !comp12
cache_peer_access compServer13 allow comp13
cache_peer_access compServer13 deny !comp13
cache_peer_access compServer14 allow comp14
cache_peer_access compServer14 deny !comp14
cache_peer_access compServer15 allow comp15
cache_peer_access compServer15 deny !comp15
cache_peer_access compServer16 allow comp16
cache_peer_access compServer16 deny !comp16
cache_peer_access compServer17 allow comp17
cache_peer_access compServer17 deny !comp17
cache_peer_access compServer18 allow comp18
cache_peer_access compServer18 deny !comp18
cache_peer_access compServer19 allow comp19
cache_peer_access compServer19 deny !comp19
cache_peer_access compServer20 allow comp20
cache_peer_access compServer20 deny !comp20
cache_peer_access compServer21 allow comp21
cache_peer_access compServer21 deny !comp21
cache_peer_access compServer22 allow comp22
cache_peer_access compServer22 deny !comp22
cache_peer_access compServer23 allow comp23
cache_peer_access compServer23 deny !comp23
cache_peer_access compServer24 allow comp24
cache_peer_access compServer24 deny !comp24

#url_rewrite_access allow status
#url_rewrite_access all
#url_rewrite_access deny all

#cache_peer_access vlowServer allow v
#cache_peer_access vlowServer deny all

#acl ncsa_users proxy_auth REQUIRED
#http_access allow ncsa_users
#acl ncsa max_user_ip 999

# Example rule allowing access from your local networks.
# Adapt to list your (internal) IP networks from where browsing
# should be allowed
acl localnet src 127.0.0.0/8 # RFC1918 possible internal network
#acl localnet src 172.16.0.0/12 # RFC1918 possible internal network
#acl localnet src 192.168.0.0/16 # RFC1918 possible internal network
#acl localnet src fc00::/7 # RFC 4193 local private network range
#acl localnet src fe80::/10 # RFC 4291 link-local (directly
plugged) machines

acl SSL_ports port 443 563
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 # https
acl Safe_ports port 70 # gopher
acl Safe_ports port 210 # wais
acl Safe_ports port 1025-65535 # unregistered ports
acl Safe_ports port 280 # http-mgmt
acl Safe_ports port 488 # gss-http
acl Safe_ports port 591 # filemaker
acl Safe_ports port 777 # multiling http

acl CONNECT method CONNECT

#
# Recommended minimum Access Permission configuration:
#
# Only allow cachemgr access from localhost
#http_access allow manager localhost
#http_access deny manager

# Deny requests to certain unsafe ports
http_access deny !Safe_ports

# Deny CONNECT to other than secure SSL ports
http_access deny CONNECT !SSL_ports

# We strongly recommend the following be uncommented to protect innocent
# web applications running on the proxy server who think the only
# one who can access services on "localhost" is a local user
#http_access deny to_localhost

#
# INSERT YOUR OWN RULE(S) HERE TO ALLOW ACCESS FROM YOUR CLIENTS
#

# Example rule allowing access from your local networks.
# Adapt localnet in the ACL section to list your (internal) IP networks
# from where browsing should be allowed
#http_access allow localnet
#http_access allow localhost

# And finally deny all other access to this proxy
http_access deny all

# We recommend you to use at least the following line.
hierarchy_stoplist cgi-bin ?

# Uncomment and adjust the following to add a disk cache directory.
#cache_dir ufs /usr/local/squid/var/cache 100 16 256

# Leave coredumps in the first cache dir
#coredump_dir /usr/local/squid/var/cache

# Add any of your own refresh_pattern entries above these.
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern -i (/cgi-bin/|\?) 0 0% 0
refresh_pattern . 0 20% 4320

# extras...

logformat Squid %{%Y-%m-%dT%H:%M:%S}tg.%03tu %ts.%03tu %6tr %>A
%Ss/%03Hs %<st %rm %ru %rp %un %Sh %et
#access_log /var/log/squid/access.log Squid
#cache_log /var/log/squid/cache.log Squid

# Prevents Squid trying to access directly the remote HTTP host
# if Squid is unable to connect to Ziproxy,
# otherwise you won't know whether Ziproxy is down/has_problems
# (the lack of gzip support is not obvious to the user).
#never_direct allow all
always_direct allow all

#ecap_enable on
#ecap_service gzip_service respmod_precache 0 ecap://www.vigos.com/ecap_gzip
#loadable_modules /usr/local/lib/ecap_adapter_gzip.so
#acl GZIP_HTTP_STATUS http_status 200
#adaptation_access gzip_service allow GZIP_HTTP_STATUS
#acl okStatus http_status 302
#http_reply_access allow okStatus

#url_rewrite_program /usr/local/bin/squidclamav
#url_rewrite_program /usr/local/squid/lib/youtube.pl
url_rewrite_program /root/videocomp/videorewriter.pl

# Squid normally listens to port 3128
#include /usr/local/squid/etc/squid_ports.conf
include /usr/local/squid/etc/squid_ports_1.conf
pid_filename /usr/local/squid/var/run/squid_1.pid
access_log /var/log/squid/access_1.log Squid
cache_log /var/log/squid/cache_1.log Squid

An example of denial:
013/02/28 12:10:04.232 kid1| external_acl.cc(1389) ExternalAclLookup:
externalAclLookup: lookup in 'myAclType' for '95.215.120.184 3257
AppleCoreMedia/1.0.0.10B146%20(iPhone;%20U;%20CPU%20OS%206_1_2%20like%20Mac%20OS%20X;%20en_us)
5.79.$
2013/02/28 12:10:04.232 kid1| external_acl.cc(1459) ExternalAclLookup:
externalAclLookup: looking up for '95.215.120.184 3257
AppleCoreMedia/1.0.0.10B146%20(iPhone;%20U;%20CPU%20OS%206_1_2%20like%20Mac%20OS%20X;%20en_us)
5.79.6.204 http:$
2013/02/28 12:10:04.233 kid1| external_acl.cc(1471) ExternalAclLookup:
externalAclLookup: no need to wait for the result of '95.215.120.184
3257
AppleCoreMedia/1.0.0.10B146%20(iPhone;%20U;%20CPU%20OS%206_1_2%20like%20Mac%20OS%20X;%20en_u$
2013/02/28 12:10:04.233 kid1| external_acl.cc(1472) ExternalAclLookup:
externalAclLookup: using cached entry 0x2a12cd8
2013/02/28 12:10:04.233 kid1| external_acl.cc(1479) ExternalAclLookup:
externalAclLookup: entry = { date=1362053403, result=1 tag=comp3 log= }
2013/02/28 12:10:04.233 kid1| external_acl.cc(1481) ExternalAclLookup:
externalAclLookup: user=3257|0|3|8
2013/02/28 12:10:04.233 kid1| Checklist.cc(141) asyncInProgress:
ACLChecklist::asyncInProgress: 0x27da918 async set to 0
2013/02/28 12:10:04.233 kid1| Checklist.cc(229) matchAclList:
aclmatchAclList: async=1 nodeMatched=0 async_in_progress=0
lastACLResult() = 0 finished() = 0
2013/02/28 12:10:04.233 kid1| Checklist.cc(243) matchAclList:
aclmatchAclList: 0x27da918 returning (AND list entry awaiting an async
lookup)
2013/02/28 12:10:04.233 kid1| Checklist.cc(162) preCheck:
ACLChecklist::preCheck: 0x27da918 checking 'http_access deny !Safe_ports'
2013/02/28 12:10:04.233 kid1| Acl.cc(321) matches: ACLList::matches:
checking !Safe_ports
2013/02/28 12:10:04.233 kid1| Acl.cc(310) checklistMatches:
ACL::checklistMatches: checking 'Safe_ports'
2013/02/28 12:10:04.233 kid1| Acl.cc(312) checklistMatches:
ACL::ChecklistMatches: result for 'Safe_ports' is 1
2013/02/28 12:10:04.233 kid1| Acl.cc(324) matches: ACLList::matches:
result is false
2013/02/28 12:10:04.233 kid1| Checklist.cc(229) matchAclList:
aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0
lastACLResult() = 0 finished() = 0
2013/02/28 12:10:04.233 kid1| Checklist.cc(243) matchAclList:
aclmatchAclList: 0x27da918 returning (AND list entry awaiting an async
lookup)
2013/02/28 12:10:04.233 kid1| Checklist.cc(162) preCheck:
ACLChecklist::preCheck: 0x27da918 checking 'http_access deny CONNECT
!SSL_ports'
2013/02/28 12:10:04.233 kid1| Acl.cc(321) matches: ACLList::matches:
checking CONNECT
2013/02/28 12:10:04.233 kid1| Acl.cc(310) checklistMatches:
ACL::checklistMatches: checking 'CONNECT'
2013/02/28 12:10:04.233 kid1| Acl.cc(312) checklistMatches:
ACL::ChecklistMatches: result for 'CONNECT' is 0
2013/02/28 12:10:04.233 kid1| Acl.cc(324) matches: ACLList::matches:
result is false
2013/02/28 12:10:04.233 kid1| Checklist.cc(229) matchAclList:
aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0
lastACLResult() = 0 finished() = 0
2013/02/28 12:10:04.233 kid1| Checklist.cc(243) matchAclList:
aclmatchAclList: 0x27da918 returning (AND list entry awaiting an async
lookup)
2013/02/28 12:10:04.233 kid1| Checklist.cc(162) preCheck:
ACLChecklist::preCheck: 0x27da918 checking 'http_access deny all'
2013/02/28 12:10:04.233 kid1| Acl.cc(321) matches: ACLList::matches:
checking all
2013/02/28 12:10:04.233 kid1| Acl.cc(310) checklistMatches:
ACL::checklistMatches: checking 'all'
2013/02/28 12:10:04.233 kid1| Ip.cc(135) aclIpAddrNetworkCompare:
aclIpAddrNetworkCompare: compare: 95.215.120.184:1661/[::] ([::]:1661)
vs [::]-[::]/[::]
2013/02/28 12:10:04.233 kid1| Ip.cc(571) match: aclIpMatchIp:
'95.215.120.184:1661' found
2013/02/28 12:10:04.233 kid1| Acl.cc(312) checklistMatches:
ACL::ChecklistMatches: result for 'all' is 1
2013/02/28 12:10:04.233 kid1| Acl.cc(328) matches: ACLList::matches:
result is true
2013/02/28 12:10:04.233 kid1| Checklist.cc(251) matchAclList:
aclmatchAclList: 0x27da918 returning true (AND list satisfied)
2013/02/28 12:10:04.233 kid1| Checklist.cc(156) markFinished:
ACLChecklist::markFinished: 0x27da918 checklist processing finished
2013/02/28 12:10:04.233 kid1| Checklist.cc(103) matchNonBlocking:
ACLChecklist::check: 0x27da918 match found, calling back with 0
2013/02/28 12:10:04.233 kid1| FilledChecklist.cc(18) checkCallback:
0x27da918 answer=0
2013/02/28 12:10:04.233 kid1| Checklist.cc(188) checkCallback:
ACLChecklist::checkCallback: 0x27da918 answer=0
2013/02/28 12:10:04.233 kid1| Gadgets.cc(84) aclIsProxyAuth:
aclIsProxyAuth: called for all
2013/02/28 12:10:04.233 kid1| Acl.cc(61) FindByName: ACL::FindByName 'all'
2013/02/28 12:10:04.233 kid1| Gadgets.cc(92) aclIsProxyAuth:
aclIsProxyAuth: returning 0
2013/02/28 12:10:04.233 kid1| Gadgets.cc(57) aclGetDenyInfoPage: got
called for all
2013/02/28 12:10:04.233 kid1| Gadgets.cc(76) aclGetDenyInfoPage:
aclGetDenyInfoPage: no match
Received on Thu Feb 28 2013 - 16:15:40 MST

This archive was generated by hypermail 2.2.0 : Thu Feb 28 2013 - 12:00:04 MST