[squid-users] Debugging http_access and http_reply_access

[Amos Jeffries]

On 3/02/2016 7:19 p.m., squid-users at filter.luko.org wrote:
> Hi Squid users,
> 
> I'm seeking some guidance regarding the best way to debug the http_access
> and http_reply_access configuration statements on a moderately busy Squid
> 3.5 cache.  In cases where a number (say, 5 or more) of http_access lines
> are present, the goal is to find which configuration statement (if any) was
> found to match for a given request, then write this information to a log for
> further processing.  Example:
> 
> http_access deny !Safe_ports
> http_access deny CONNECT !SSL_ports
> http_access allow localhost manager
> http_access deny manager
> http_access allow localhost
> http_access deny out_working_hours
> http_access allow working_hours whitelist
> http_access allow network
> http_access deny all
> 
> Let's assume each of those lines have an index (0, 1, 2 thru 8 in the
> example above).  Is there any way to find which one matched?

Well, don't assume. They are logged in cache.log as http_access#1 to
http_access#9 as seen below (with a bit more optimal config than yours):

"
2016/02/03 22:54:24.461 kid1| 28,3| ../src/acl/Checklist.cc(70)
preCheck: 0xa77d3a8 checking slow rules
2016/02/03 22:54:24.461 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: Safe_ports = 1
2016/02/03 22:54:24.461 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: !Safe_ports = 0
2016/02/03 22:54:24.461 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: http_access#1 = 0
2016/02/03 22:54:24.462 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: CONNECT = 0
2016/02/03 22:54:24.462 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: http_access#2 = 0
2016/02/03 22:54:24.462 kid1| 28,3| ../src/acl/Ip.cc(540) match:
aclIpMatchIp: '[::1]:43636' found
2016/02/03 22:54:24.463 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: localhost = 1
2016/02/03 22:54:24.463 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: http_access#3 = 1
2016/02/03 22:54:24.463 kid1| 28,3| ../src/acl/Acl.cc(290) matches:
checked: http_access = 1
2016/02/03 22:54:24.463 kid1| 28,3| ../src/acl/Checklist.cc(63)
markFinished: 0xa77d3a8 answer ALLOWED for match
2016/02/03 22:54:24.463 kid1| 28,3| ../src/acl/Checklist.cc(163)
checkCallback: ACLChecklist::checkCallback: 0xa77d3a8 answer=ALLOWED
"

> 
> Explored so far: using debug_options to look at sections 33 (Client Side
> Routines), 88 (Client-side Reply Routines) and 85 (Client Side Request
> Routines) return useful information, but it's hard to use it to identify
> (programmatically) which log entries relate to which request on a busy
> cache.  Activating debug logging on a busy cache also doesn't seem like the
> right approach.

debug_options 11,2 28,3


11,2 gives you the HTTP messages.
28,3 gives you the ACL processing action and results.

Its a bit like quantum mechanics at the moment though. You can know the
request mesage details. OR you can know the ACL matching. Not both at once.

> 
> Are there any other debug sections which would be more appropriate to the
> task?  If not, is there another more suitable approach?
> 

Why exactly are you doing this? What are you trying to achieve with it?

Amos