[squid-users] Auth problem

Hi, all!

squid.conf
======
include "/etc/squid3/AUTH.config"
acl SSL_ports port 443
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 # https
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 CONNECT method CONNECT
acl auth_access proxy_auth REQUIRED
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access allow localhost manager
http_access deny manager
http_access deny !auth_access
http_access allow all
http_access deny all
http_port 8080
debug_options 28,9 29,9
coredump_dir /var/spool/squid3
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern -i (/cgi-bin/|\?) 0 0% 0
refresh_pattern . 0 20% 4320
=====

include "/etc/squid3/AUTH.config"
======
auth_param basic program /usr/lib/squid3/basic_pam_auth
auth_param basic children 10 startup=10 idle=5 concurrency=5
auth_param basic realm Company proxy server
auth_param basic credentialsttl 24 hours

authenticate_ttl 24 hour
authenticate_ip_ttl 60 seconds
======

/var/log/squid3/cache.log
====
2013/10/03 11:58:52.353 kid1| Config.cc(52) CreateAuthUser: header =
'Basic a2FtOmZzN2xxxxxx'
2013/10/03 11:58:52.353 kid1| UserRequest.cc(115) UserRequest:
initialised request 0x7f1f85b00940
2013/10/03 11:58:52.353 kid1| auth_basic.cc(242) decodeCleartext:
'user:password''
2013/10/03 11:58:52.353 kid1| User.cc(67) User: Initialised auth_user
'0x7f1f85e698f0'.
2013/10/03 11:58:52.353 kid1| auth_basic.cc(202)
authBasicAuthUserFindUsername: Looking for user 'user'
2013/10/03 11:58:52.353 kid1| User.cc(56) updateCached: Found user
'user' already in the user cache as '0x7f1f85e5e810'
2013/10/03 11:58:52.353 kid1| User.cc(69) updateCached: last attempt
to authenticate this user failed, resetting auth state to unchecked
2013/10/03 11:58:52.353 kid1| User.cc(153) ~User: Freeing auth_user
'0x7f1f85e698f0'.
2013/10/03 11:58:52.353 kid1| Acl.cc(281) aclCacheMatchFlush:
aclCacheMatchFlush called for cache 0x7f1f85e69918
2013/10/03 11:58:52.353 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.353 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.353 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.353 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.353 kid1| User.cc(38) authenticated: User not
authenticated or credentials need rechecking.
2013/10/03 11:58:52.354 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.354 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.354 kid1| User.cc(38) authenticated: User not
authenticated or credentials need rechecking.
2013/10/03 11:58:52.354 kid1| Acl.cc(61) AuthenticateAcl: returning 2
sending credentials to helper.
2013/10/03 11:58:52.354 kid1| Acl.cc(321) checklistMatches:
ACL::ChecklistMatches: result for 'auth_access' is -1
2013/10/03 11:58:52.354 kid1| Acl.cc(346) matches: auth_access needs
async lookup
2013/10/03 11:58:52.354 kid1| Acl.cc(354) matches: !auth_access result is false
2013/10/03 11:58:52.354 kid1| Checklist.cc(275) matchNode:
0x7f1f85dfd988 matched=0 async=1 finished=0
2013/10/03 11:58:52.354 kid1| Checklist.cc(312) matchNode:
0x7f1f85dfd988 going async
2013/10/03 11:58:52.354 kid1| Checklist.cc(131) asyncInProgress:
ACLChecklist::asyncInProgress: 0x7f1f85dfd988 async set to 1
2013/10/03 11:58:52.354 kid1| AclProxyAuth.cc(144) checkForAsync:
checking password via authenticator
2013/10/03 11:58:52.354 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.354 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:52.354 kid1| UserRequest.cc(66) start:
auth_user_request '0x7f1f85b00940'
2013/10/03 11:58:52.354 kid1| UserRequest.cc(86) module_start: 'user:password'
2013/10/03 11:58:52.354 kid1| Checklist.cc(256) matchNodes:
0x7f1f85dfd988 awaiting async operation
2013/10/03 11:58:53.535 kid1| UserRequest.cc(144) HandleReply: {ERR }
2013/10/03 11:58:53.535 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| Checklist.cc(131) asyncInProgress:
ACLChecklist::asyncInProgress: 0x7f1f85dfd988 async set to 0
2013/10/03 11:58:53.535 kid1| Checklist.cc(160) checkAccessList:
0x7f1f85dfd988 checking 'http_access deny !auth_access'
2013/10/03 11:58:53.535 kid1| Acl.cc(336) matches: ACLList::matches:
checking !auth_access
2013/10/03 11:58:53.535 kid1| Acl.cc(319) checklistMatches:
ACL::checklistMatches: checking 'auth_access'
2013/10/03 11:58:53.535 kid1| UserRequest.cc(338) authenticate: header
Basic a2FtOmZzN2xxxxxx.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| User.cc(38) authenticated: User not
authenticated or credentials need rechecking.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| User.cc(38) authenticated: User not
authenticated or credentials need rechecking.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(73) valid: Validating
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| UserRequest.cc(93) valid: Validated.
Auth::UserRequest '0x7f1f85b00940'.
2013/10/03 11:58:53.535 kid1| User.cc(38) authenticated: User not
authenticated or credentials need rechecking.
2013/10/03 11:58:53.535 kid1| Acl.cc(66) AuthenticateAcl: returning 3
sending authentication challenge.
2013/10/03 11:58:53.535 kid1| Checklist.cc(146) markFinished:
0x7f1f85dfd988 answer AUTH_REQUIRED for AuthenticateAcl exception
2013/10/03 11:58:53.535 kid1| Acl.cc(321) checklistMatches:
ACL::ChecklistMatches: result for 'auth_access' is -1
2013/10/03 11:58:53.535 kid1| Acl.cc(343) matches: auth_access failed.
2013/10/03 11:58:53.535 kid1| Acl.cc(354) matches: !auth_access result is false
2013/10/03 11:58:53.535 kid1| Checklist.cc(275) matchNode:
0x7f1f85dfd988 matched=0 async=0 finished=1
2013/10/03 11:58:53.535 kid1| Checklist.cc(294) matchNode:
0x7f1f85dfd988 exception: AUTH_REQUIRED
2013/10/03 11:58:53.535 kid1| Checklist.cc(88) matchNonBlocking:
ACLChecklist::check: 0x7f1f85dfd988 match found, calling back with
AUTH_REQUIRED
======

root_at_april3:/etc/squid3# /usr/lib/squid3/basic_pam_auth
user:password
ERR
user password
OK

More...
/var/log/auth.log
Oct 3 14:46:32 april3 (basic_pam_auth): pam_unix(squid:auth):
authentication failure; logname= uid=13 euid=13 tty= ruser= rhost=
Oct 3 14:46:32 april3 (basic_pam_auth): pam_sss(squid:auth):
authentication failure; logname= uid=13 euid=13 tty= ruser= rhost=
user=0
Oct 3 14:46:32 april3 (basic_pam_auth): pam_sss(squid:auth): received
for user 0: 10 (User not known to the underlying authentication
module)
Oct 3 14:46:34 april3 (basic_pam_auth): pam_unix(squid:auth): check
pass; user unknown
======

And:
root_at_april3:/etc/squid3#login
in /var/log/auth.log
Oct 3 14:49:44 april3 login[17481]: pam_unix(login:auth):
authentication failure; logname=user uid=0 euid=0 tty=/dev/pts/1
ruser= rhost= user=user
Oct 3 14:49:45 april3 login[17481]: pam_sss(login:auth):
authentication success; logname=user uid=0 euid=0 tty=/dev/pts/1
ruser= rhost= user=user
Oct 3 14:49:45 april3 login[17481]: pam_unix(login:session): session
opened for user user by user(uid=0)

Where I mistake?

Best regards.
Received on Thu Oct 03 2013 - 11:27:44 MDT