Re: Problem with SQUID_KERB_LDAP

["Markus Moeller" <huaraz@xxxxxxxxxxxxxxxx>]

"DmitrySh" <sbros_v@xxxxxxxx> wrote in message 
news:1287753284416-3007186.post@xxxxxxxxxxxxxxxx
> Hi guru's
>
> I try some weeks to configure my squid to auth with MS AD with
> squid_kerb_auth.
> As i understand squid_kerb_ldap is a new helper for ldap requests instead 
> of
> squid_ldap_group, or am i wrong?

Yes that is correct

> My squid.conf look like this:
>
> auth_param negotiate program 
> /usr/local/squid/libexec/squid_kerb_auth -d -s
> HTTP/proxyhostname.mydomain.com
> auth_param negotiate children 2
> auth_param negotiate keep_alive on
>
> external_acl_type SQUID_KERB_LDAP ttl=3600  negative_ttl=3600  %LOGIN
> /usr/local/squid/libexec/squid_kerb_ldap -g ProxyUsersGroup_in_AD
>
> acl LDAP_GROUP_CHECK external SQUID_KERB_LDAP
>
> http_access allow LDAP_GROUP_CHECK
>
> But when i start squid i have two problems:
> 1. squid_kerb_ldap didn't start
>
> 2010/10/21 16:19:09| Starting Squid Cache version 3.1.8 for
> i686-pc-linux-gnu...
> 2010/10/21 16:19:09| Process ID 7648
> 2010/10/21 16:19:09| With 1024 file descriptors available
> 2010/10/21 16:19:09| Initializing IP Cache...
> 2010/10/21 16:19:09| DNS Socket created at [::], FD 8
> 2010/10/21 16:19:09| DNS Socket created at 0.0.0.0, FD 9
> 2010/10/21 16:19:09| Adding domain mydomain.com from /etc/resolv.conf
> 2010/10/21 16:19:09| Adding nameserver 192.168.1.28 from /etc/resolv.conf
> 2010/10/21 16:19:09| Adding nameserver 192.168.1.17 from /etc/resolv.conf
> 2010/10/21 16:19:09| helperOpenServers: Starting 2/2 'squid_kerb_auth'
> processes
> 2010/10/21 16:19:09| squid_kerb_auth: INFO: Starting version 1.0.5
> 2010/10/21 16:19:09| helperOpenServers: Starting 5/5 'squid_kerb_ldap'
> processes
> 2010/10/21 16:19:09| WARNING: Cannot run
> '/usr/local/squid/libexec/squid_kerb_ldap' process.

Does it rin on the command line ? Do you have any process controls (selinux, 
apparmor) enabled ?

> 2010/10/21 16:19:09| WARNING: Cannot run
> '/usr/local/squid/libexec/squid_kerb_ldap' process.
> 2010/10/21 16:19:09| WARNING: Cannot run
> '/usr/local/squid/libexec/squid_kerb_ldap' process.
> 2010/10/21 16:19:09| WARNING: Cannot run
> '/usr/local/squid/libexec/squid_kerb_ldap' process.
> 2010/10/21 16:19:09| WARNING: Cannot run
> '/usr/local/squid/libexec/squid_kerb_ldap' process.
> 2010/10/21 16:19:09| squid_kerb_auth: INFO: Starting version 1.0.5
> 2010/10/21 16:19:09| Unlinkd pipe opened on FD 28
> 2010/10/21 16:19:09| Store logging disabled
> 2010/10/21 16:19:09| Swap maxSize 0 + 262144 KB, estimated 20164 objects
> 2010/10/21 16:19:09| Target number of buckets: 1008
> 2010/10/21 16:19:09| Using 8192 Store buckets
> 2010/10/21 16:19:09| Max Mem  size: 262144 KB
> 2010/10/21 16:19:09| Max Swap size: 0 KB
> 2010/10/21 16:19:09| Using Least Load store dir selection
> 2010/10/21 16:19:09| chdir: /usr/local/squid/var/cache: (2) No such file 
> or
> directory
> 2010/10/21 16:19:09| Current Directory is /etc/init.d
> 2010/10/21 16:19:09| Loaded Icons.
> 2010/10/21 16:19:09| Accepting  HTTP connections at [::]:80, FD 29.
> 2010/10/21 16:19:09| HTCP Disabled.
> 2010/10/21 16:19:09| Squid modules loaded: 0
> 2010/10/21 16:19:09| Ready to serve requests.
> 2010/10/21 16:19:10| storeLateRelease: released 0 objects
>
> Here detailed log with debug level 9
>
> 2010/10/21 17:41:24.062| comm_openex: Attempt open socket for: [::1]
> 2010/10/21 17:41:24.062| comm_openex: Opened socket FD 16 : family=10,
> type=1, protocol=0
> 2010/10/21 17:41:24.062| comm_open: FD 16 is a new socket
> 2010/10/21 17:41:24.062| fd_open() FD 16 squid_kerb_ldap
> 2010/10/21 17:41:24.062| commBind: bind socket FD 16 to [::1]
> 2010/10/21 17:41:24.062| comm_openex: Attempt open socket for: [::1]
> 2010/10/21 17:41:24.062| comm_openex: Opened socket FD 17 : family=10,
> type=1, protocol=0
> 2010/10/21 17:41:24.062| comm_open: FD 17 is a new socket
> 2010/10/21 17:41:24.062| fd_open() FD 17 squid_kerb_ldap
> 2010/10/21 17:41:24.062| commBind: bind socket FD 17 to [::1]
> 2010/10/21 17:41:24.062| ipcCreate: prfd FD 17
> 2010/10/21 17:41:24.062| ipcCreate: pwfd FD 17
> 2010/10/21 17:41:24.062| ipcCreate: crfd FD 16
> 2010/10/21 17:41:24.062| ipcCreate: cwfd FD 16
> 2010/10/21 17:41:24.062| ipcCreate: FD 17 sockaddr [::1]:60649
> 2010/10/21 17:41:24.062| ipcCreate: FD 16 sockaddr [::1]:47055
> 2010/10/21 17:41:24.062| ipcCreate: FD 16 listening...
> 2010/10/21 17:41:24.062| comm_close: start closing FD 16
> 2010/10/21 17:41:24.062| The AsyncCall comm_close_start constructed,
> this=0x83b85c0 [call13]
> 2010/10/21 17:41:24.062| comm.cc(1611) will call comm_close_start(FD 16)
> [call13]
> 2010/10/21 17:41:24.062| comm.cc(1195) commSetTimeout: FD 16 timeout -1
> 2010/10/21 17:41:24.062| comm.cc(1206) commSetTimeout: FD 16 timeout -1
> 2010/10/21 17:41:24.062| commCallCloseHandlers: FD 16
> 2010/10/21 17:41:24.062| The AsyncCall comm_close_complete constructed,
> this=0x83b8600 [call14]
> 2010/10/21 17:41:24.062| comm.cc(1643) will call comm_close_complete(FD 
> 16)
> [call14]
> 2010/10/21 17:41:24.062| comm_connect_addr: connecting socket 17 to
> [::1]:47055 (want family: 10)
> 2010/10/21 17:41:24.062| comm_connect_addr: sock=17, addrinfo(  flags=4,
> family=10, socktype=1, protocol=6, &addr=0x83b8668, addrlen
> =28 )
> 2010/10/21 17:41:24.062| connect FD 17: (-1) (101) Network is unreachable
> 2010/10/21 17:41:24.062| connecting to: [::1]:47055
> 2010/10/21 17:41:24.062| comm_close: start closing FD 17
> 2010/10/21 17:41:24.062| The AsyncCall comm_close_start constructed,
> this=0x83b8640 [call15]
> 2010/10/21 17:41:24.062| comm.cc(1611) will call comm_close_start(FD 17)
> [call15]
> 2010/10/21 17:41:24.062| comm.cc(1195) commSetTimeout: FD 17 timeout -1
> 2010/10/21 17:41:24.062| comm.cc(1206) commSetTimeout: FD 17 timeout -1
> 2010/10/21 17:41:24.062| commCallCloseHandlers: FD 17
> 2010/10/21 17:41:24.062| The AsyncCall comm_close_complete constructed,
> this=0x83b8680 [call16]
> 2010/10/21 17:41:24.062| comm.cc(1643) will call comm_close_complete(FD 
> 17)
> [call16]
>
>
> 2. In browser i have a request for username/password and after i enter it
> there are still errors in cache.log
>
> 2010/10/21 17:57:37.248| ACLList::matches: checking LDAP_GROUP_CHECK
> 2010/10/21 17:57:37.248| ACL::checklistMatches: checking 
> 'LDAP_GROUP_CHECK'
> 2010/10/21 17:57:37.248| authenticateAuthenticate: no connection
> authentication type
> 2010/10/21 17:57:37.248| Acl.cc(65) AuthenticateAcl: returning 0 sending
> credentials to helper.
> 2010/10/21 17:57:37.248| aclMatchExternal: SQUID_KERB_LDAP user not
> authenticated (0)
> 2010/10/21 17:57:37.248| ACL::ChecklistMatches: result for
> 'LDAP_GROUP_CHECK' is 0
> 2010/10/21 17:57:37.248| ACLList::matches: result is false
> 2010/10/21 17:57:37.248| aclmatchAclList: 0x85a7cf0 returning false (AND
> list entry failed to match)
> 2010/10/21 17:57:37.248| ACLChecklist::asyncInProgress: 0x85a7cf0 async 
> set
> to 1
> 2010/10/21 17:57:37.248| ACLChecklist::checkForAsync: checking password 
> via
> authenticator
> 2010/10/21 17:57:37.249| aclmatchAclList: async=1 nodeMatched=0
> async_in_progress=1 lastACLResult() = 0 finished() = 0
> 2010/10/21 17:57:37.249| clientReadSomeData: FD 12: reading request...
> 2010/10/21 17:57:37| squid_kerb_auth: DEBUG: Got 'YR YIIGZgYGK.....
> .....
> =' from squid (length: 2195).
> 2010/10/21 17:57:37| squid_kerb_auth: DEBUG: Decode 'YIIGZgYGKwYBBQU....
> ....
> =' (decoded length: 1642).
> 2010/10/21 17:57:37| squid_kerb_auth: ERROR: gss_acquire_cred() failed:
> Unspecified GSS failure.  Minor code may provide more inform
> ation. Permission denied
> 2010/10/21 17:57:37.250| commio_finish_callback: called for FD 11 (0, 0)
> 2010/10/21 17:57:37.250| comm_read_try: FD 11, size 8191, retval 115, 
> errno
> 0
> 2010/10/21 17:57:37.250| commio_finish_callback: called for FD 11 (0, 0)
> 2010/10/21 17:57:37.250| comm.cc(165) will call SomeCommReadHandler(FD 11,
> data=0x83ad588, size=115, buf=0x83ad600) [call95]
> 2010/10/21 17:57:37.250| entering SomeCommReadHandler(FD 11, 
> data=0x83ad588,
> size=115, buf=0x83ad600)
> 2010/10/21 17:57:37.250| AsyncCall.cc(32) make: make call
> SomeCommReadHandler [call95]
> 2010/10/21 17:57:37.250| helperStatefulHandleRead: end of reply found
> 2010/10/21 17:57:37.250| helper.cc(375) helperStatefulReleaseServer: srv-0
> flags.reserved = 1
> 2010/10/21 17:57:37.250| authenticateNegotiateHandleReply: Error 
> validating
> user via Negotiate. Error returned 'BH gss_acquire_cred(
> ) failed: Unspecified GSS failure.  Minor code may provide more 
> information.
> Permission denied'
> 2010/10/21 17:57:37.250| ACLChecklist::asyncInProgress: 0x85a7cf0 async 
> set
> to 0
> 2010/10/21 17:57:37.250| ACLChecklist::preCheck: 0x85a7cf0 checking
> 'http_access allow LDAP_GROUP_CHECK'
> 2010/10/21 17:57:37.250| ACLList::matches: checking LDAP_GROUP_CHECK
> 2010/10/21 17:57:37.250| ACL::checklistMatches: checking 
> 'LDAP_GROUP_CHECK'
> 2010/10/21 17:57:37.250| Acl.cc(70) AuthenticateAcl: returning 0 sending
> authentication challenge.
> 2010/10/21 17:57:37.250| aclMatchExternal: SQUID_KERB_LDAP user not
> authenticated (0)
> 2010/10/21 17:57:37.250| ACL::ChecklistMatches: result for
> 'LDAP_GROUP_CHECK' is 0
>
> etc..
>
> That's it.
>
> Can somebody help me to solve it?
> If needed more details i will give it.
>
> Regards,
>
> Dmitry Gorbunov
> --
> View this message in context: 
> http://squid-web-proxy-cache.1019090.n4.nabble.com/Problem-with-SQUID-KERB-LDAP-tp1468788p3007186.html
> Sent from the Squid - Users mailing list archive at Nabble.com.

Regards
Markus