[squid-users] external ACL check sporadically failing

Hi,

Problem: We need to limit access to our Squid installation
to ~90,000 specified ip addresses.

We've set up an external_acl_type and external acl checker
to check the ip address against the flat file listing the
permitted ip addresses, and this mostly works, but not always:
squid access log occasionally shows TCP_DENIED/403 for IP
addresses that _are_ in the allow file and that should have
been let through.

After adding logging to the external acl checker, I see that
the external acl checker was never queried about the ip addreses
that got denied.

Cache.log entry does not show any communication with the
external acl checker. Example (and this is not the real ip
address):

2003/04/14 09:26:28| aclMatchAclList: checking our_ips
2003/04/14 09:26:28| aclMatchAcl: checking 'acl our_ips external our_external'
2003/04/14 09:26:28| aclMatchExternal: our_external("0.0.0.1") = lookup needed
2003/04/14 09:26:28| aclMatchAclList: returning 0

Whereas in cases when an allowed ip is let through, cache log
shows:

2003/04/14 10:43:44| aclMatchAclList: checking our_ips
2003/04/14 10:43:44| aclMatchAcl: checking 'acl our_ips
2003/04/14 10:43:44| external_acl_cache_lookup: '0.0.0.2' = expired
2003/04/14 10:43:44| aclMatchExternal: our_external("0.0.0.2") = lookup needed
2003/04/14 10:43:44| aclMatchAclList: returning 0
2003/04/14 10:43:44| externalAclLookup: lookup in 'our_external' for '0.0.0.2'
2003/04/14 10:43:44| external_acl_cache_add: Adding '0.0.0.2' = -1
2003/04/14 10:43:44| externalAclHandleReply: reply="OK"
2003/04/14 10:43:44| external_acl_cache_add: Adding '0.0.0.2' = 1

And when a non-allowed ip is forbidden due to reply from the
acl checker, ERR from acl checker is logged:

2003/04/14 10:43:55| aclMatchAclList: checking our_ips
2003/04/14 10:43:55| aclMatchAcl: checking 'acl our_ips external our_external'
2003/04/14 10:43:55| external_acl_cache_lookup: '0.0.0.3' = expired
2003/04/14 10:43:55| aclMatchExternal: our_external("0.0.0.3") = lookup needed
2003/04/14 10:43:55| aclMatchAclList: returning 0
2003/04/14 10:43:55| externalAclLookup: lookup in 'our_external' for '0.0.0.3'
2003/04/14 10:43:55| external_acl_cache_add: Adding '0.0.0.3' = -1
2003/04/14 10:43:55| externalAclHandleReply: reply="ERR"
2003/04/14 10:43:55| external_acl_cache_add: Adding '0.0.0.3' = 0

But in the "false negative" cases we're running into, it's
like squid was unable to talk to the external acl checker
(no "externalAclHandleReply: reply=" line) and therefore
assumed 403.

I even tried setting up a 2nd external ACL checker, and
invoking it after the first, but that did not help (i guess
if the first check results in a false negative it never
tries to check again).

Squid Cache: Version 2.5.STABLE2
Solaris 8

Here is my external ACL checker:

#!/usr/local/bin/perl

select (STDIN);
$|=1;

select (STDOUT);
$|=1;

open (ACL, "/tmp/our_ips") || die;
while ($ip = <ACL>) {
    chomp $ip;
    $ip =~ s/\s//g;
    $acl{${ip}} = 1;
}
close (ACL);

open (LOG, ">> /var/log/squidproxy/ACLchecker.log") || die;

select (LOG);
$|=1;

print LOG localtime() . ' ' . $$ . " starting\n";

while ( defined ($ip = <STDIN>)) {
    chomp $ip;
    if ($acl{$ip}) { $result="OK\n" } else { $result="ERR\n" }
    print STDOUT $result;
    print LOG localtime() . ' ' . $ip . ' ' . $result || die;
}

print LOG localtime() . ' ' . $$ . " exiting\n";
close (LOG);
exit;

Config:
external_acl_type our_external concurrency=10 ttl=86400 negative_ttl=1 %SRC /path/to/squidproxy/bin/check-acls.pl

(we set negative_ttl to 1 because it 0 it seemed to be
turned off and we didn't want caching of negatives)

Why are we getting false negatives and how can it be
remedied, please?

Yours Sincerely,
Alex Tsalolikhin
Unix Sys Admin
Received on Mon Apr 14 2003 - 15:34:45 MDT