[squid-users] avg antivirus and squid-2.5.STABLE13 ntlm auth issue

From: Marco Berizzi <pupilla@dont-contact.us>
Date: Wed, 22 Mar 2006 10:51:39 +0100

Hello everybody. I have updated squid from 2.5-STABLE12 to
2.5-STABLE13 and now avg antivirus updates don't work
anymore. This is my squid.conf:

hierarchy_stoplist cgi-bin ?
acl QUERY urlpath_regex cgi-bin \?
no_cache deny QUERY

cache_mem 48 MB

maximum_object_size 32 MB

cache_replacement_policy heap LFUDA
memory_replacement_policy heap GDSF

cache_dir ufs /var/spool/squid/cache 2047 16 256

cache_access_log /var/spool/squid/logs/access.log
cache_log /var/spool/squid/logs/cache.log
cache_store_log none
logfile_rotate 3

pid_filename /var/run/squid.pid

debug_options ALL,5

auth_param ntlm program /usr/libexec/squid/ntlm_auth foo/ntexve
auth_param ntlm children 50
auth_param ntlm max_challenge_reuses 0
auth_param ntlm max_challenge_lifetime 2 minutes

auth_param basic program /usr/libexec/squid/msnt_auth
auth_param basic children 5
auth_param basic realm Squid proxy-caching web server
auth_param basic credentialsttl 2 hours

authenticate_ip_ttl 800 seconds

cache_mgr postmaster@foo.it

cache_effective_user squid
cache_effective_group squidadm

forwarded_for off
store_avg_object_size 50 KB
buffered_logs on

acl all src 0.0.0.0/0.0.0.0
acl mynet src 172.16.0.0/23
acl allowsite dstdomain "/etc/squid/allowsite"
acl allowip dst "/etc/squid/allowip"
acl myproto proto HTTP FTP SSL
acl SSL_ports port 443 563 1443 8102
acl password proxy_auth_regex "/etc/squid/allowusers"
acl CONNECT method CONNECT

http_access deny CONNECT !SSL_ports
http_access deny !mynet
http_access deny !myproto

http_access allow allowsite
http_access allow allowip
http_access deny !password all
http_access allow password
http_access deny all

I have noticed that avg was working with squid 2.5-STABLE12
because basic auth was negotiated. With squid 2.5-STABLE13
ntml auth is negotiated with avg. Here is cache.log from
2.5-STABLE12 (avg and squid talk basic auth):

2006/03/22 10:17:10| clientReadRequest: FD 64: reading request...
2006/03/22 10:17:10| commSetSelect: FD 64 type 1
2006/03/22 10:17:10| cbdataLock: 0x846d6d0
2006/03/22 10:17:10| parseHttpRequest: Method is 'GET'
2006/03/22 10:17:10| parseHttpRequest: URI is
'http://guru.grisoft.com/softw/70free/update/avg7info.ctf'
2006/03/22 10:17:10| parseHttpRequest: req_hdr = {User-Agent: AVGINET-XP
71FREE AVI=268.2.6/287 BUILD=385 LIC=70FREE-TX-L7Z2U-IB-P1-C01-SIJTY-QEN
Host: guru.grisoft.com:80
Accept: *.*, */*
Proxy-Authorization: Basic bGJhcmluYTpsdWtlc2Fu
Connection: keep-alive
Proxy-Connection: Keep-Alive
Pragma: no-cache
Cache-Control: no-cache
Pragma: ID=

}
2006/03/22 10:17:10| parseHttpRequest: end = {}
2006/03/22 10:17:10| parseHttpRequest: prefix_sz = 374, req_line_sz = 71
2006/03/22 10:17:10| parseHttpRequest: Request Header is
User-Agent: AVGINET-XP 71FREE AVI=268.2.6/287 BUILD=385
LIC=70FREE-TX-L7Z2U-IB-P1-C01-SIJTY-QEN
Host: guru.grisoft.com:80
Accept: *.*, */*
Proxy-Authorization: Basic bGJhcmluYTpsdWtlc2Fu
Connection: keep-alive
Proxy-Connection: Keep-Alive
Pragma: no-cache
Cache-Control: no-cache
Pragma: ID=

2006/03/22 10:17:10| parseHttpRequest: Complete request received
2006/03/22 10:17:10| conn->in.offset = 0
2006/03/22 10:17:10| commSetTimeout: FD 64 timeout 86400
2006/03/22 10:17:10| clientSetKeepaliveFlag: http_ver = 1.1
2006/03/22 10:17:10| clientSetKeepaliveFlag: method = GET
2006/03/22 10:17:10| cbdataLock: 0x820bbc8
2006/03/22 10:17:10| cbdataLock: 0x846d6d0
2006/03/22 10:17:10| cbdataLock: 0x846ea40
2006/03/22 10:17:10| cbdataValid: 0x820bbc8
2006/03/22 10:17:10| aclCheck: checking 'http_access deny CONNECT
!SSL_ports'
2006/03/22 10:17:10| aclMatchAclList: checking CONNECT
2006/03/22 10:17:10| aclMatchAcl: checking 'acl CONNECT method CONNECT'
2006/03/22 10:17:10| aclMatchAclList: no match, returning 0
2006/03/22 10:17:10| cbdataLock: 0x820bba0
2006/03/22 10:17:10| cbdataUnlock: 0x820bbc8
2006/03/22 10:17:10| cbdataValid: 0x820bba0
2006/03/22 10:17:10| aclCheck: checking 'http_access deny !mynet'
2006/03/22 10:17:10| aclMatchAclList: checking !mynet
2006/03/22 10:17:10| aclMatchAcl: checking 'acl mynet src 172.16.0.0/23'
2006/03/22 10:17:10| aclMatchIp: '172.16.0.125' found
2006/03/22 10:17:10| aclMatchAclList: no match, returning 0
2006/03/22 10:17:10| cbdataLock: 0x820d1f0
2006/03/22 10:17:10| cbdataUnlock: 0x820bba0
2006/03/22 10:17:10| cbdataValid: 0x820d1f0
2006/03/22 10:17:10| aclCheck: checking 'http_access deny !myproto'
2006/03/22 10:17:10| aclMatchAclList: checking !myproto
2006/03/22 10:17:10| aclMatchAcl: checking 'acl myproto proto HTTP FTP SSL'
2006/03/22 10:17:10| aclMatchAclList: no match, returning 0
2006/03/22 10:17:10| cbdataLock: 0x820d248
2006/03/22 10:17:10| cbdataUnlock: 0x820d1f0
2006/03/22 10:17:10| cbdataValid: 0x820d248
2006/03/22 10:17:10| aclCheck: checking 'http_access allow allowsite'
2006/03/22 10:17:10| aclMatchAclList: checking allowsite
2006/03/22 10:17:10| aclMatchAcl: checking 'acl allowsite dstdomain
"/etc/squid/allowsite"'
2006/03/22 10:17:10| aclMatchDomainList: checking 'guru.grisoft.com'
2006/03/22 10:17:10| aclMatchDomainList: 'guru.grisoft.com' NOT found
2006/03/22 10:17:10| aclMatchAclList: no match, returning 0
2006/03/22 10:17:10| cbdataLock: 0x820d2a0
2006/03/22 10:17:10| cbdataUnlock: 0x820d248
2006/03/22 10:17:10| cbdataValid: 0x820d2a0
2006/03/22 10:17:10| aclCheck: checking 'http_access allow allowip'
2006/03/22 10:17:10| aclMatchAclList: checking allowip
2006/03/22 10:17:10| aclMatchAcl: checking 'acl allowip dst
"/etc/squid/allowip"'
2006/03/22 10:17:10| ipcache_gethostbyname: 'guru.grisoft.com', flags=1
2006/03/22 10:17:10| ipcache_nbgethostbyname: Name 'guru.grisoft.com'.
2006/03/22 10:17:10| ipcache_nbgethostbyname: MISS for 'guru.grisoft.com'
2006/03/22 10:17:10| idnsALookup: buf is 34 bytes for guru.grisoft.com, id =
0x414a
2006/03/22 10:17:10| cbdataLock: 0x846ef80
2006/03/22 10:17:10| commSetSelect: FD 5 type 1
2006/03/22 10:17:10| aclMatchAcl: Can't yet compare 'allowip' ACL for
'guru.grisoft.com'
2006/03/22 10:17:10| aclMatchAclList: no match, returning 0
2006/03/22 10:17:10| ipcache_nbgethostbyname: Name 'guru.grisoft.com'.
2006/03/22 10:17:10| ipcache_nbgethostbyname: MISS for 'guru.grisoft.com'
2006/03/22 10:17:10| cbdataLock: 0x846ece8
2006/03/22 10:17:10| cbdataLock: 0x846f348
2006/03/22 10:17:10| cbdataValid: 0x846d6d0
2006/03/22 10:17:10| cbdataUnlock: 0x846d6d0
2006/03/22 10:17:11| comm_poll: 1+0 FDs ready
2006/03/22 10:17:11| idnsRead: FD 5: received 66 bytes from 172.16.1.16.
2006/03/22 10:17:11| idnsGrokReply: ID 0x414a, 2 answers
2006/03/22 10:17:11| cbdataValid: 0x846ef80
2006/03/22 10:17:11| cbdataUnlock: 0x846ef80
2006/03/22 10:17:11| cbdataFree: 0x846ef80
2006/03/22 10:17:11| cbdataFree: Freeing 0x846ef80
2006/03/22 10:17:11| ipcacheParse: #0 193.86.3.36
2006/03/22 10:17:11| ipcacheParse: #1 193.86.3.38
2006/03/22 10:17:11| cbdataValid: 0x846f348
2006/03/22 10:17:11| cbdataUnlock: 0x846f348
2006/03/22 10:17:11| cbdataFree: 0x846f348
2006/03/22 10:17:11| cbdataFree: Freeing 0x846f348
2006/03/22 10:17:11| ipcacheParse: #0 193.86.3.36
2006/03/22 10:17:11| ipcacheParse: #1 193.86.3.38
2006/03/22 10:17:11| ipcacheRelease: Releasing entry for 'guru.grisoft.com'
2006/03/22 10:17:11| cbdataValid: 0x846ece8
2006/03/22 10:17:11| cbdataValid: 0x820d2a0
2006/03/22 10:17:11| aclCheck: checking 'http_access allow allowip'
2006/03/22 10:17:11| aclMatchAclList: checking allowip
2006/03/22 10:17:11| aclMatchAcl: checking 'acl allowip dst
"/etc/squid/allowip"'
2006/03/22 10:17:11| ipcache_gethostbyname: 'guru.grisoft.com', flags=1
2006/03/22 10:17:11| aclMatchIp: '193.86.3.36' NOT found
2006/03/22 10:17:11| aclMatchIp: '193.86.3.38' NOT found
2006/03/22 10:17:11| aclMatchAclList: no match, returning 0
2006/03/22 10:17:11| cbdataLock: 0x820d320
2006/03/22 10:17:11| cbdataUnlock: 0x820d2a0
2006/03/22 10:17:11| cbdataValid: 0x820d320
2006/03/22 10:17:11| aclCheck: checking 'http_access deny !password all'
2006/03/22 10:17:11| aclMatchAclList: checking !password
2006/03/22 10:17:11| aclMatchAcl: checking 'acl password proxy_auth_regex
"/etc/squid/allowusers"'
2006/03/22 10:17:11| authenticateAuthenticate: no connection authentication
type
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| User not authenticated or credentials need rechecking.
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| User not authenticated or credentials need rechecking.
2006/03/22 10:17:11| aclMatchAcl: returning 0 sending credentials to helper.
2006/03/22 10:17:11| aclMatchAclList: no match, returning 0
2006/03/22 10:17:11| aclCheck: checking password via authenticator
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| cbdataLock: 0x846ece8
2006/03/22 10:17:11| cbdataLock: 0x846fbd8
2006/03/22 10:17:11| cbdataValid: 0x846fbd8
2006/03/22 10:17:11| comm_write: FD 57: sz 16: hndl (nil): data (nil).
2006/03/22 10:17:11| commSetSelect: FD 57 type 2
2006/03/22 10:17:11| helperDispatch: Request sent to basicauthenticator #1,
16 bytes
2006/03/22 10:17:11| cbdataUnlock: 0x846ece8
2006/03/22 10:17:11| comm_poll: 1+0 FDs ready
2006/03/22 10:17:11| comm_poll: FD 57 ready for writing
2006/03/22 10:17:11| commHandleWrite: FD 57: off 0, sz 16.
2006/03/22 10:17:11| commHandleWrite: write() returns 16
2006/03/22 10:17:11| comm_poll: 1+0 FDs ready
2006/03/22 10:17:11| cbdataValid: 0x8276de0
2006/03/22 10:17:11| helperHandleRead: 3 bytes from basicauthenticator #1.
2006/03/22 10:17:11| commSetSelect: FD 57 type 1
2006/03/22 10:17:11| helperHandleRead: end of reply found
2006/03/22 10:17:11| cbdataValid: 0x846fbd8
2006/03/22 10:17:11| cbdataValid: 0x846ece8
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| cbdataValid: 0x820d320
2006/03/22 10:17:11| aclCheck: checking 'http_access deny !password all'
2006/03/22 10:17:11| aclMatchAclList: checking !password
2006/03/22 10:17:11| aclMatchAcl: checking 'acl password proxy_auth_regex
"/etc/squid/allowusers"'
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| authenticateAuthUserRequestSetIp: user 'lbarina' has
been seen at a new IP address (172.16.0.125)
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| aclMatchRegex: checking 'lbarina'
2006/03/22 10:17:11| aclMatchRegex: looking for 'mbissatini'
2006/03/22 10:17:11| aclMatchRegex: looking for 'lbarina'
2006/03/22 10:17:11| aclMatchAclList: no match, returning 0
2006/03/22 10:17:11| cbdataLock: 0x820d2f8
2006/03/22 10:17:11| cbdataUnlock: 0x820d320
2006/03/22 10:17:11| cbdataValid: 0x820d2f8
2006/03/22 10:17:11| aclCheck: checking 'http_access allow password'
2006/03/22 10:17:11| aclMatchAclList: checking password
2006/03/22 10:17:11| aclMatchAcl: checking 'acl password proxy_auth_regex
"/etc/squid/allowusers"'
2006/03/22 10:17:11| authenticateValidateUser: Validated Auth_user request
'0x846ef58'.
2006/03/22 10:17:11| aclCacheMatchAcl: cache hit on acl '0x8209f88'
2006/03/22 10:17:11| aclMatchAclList: returning 1
2006/03/22 10:17:11| aclCheck: match found, returning 1
2006/03/22 10:17:11| cbdataUnlock: 0x820d2f8
2006/03/22 10:17:11| aclCheckCallback: answer=1
2006/03/22 10:17:11| cbdataValid: 0x846ea40
2006/03/22 10:17:11| The request GET
http://guru.grisoft.com/softw/70free/update/avg7info.ctf is ALLOWED, because
it matched 'password'

And here is cache.log from 2.5-STABLE13 (avg and squid try
to talk ntlm auth):

2006/03/22 10:03:59| clientReadRequest: FD 66: reading request...
2006/03/22 10:03:59| commSetSelect: FD 66 type 1
2006/03/22 10:03:59| cbdataLock: 0x846e860
2006/03/22 10:03:59| parseHttpRequest: Method is 'GET'
2006/03/22 10:03:59| parseHttpRequest: URI is
'http://guru.grisoft.com/softw/70free/update/avginfo.ctf'
2006/03/22 10:03:59| parseHttpRequest: req_hdr = {User-Agent: AVGINET-XP
71FREE AVI=268.2.6/287 BUILD=385 LIC=70FREE-TX-L7Z2U-IB-P1-C01-SIJTY-QEN
Host: guru.grisoft.com:80
Accept: *.*, */*
If-Modified-Since: Tue, 21 Mar 2006 13:52:20 GMT
Pragma: no-cache
Cache-Control: no-cache
Pragma: ID=

}
2006/03/22 10:03:59| parseHttpRequest: end = {}
2006/03/22 10:03:59| parseHttpRequest: prefix_sz = 320, req_line_sz = 70
2006/03/22 10:03:59| parseHttpRequest: Request Header is
User-Agent: AVGINET-XP 71FREE AVI=268.2.6/287 BUILD=385
LIC=70FREE-TX-L7Z2U-IB-P1-C01-SIJTY-QEN
Host: guru.grisoft.com:80
Accept: *.*, */*
If-Modified-Since: Tue, 21 Mar 2006 13:52:20 GMT
Pragma: no-cache
Cache-Control: no-cache
Pragma: ID=

2006/03/22 10:03:59| parseHttpRequest: Complete request received
2006/03/22 10:03:59| conn->in.offset = 0
2006/03/22 10:03:59| commSetTimeout: FD 66 timeout 86400
2006/03/22 10:03:59| clientSetKeepaliveFlag: http_ver = 1.1
2006/03/22 10:03:59| clientSetKeepaliveFlag: method = GET
2006/03/22 10:03:59| cbdataLock: 0x82091c8
2006/03/22 10:03:59| cbdataLock: 0x846e860
2006/03/22 10:03:59| cbdataLock: 0x846fb98
2006/03/22 10:03:59| cbdataValid: 0x82091c8
2006/03/22 10:03:59| aclCheck: checking 'http_access deny CONNECT
!SSL_ports'
2006/03/22 10:03:59| aclMatchAclList: checking CONNECT
2006/03/22 10:03:59| aclMatchAcl: checking 'acl CONNECT method CONNECT'
2006/03/22 10:03:59| aclMatchAclList: no match, returning 0
2006/03/22 10:03:59| cbdataLock: 0x8209190
2006/03/22 10:03:59| cbdataUnlock: 0x82091c8
2006/03/22 10:03:59| cbdataValid: 0x8209190
2006/03/22 10:03:59| aclCheck: checking 'http_access deny !mynet'
2006/03/22 10:03:59| aclMatchAclList: checking !mynet
2006/03/22 10:03:59| aclMatchAcl: checking 'acl mynet src 172.16.0.0/23'
2006/03/22 10:03:59| aclMatchIp: '172.16.0.125' found
2006/03/22 10:03:59| aclMatchAclList: no match, returning 0
2006/03/22 10:03:59| cbdataLock: 0x820e3e8
2006/03/22 10:03:59| cbdataUnlock: 0x8209190
2006/03/22 10:03:59| cbdataValid: 0x820e3e8
2006/03/22 10:03:59| aclCheck: checking 'http_access deny !myproto'
2006/03/22 10:03:59| aclMatchAclList: checking !myproto
2006/03/22 10:03:59| aclMatchAcl: checking 'acl myproto proto HTTP FTP SSL'
2006/03/22 10:03:59| aclMatchAclList: no match, returning 0
2006/03/22 10:03:59| cbdataLock: 0x820e320
2006/03/22 10:03:59| cbdataUnlock: 0x820e3e8
2006/03/22 10:03:59| cbdataValid: 0x820e320
2006/03/22 10:03:59| aclCheck: checking 'http_access allow allowsite'
2006/03/22 10:03:59| aclMatchAclList: checking allowsite
2006/03/22 10:03:59| aclMatchAcl: checking 'acl allowsite dstdomain
"/etc/squid/allowsite"'
2006/03/22 10:03:59| aclMatchDomainList: checking 'guru.grisoft.com'
2006/03/22 10:03:59| aclMatchDomainList: 'guru.grisoft.com' NOT found
2006/03/22 10:03:59| aclMatchAclList: no match, returning 0
2006/03/22 10:03:59| cbdataLock: 0x820e348
2006/03/22 10:03:59| cbdataUnlock: 0x820e320
2006/03/22 10:03:59| cbdataValid: 0x820e348
2006/03/22 10:03:59| aclCheck: checking 'http_access allow allowip'
2006/03/22 10:03:59| aclMatchAclList: checking allowip
2006/03/22 10:03:59| aclMatchAcl: checking 'acl allowip dst
"/etc/squid/allowip"'
2006/03/22 10:03:59| ipcache_gethostbyname: 'guru.grisoft.com', flags=1
2006/03/22 10:03:59| aclMatchIp: '193.86.3.36' NOT found
2006/03/22 10:03:59| aclMatchIp: '193.86.3.38' NOT found
2006/03/22 10:03:59| aclMatchAclList: no match, returning 0
2006/03/22 10:03:59| cbdataLock: 0x820e2c8
2006/03/22 10:03:59| cbdataUnlock: 0x820e348
2006/03/22 10:03:59| cbdataValid: 0x820e2c8
2006/03/22 10:03:59| aclCheck: checking 'http_access deny !password all'
2006/03/22 10:03:59| aclMatchAclList: checking !password
2006/03/22 10:03:59| aclMatchAcl: checking 'acl password proxy_auth_regex
"/etc/squid/allowusers"'
2006/03/22 10:03:59| authenticateValidateUser: Auth_user_request was NULL!
2006/03/22 10:03:59| authenticateAuthenticate: broken auth or no proxy_auth
header. Requesting auth header.
2006/03/22 10:03:59| aclMatchAcl: returning 0 sending authentication
challenge.
2006/03/22 10:03:59| aclMatchAclList: no match, returning 0
2006/03/22 10:03:59| aclCheck: match found, returning 2
2006/03/22 10:03:59| cbdataUnlock: 0x820e2c8
2006/03/22 10:03:59| aclCheckCallback: answer=2
2006/03/22 10:03:59| cbdataValid: 0x846fb98
2006/03/22 10:03:59| The request GET
http://guru.grisoft.com/softw/70free/update/avginfo.ctf is DENIED, because
it matched 'password'

Hints?
Received on Wed Mar 22 2006 - 02:51:46 MST

This archive was generated by hypermail pre-2.1.9 : Sat Apr 01 2006 - 12:00:04 MST