Re: [squid-users] How to debug external_acl_type

Hello,

Am 27.08.09 00:49, "Amos Jeffries" <squid3_at_treenet.co.nz> schrieb:

> Whey it never enters the loop? It works if I start it from command line

>> I think Squid is noticing the %LOGIN requirements are missing and aborting
>> with a 'needs auth credentials' before calling into the helpers.

I have now removed $LOGIN, and I get at least a answer from the perl script.

helperHandleRead: 'ERR' or helperHandleRead: 'OK' whatever I have in the
perl script.

But no Access to any website. And I don't see any ALLOWED or DENIED in the
log, but some timeouts and warnings:
2009/08/26 20:06:06| WARNING: Closing client 192.168.32.1 connection due to
lifetime timeout

Log samples:
-----8<-----
2009/08/26 20:04:47| httpAccept: FD 18: accepted port 3128 client
192.168.32.1:53584
2009/08/26 20:04:47| cbdataLock: 0x871ddd0
2009/08/26 20:04:47| comm_add_close_handler: FD 18, handler=0x806dd30,
data=0x88bb410
2009/08/26 20:04:47| cbdataLock: 0x88bb410
2009/08/26 20:04:47| commSetTimeout: FD 18 timeout 300
2009/08/26 20:04:47| aclCheckFast: list: 0x871d7f0
2009/08/26 20:04:47| aclMatchAclList: checking all
2009/08/26 20:04:47| aclMatchAcl: checking 'acl all src all'
2009/08/26 20:04:47| aclMatchIp: '192.168.32.1' found
2009/08/26 20:04:47| aclMatchAclList: returning 1
2009/08/26 20:04:47| commSetSelect: FD 18 type 1
2009/08/26 20:04:47| commSetEvents(fd=18)
2009/08/26 20:04:47| comm_accept: FD 19: (11) Resource temporarily
unavailable

...

2009/08/26 20:04:48| aclCheck: checking 'http_access deny !MyAcl'
2009/08/26 20:04:48| aclMatchAclList: checking !MyAcl
2009/08/26 20:04:48| aclMatchAcl: checking 'acl MyAcl external myAclType'
2009/08/26 20:04:48| aclMatchExternal: acl="myAclType"
2009/08/26 20:04:48| aclMatchExternal: myAclType("192.168.32.1") = lookup
needed
2009/08/26 20:04:48| aclMatchAclList: no match, returning 0
2009/08/26 20:04:48| externalAclLookup: lookup in 'myAclType' for
'192.168.32.1'
2009/08/26 20:04:48| cbdataLock: 0x871db00
2009/08/26 20:04:48| cbdataLock: 0x88bbd50
2009/08/26 20:04:48| cbdataLock: 0x88bbea8
2009/08/26 20:04:48| cbdataValid: 0x88bbea8
2009/08/26 20:04:48| comm_write: FD 12: sz 13: hndl 0x808e530: data
0x8739d28.
2009/08/26 20:04:48| cbdataLock: 0x8739d28
2009/08/26 20:04:48| commSetSelect: FD 12 type 2
2009/08/26 20:04:48| commSetEvents(fd=12)
2009/08/26 20:04:48| helperDispatch: Request sent to myAclType #1[0], 13
bytes
2009/08/26 20:04:48| helperSubmit: 192.168.32.1
2009/08/26 20:04:48| cbdataValid: 0x88bb410
2009/08/26 20:04:48| cbdataValid: 0x88bb410
2009/08/26 20:04:48| cbdataValid: 0x88bb410
2009/08/26 20:04:48| cbdataUnlock: 0x88bb410
2009/08/26 20:04:48| commSetSelect: FD 18 type 1
2009/08/26 20:04:48| commSetEvents(fd=18)
2009/08/26 20:04:48| comm_select: timeout 99
2009/08/26 20:04:48| comm_call_handlers(): got fd=12 read_event=0
write_event=4 F->read_handler=0x808f5a0 F->write_handler=0x8072fb0
2009/08/26 20:04:48| commHandleWrite: FD 12: off 0, hd 0, sz 13.
2009/08/26 20:04:48| commHandleWrite: write() returns 13
2009/08/26 20:04:48| cbdataValid: 0x8739d28
2009/08/26 20:04:48| cbdataUnlock: 0x8739d28
2009/08/26 20:04:48| commSetEvents(fd=12)
2009/08/26 20:04:48| comm_select: timeout 99
2009/08/26 20:04:48| comm_call_handlers(): got fd=12 read_event=1
write_event=0 F->read_handler=0x808f5a0 F->write_handler=(nil)
2009/08/26 20:04:48| comm_call_handlers(): Calling read handler on fd=12
2009/08/26 20:04:48| cbdataValid: 0x8739d28
2009/08/26 20:04:48| helperHandleRead: 3 bytes from myAclType #1.
2009/08/26 20:04:48| commSetSelect: FD 12 type 1
2009/08/26 20:04:48| commSetEvents(fd=12)
2009/08/26 20:04:48| helperHandleRead: 'ERR'
2009/08/26 20:04:48| comm_select: timeout 99
2009/08/26 20:04:48| comm_select: time out
2009/08/26 20:04:48| comm_select: timeout 1
2009/08/26 20:04:48| comm_select: time out
2009/08/26 20:04:48| eventRun: RUN ID 25
2009/08/26 20:04:48| eventRun: Running 'ipcache_purgelru', id 0
2009/08/26 20:04:48| eventAdd: Adding 'ipcache_purgelru', in 10.000000
seconds
2009/08/26 20:04:48| ipcache_purgelru: removed 0 entries
2009/08/26 20:04:48| comm_select: timeout 13
2009/08/26 20:04:48| comm_select: time out
2009/08/26 20:04:48| eventRun: RUN ID 26
2009/08/26 20:04:48| eventRun: Running 'MaintainSwapSpace', id 24
2009/08/26 20:04:48| storeMaintainSwapSpace: f=0.000000, max_scan=100,
max_remove=10
2009/08/26 20:04:48| cbdataFree: 0x88bb398
2009/08/26 20:04:48| cbdataFree: Freeing 0x88bb398
2009/08/26 20:04:48| storeUfsDirMaintain: /var/spool/squid removed 0/10
f=0.000 max_scan=100
----->8-----

squid.conf:
-----8<-----
acl all src all
auth_param basic program /usr/local/bin/my-auth.pl
external_acl_type myAclType ttl=10 children=1 %SRC /usr/local/bin/foobar
acl MyAcl external myAclType
http_access deny !MyAcl
http_access allow all

http_port 3128
debug_options ALL,1 82,9 4,9 28,9

hosts_file /etc/hosts
access_log /var/log/squid/access.log squid
coredump_dir /var/spool/squid
----->8-----

/usr/local/bin/foobar:
-----8<-----
$|=1;

my $FILENAME = "/tmp/acl.log";

open (MYFILE, ">>$FILENAME");
print MYFILE "Start\n";
close (MYFILE);

while (<>) {
  open (MYFILE, ">>$FILENAME");
  print MYFILE "Loop\n";
  print "ERR";
  close (MYFILE);
}
----->8-----

/tmp/acl.log
-----8<-----
Start
Loop
----->8-----

Thanks and best regards

dä Maik
Received on Thu Aug 27 2009 - 09:41:22 MDT