[squid-users] squid 2.5.9, authentication problem

From: Dmitry Hazin <dhazin@dont-contact.us>
Date: Tue, 13 Mar 2007 22:02:58 +0600

debian sarge, squid 2.5.9

squid works fine without authentication, but when I try to configure
basic Authentication (the same problem with digest), pop-up login
window appears and then page is not loaded.
I suspect that ncsa_auth process is not being started (btw, should it
be in the process list when squid is running?)
Access rights and paths are all correct (proxy:proxy for file
containing password); ncsa_auth works ok in console (tried for proxy
user too)

Relevant configurations:

auth_param basic program /usr/lib/squid/ncsa_auth /etc/squid/squid_passwd
auth_param basic children 5
auth_param basic realm Squid proxy-caching web server
auth_param basic credentialsttl 2 hours
auth_param basic casesensitive off

acl all src 0.0.0.0/0.0.0.0
acl manager proto cache_object
acl localhost src 127.0.0.1/255.255.255.255
acl localnet src 192.168.128.0/24
acl to_localhost dst 127.0.0.0/8
acl SSL_ports port 443 563 # https, snews
acl SSL_ports port 873 # rsync
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 563 # https, snews
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 Safe_ports port 631 # cups
acl Safe_ports port 873 # rsync
acl Safe_ports port 901 # SWAT
acl purge method PURGE
acl CONNECT method CONNECT
acl authenticated_users proxy_auth REQUIRED

http_access allow purge localhost
http_access deny purge
# Deny requests to unknown ports
http_access deny !Safe_ports
# Deny CONNECT to other than 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
# to list your (internal) IP networks from where browsing should
# be allowed
#acl our_networks src 192.168.1.0/24 192.168.2.0/24
#http_access allow our_network
http_access allow localhost
http_access allow localnet authenticated_users

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

2007/03/13 21:38:34| authBasicConfigured: returning configured
2007/03/13 21:38:34| helperOpenServers: Starting 5 'ncsa_auth' processes
2007/03/13 21:38:35| User-Agent logging is disabled.
2007/03/13 21:38:35| Referer logging is disabled.
2007/03/13 21:38:35| Unlinkd pipe opened on FD 19
2007/03/13 21:38:35| Swap maxSize 102400 KB, estimated 7876 objects
2007/03/13 21:38:35| Target number of buckets: 393
2007/03/13 21:38:35| Using 8192 Store buckets
2007/03/13 21:38:35| Max Mem size: 8192 KB
2007/03/13 21:38:35| Max Swap size: 102400 KB
2007/03/13 21:38:35| Local cache digest enabled; rebuild/rewrite every
3600/3600 sec
2007/03/13 21:38:35| Rebuilding storage in /var/spool/squid (CLEAN)
2007/03/13 21:38:35| Using Least Load store dir selection
2007/03/13 21:38:35| Set Current Directory to /var/spool/squid
2007/03/13 21:38:35| Loaded Icons.
2007/03/13 21:38:35| Accepting HTTP connections at 192.168.128.1, port
3128, FD 21.
2007/03/13 21:38:35| Accepting ICP messages at 0.0.0.0, port 3130, FD 22.
2007/03/13 21:38:35| HTCP Disabled.
2007/03/13 21:38:35| WCCP Disabled.
2007/03/13 21:38:35| Ready to serve requests.
2007/03/13 21:38:35| Done reading /var/spool/squid swaplog (0 entries)
2007/03/13 21:38:35| Finished rebuilding storage from disk.
2007/03/13 21:38:35| 0 Entries scanned
2007/03/13 21:38:35| 0 Invalid entries.
2007/03/13 21:38:35| 0 With invalid flags.
2007/03/13 21:38:35| 0 Objects loaded.
2007/03/13 21:38:35| 0 Objects expired.
2007/03/13 21:38:35| 0 Objects cancelled.
2007/03/13 21:38:35| 0 Duplicate URLs purged.
2007/03/13 21:38:35| 0 Swapfile clashes avoided.
2007/03/13 21:38:35| Took 0.4 seconds ( 0.0 objects/sec).
2007/03/13 21:38:35| Beginning Validation Procedure
2007/03/13 21:38:35| Completed Validation Procedure
2007/03/13 21:38:35| Validated 0 Entries
2007/03/13 21:38:35| store_swap_size = 0k

...

2007/03/13 21:38:44| aclMatchAclList: checking authenticated_users
2007/03/13 21:38:44| aclMatchAcl: checking 'acl authenticated_users
proxy_auth REQUIRED'
2007/03/13 21:38:44| authenticateValidateUser: Validating Auth_user
request '(nil)'.
2007/03/13 21:38:44| authenticateValidateUser: Auth_user_request was NULL!
2007/03/13 21:38:44| authenticateAuthenticate: broken auth or no
proxy_auth header. Requesting auth header.
2007/03/13 21:38:44| aclMatchAcl: returning 0 sending authentication challenge.
2007/03/13 21:38:44| aclMatchAclList: no match, returning 0
2007/03/13 21:38:44| aclCheck: requiring Proxy Auth header.
2007/03/13 21:38:44| aclCheck: match found, returning 2
2007/03/13 21:38:44| aclCheckCallback: answer=2
2007/03/13 21:38:44| The request GET http://www.nsu.ru/ is DENIED,
because it matched 'authenticated_users'
2007/03/13 21:38:44| errorConvert: %U --> 'http://www.nsu.ru/'
2007/03/13 21:38:44| errorConvert: %U --> 'http://www.nsu.ru/'
2007/03/13 21:38:44| errorConvert: %U --> 'http://www.nsu.ru/'
2007/03/13 21:38:44| errorConvert: %w --> 'webmaster'
2007/03/13 21:38:44| errorConvert: %h --> 'my.host.com'
2007/03/13 21:38:44| errorConvert: %T --> 'Tue, 13 Mar 2007 15:38:44 GMT'
2007/03/13 21:38:44| errorConvert: %h --> 'my.host.com'
2007/03/13 21:38:44| errorConvert: %s --> 'squid/2.5.STABLE9'
2007/03/13 21:38:44| errorConvert: %S --> '
<BR clear="all">
<HR noshade size="1px">
<ADDRESS>
Generated Tue, 13 Mar 2007 15:38:44 GMT by my.host.com (squid/2.5.STABLE9)
</ADDRESS>
</BODY></HTML>
'
2007/03/13 21:38:44| authenticateFixHeader: headertype:35 authuser:(nil)
2007/03/13 21:38:44| authenticateFixErrorHeader: Sending type:35
header: 'Basic realm="Squid proxy-caching web server"'
2007/03/13 21:38:48| aclCheck: checking 'http_access allow purge localhost'
2007/03/13 21:38:48| aclMatchAclList: checking purge
2007/03/13 21:38:48| aclMatchAcl: checking 'acl purge method PURGE'
2007/03/13 21:38:48| aclMatchAclList: no match, returning 0
2007/03/13 21:38:48| aclCheck: checking 'http_access deny purge'
2007/03/13 21:38:48| aclMatchAclList: checking purge
2007/03/13 21:38:48| aclMatchAcl: checking 'acl purge method PURGE'
2007/03/13 21:38:48| aclMatchAclList: no match, returning 0
2007/03/13 21:38:48| aclCheck: checking 'http_access deny !Safe_ports'
2007/03/13 21:38:48| aclMatchAclList: checking !Safe_ports
2007/03/13 21:38:48| aclMatchAcl: checking 'acl Safe_ports port 80
         # http'
2007/03/13 21:38:48| aclMatchAclList: no match, returning 0
2007/03/13 21:38:48| aclCheck: checking 'http_access deny CONNECT !SSL_ports'
2007/03/13 21:38:48| aclMatchAclList: checking CONNECT
2007/03/13 21:38:48| aclMatchAcl: checking 'acl CONNECT method CONNECT'
2007/03/13 21:38:48| aclMatchAclList: no match, returning 0
2007/03/13 21:38:48| aclCheck: checking 'http_access allow localhost'
2007/03/13 21:38:48| aclMatchAclList: checking localhost
2007/03/13 21:38:48| aclMatchAcl: checking 'acl localhost src
127.0.0.1/255.255.255.255'
2007/03/13 21:38:48| aclMatchIp: '192.168.128.88' NOT found
2007/03/13 21:38:48| aclMatchAclList: no match, returning 0
2007/03/13 21:38:48| aclCheck: checking 'http_access allow localnet
authenticated_users'
2007/03/13 21:38:48| aclMatchAclList: checking localnet
2007/03/13 21:38:48| aclMatchAcl: checking 'acl localnet src 192.168.128.0/24'
2007/03/13 21:38:48| aclMatchIp: '192.168.128.88' found
2007/03/13 21:38:48| aclMatchAclList: checking authenticated_users
2007/03/13 21:38:48| aclMatchAcl: checking 'acl authenticated_users
proxy_auth REQUIRED'
2007/03/13 21:38:48| authenticateAuthenticate: header Basic d3d3OjEyMw==.
2007/03/13 21:38:48| authenticateAuthenticate: This is a new checklist
test on FD:20
2007/03/13 21:38:48| authenticateAuthenticate: no connection authentication type
2007/03/13 21:38:48| authenticateAuthUserRequestLock auth_user request
'0x844d1e8'.
2007/03/13 21:38:48| authenticateAuthUserRequestLock auth_user request
'0x844d1e8' now at '1'.
2007/03/13 21:38:48| authenticateDecodeAuth: header = 'Basic d3d3OjEyMw=='
2007/03/13 21:38:48| authenticateBasicDecodeAuth: cleartext = 'www:123'
2007/03/13 21:38:48| authBasicAuthUserFindUsername: Looking for user 'www'
2007/03/13 21:38:48| authBasicDecodeAuth: Creating new user 'www'
2007/03/13 21:38:48| authenticateAuthUserLock auth_user '0x8451318'.
2007/03/13 21:38:48| authenticateAuthUserLock auth_user '0x8451318' now at '1'.
2007/03/13 21:38:48| authenticateAuthUserLock auth_user '0x8451318'.
2007/03/13 21:38:48| authenticateAuthUserLock auth_user '0x8451318' now at '2'.
2007/03/13 21:38:48| authenticateValidateUser: Validating Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| authenticateValidateUser: Validated Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| authenticateValidateUser: Validating Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| authenticateValidateUser: Validated Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| User not authenticated or credentials need rechecking.
2007/03/13 21:38:48| authenticateValidateUser: Validating Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| authenticateValidateUser: Validated Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| User not authenticated or credentials need rechecking.
2007/03/13 21:38:48| aclMatchAcl: returning 0 sending credentials to helper.
2007/03/13 21:38:48| aclMatchAclList: no match, returning 0
2007/03/13 21:38:48| aclCheck: checking password via authenticator
2007/03/13 21:38:48| authenticateValidateUser: Validating Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| authenticateValidateUser: Validated Auth_user
request '0x844d1e8'.
2007/03/13 21:38:48| authenticateStart: auth_user_request '0x844d1e8'
2007/03/13 21:38:48| authenticateStart: 'www:123'
2007/03/13 21:38:48| authenticateAuthUserRequestLock auth_user request
'0x844d1e8'.
2007/03/13 21:38:48| authenticateAuthUserRequestLock auth_user request
'0x844d1e8' now at '2'.
2007/03/13 21:38:48| helperDispatch: Request sent to
basicauthenticator #1, 8 bytes
2007/03/13 21:38:48| helperSubmit: www 123

after this line nothing happens, if I press stop in the browser 2
additional lines are added:
2007/03/13 21:45:50| authenticateAuthUserRequestUnlock auth_user
request '0x844d1e8'.
2007/03/13 21:45:50| authenticateAuthUserRequestUnlock
auth_user_request '0x844d1e8' now at '1'.
Received on Tue Mar 13 2007 - 10:03:10 MDT

This archive was generated by hypermail pre-2.1.9 : Sat Mar 31 2007 - 13:00:02 MDT