Re: [squid-users] Re: Re: Re: Re: squid_ldap_group against nested groups/Ous

From: Eugene M. Zheganin <emz_at_norma.perm.ru>
Date: Tue, 31 Jul 2012 02:10:06 +0600

Hi, guys.

Hi, Markus. :)

I'm this weird guy that asks every 2 years about squid_kerb_ldap and
then falls back to his letargic sleep. :)
But it's not because I lose interest, but because of the time, and
because of the old decent authorization schemes on my squids that still
work fine even with Windows 7.

But, last time I once again decided to setup the nested groups and
GSS-SPNEGO.
negotiate_wrapper works just fine, thanks again.

So, to refresh your memory, last time :) I got this problem: inability
to bind to LDAP server.
I have an AD domain and a bunch of controllers.

Some of my thoughts I described below, but first the output.
The debug output looks like (fresh one, and sorry for the
pseudographics, but it's a real output):
===Cut===
[emz_at_wizard:/usr/local/etc/squid]# ./squid_kerb_group.sh
2012/07/31 01:27:12| squid_kerb_ldap: Starting version 1.2.2
2012/07/31 01:27:12| squid_kerb_ldap: Group list Internet Users - Proxy1@
2012/07/31 01:27:12| squid_kerb_ldap: Group Internet Users - Proxy1 Domain
2012/07/31 01:27:12| squid_kerb_ldap: Netbios list SOFTLAB_at_NORMA.COM
2012/07/31 01:27:12| squid_kerb_ldap: Netbios name SOFTLAB Domain NORMA.COM
2012/07/31 01:27:12| squid_kerb_ldap: ldap server list NULL
2012/07/31 01:27:12| squid_kerb_ldap: No ldap servers defined.
emz
2012/07/31 01:27:52| squid_kerb_ldap: Got User: emz set default domain:
NORMA.COM
2012/07/31 01:27:52| squid_kerb_ldap: Got User: emz Domain: NORMA.COM
2012/07/31 01:27:52| squid_kerb_ldap: User domain loop: group_at_domain
Internet Users - Proxy1@
2012/07/31 01:27:52| squid_kerb_ldap: Default domain loop: group_at_domain
Internet Users - Proxy1@
2012/07/31 01:27:52| squid_kerb_ldap: Found group_at_domain Internet Users
- Proxy1@
2012/07/31 01:27:52| squid_kerb_ldap: Setup Kerberos credential cache
2012/07/31 01:27:52| squid_kerb_ldap: Get default keytab file name
2012/07/31 01:27:52| squid_kerb_ldap: Got default keytab file name
/usr/local/etc/squid/HTTP.keytab
2012/07/31 01:27:52| squid_kerb_ldap: Get principal name from keytab
/usr/local/etc/squid/HTTP.keytab
2012/07/31 01:27:52| squid_kerb_ldap: Keytab entry has realm name: NORMA.COM
2012/07/31 01:27:52| squid_kerb_ldap: Found principal name:
HTTP/proxy-wizard.norma.com._at_NORMA.COM
2012/07/31 01:27:52| squid_kerb_ldap: Set credential cache to
MEMORY:squid_ldap_19356
2012/07/31 01:27:52| squid_kerb_ldap: Got principal name
HTTP/proxy-wizard.norma.com._at_NORMA.COM
2012/07/31 01:27:52| squid_kerb_ldap: Stored credentials
2012/07/31 01:27:52| squid_kerb_ldap: Initialise ldap connection
2012/07/31 01:27:52| squid_kerb_ldap: Canonicalise ldap server name for
domain NORMA.COM
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to spb-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to spb-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to sad-srv.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to hq-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to nb-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to mos-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved SRV _ldap._tcp.NORMA.COM
record to sam-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 1 of NORMA.COM to
hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 2 of NORMA.COM to
fd00::322
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 3 of NORMA.COM to
hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 4 of NORMA.COM to
fd00::322
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 5 of NORMA.COM to
hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 6 of NORMA.COM to
fd00::322
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 7 of NORMA.COM to
hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 8 of NORMA.COM to
hq-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 9 of NORMA.COM to
hq-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 10 of NORMA.COM
to hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 11 of NORMA.COM
to hq-dc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 12 of NORMA.COM
to hq-gc.norma.com
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 13 of NORMA.COM
to 192.168.92.189
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 14 of NORMA.COM
to 192.168.92.189
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 15 of NORMA.COM
to 192.168.92.189
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 16 of NORMA.COM
to 192.168.173.3
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 17 of NORMA.COM
to 192.168.180.26
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 18 of NORMA.COM
to 192.168.0.9
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 19 of NORMA.COM
to 192.168.173.3
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 20 of NORMA.COM
to 192.168.21.38
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 21 of NORMA.COM
to 192.168.21.38
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 22 of NORMA.COM
to 192.168.0.9
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 23 of NORMA.COM
to 192.168.180.3
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 24 of NORMA.COM
to 192.168.180.3
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 25 of NORMA.COM
to 192.168.180.26
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 26 of NORMA.COM
to 192.168.0.9
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 27 of NORMA.COM
to 192.168.180.26
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 28 of NORMA.COM
to 192.168.180.3
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 29 of NORMA.COM
to 192.168.21.38
2012/07/31 01:27:52| squid_kerb_ldap: Resolved address 30 of NORMA.COM
to 192.168.173.3
2012/07/31 01:27:52| squid_kerb_ldap: Adding NORMA.COM to list
2012/07/31 01:27:52| squid_kerb_ldap: Sorted ldap server names for
domain NORMA.COM:
2012/07/31 01:27:52| squid_kerb_ldap: Host: spb-gc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: sad-srv.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: hq-dc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: hq-gc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: nb-dc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: mos-dc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: sam-dc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: spb-dc.norma.com Port: 389
Priority: 0 Weight: 100
2012/07/31 01:27:52| squid_kerb_ldap: Host: 192.168.173.3 Port: -1
Priority: -1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: 192.168.180.26 Port: -1
Priority: -1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: 192.168.0.9 Port: -1
Priority: -1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: 192.168.21.38 Port: -1
Priority: -1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: 192.168.180.3 Port: -1
Priority: -1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: fd00::322 Port: -1 Priority:
-1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: 192.168.92.189 Port: -1
Priority: -1 Weight: -1
2012/07/31 01:27:52| squid_kerb_ldap: Host: NORMA.COM Port: -1 Priority:
-2 Weight: -2
2012/07/31 01:27:52| squid_kerb_ldap: Setting up connection to ldap
server spb-gc.norma.com:389
2012/07/31 01:27:52| squid_kerb_ldap: Bind to ldap server with SASL/GSSAPI
2012/07/31 01:27:52| squid_kerb_ldap: ldap_sasl_interactive_bind_s
error: Local error
2012/07/31 01:27:52| squid_kerb_ldap: Error while binding to ldap server
with SASL/GSSAPI: Local error
2012/07/31 01:27:52| squid_kerb_ldap: Setting up connection to ldap
server sad-srv.norma.com:389
2012/07/31 01:27:52| squid_kerb_ldap: Bind to ldap server with SASL/GSSAPI
2012/07/31 01:27:52| squid_kerb_ldap: ldap_sasl_interactive_bind_s
error: Local error
2012/07/31 01:27:52| squid_kerb_ldap: Error while binding to ldap server
with SASL/GSSAPI: Local error
2012/07/31 01:27:52| squid_kerb_ldap: Setting up connection to ldap
server hq-dc.norma.com:389
2012/07/31 01:27:52| squid_kerb_ldap: Bind to ldap server with SASL/GSSAPI
2012/07/31 01:27:52| squid_kerb_ldap: ldap_sasl_interactive_bind_s
error: Local error
2012/07/31 01:27:52| squid_kerb_ldap: Error while binding to ldap server
with SASL/GSSAPI: Local error
2012/07/31 01:27:52| squid_kerb_ldap: Setting up connection to ldap
server hq-gc.norma.com:389
2012/07/31 01:27:52| squid_kerb_ldap: Bind to ldap server with SASL/GSSAPI
2012/07/31 01:27:52| squid_kerb_ldap: Successfully initialised
connection to ldap server hq-gc.norma.com:389
2012/07/31 01:27:52| squid_kerb_ldap: Search ldap server with bind path
"" and filter: (objectclass=*)
2012/07/31 01:27:52| squid_kerb_ldap: Search ldap entries for attribute
: schemaNamingContext
2012/07/31 01:27:52| squid_kerb_ldap: 1 ldap entry found with attribute
: schemaNamingContext
2012/07/31 01:27:52| squid_kerb_ldap: Search ldap server with bind path
CN=Schema,CN=Configuration,DC=norma,DC=com and filter:
(ldapdisplayname=samaccountname)
2012/07/31 01:27:52| squid_kerb_ldap: Found 1 ldap entry
2012/07/31 01:27:52| squid_kerb_ldap: Determined ldap server as an
Active Directory server
2012/07/31 01:27:52| squid_kerb_ldap: Search ldap server with bind path
dc=NORMA,dc=COM and filter : (samaccountname=emz)
2012/07/31 01:27:52| squid_kerb_ldap: Found 1 ldap entry
2012/07/31 01:27:52| squid_kerb_ldap: Search ldap entries for attribute
: memberof
2012/07/31 01:27:52| squid_kerb_ldap: 14 ldap entries found with
attribute : memberof
2012/07/31 01:27:52| squid_kerb_ldap: Entry 1 "п÷п╬п╩я▄пЇп╬п╡п╟я┌п╣п╩п╦
п≤пҐя┌п╣я─пҐп╣я┌ - п°п╬я│п╨п╡п╟" in hex UTF-8 is
d09fd0bed0bbd18cd0b7d0bed0b2d0b0d182d0b5d0bbd0b820d098d0bdd182d0b5d180d0bdd0b5d182202d20d09cd0bed181d0bad0b2d0b0
2012/07/31 01:27:52| squid_kerb_ldap: Entry 1 "п÷п╬п╩я▄пЇп╬п╡п╟я┌п╣п╩п╦
п≤пҐя┌п╣я─пҐп╣я┌ - п°п╬я│п╨п╡п╟" does not match group name "Internet
Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 2 "Internet Users - Crystal"
in hex UTF-8 is 496e7465726e6574205573657273202d204372797374616c
2012/07/31 01:27:52| squid_kerb_ldap: Entry 2 "Internet Users - Crystal"
does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 3 "Internet Users - Samara"
in hex UTF-8 is 496e7465726e6574205573657273202d2053616d617261
2012/07/31 01:27:52| squid_kerb_ldap: Entry 3 "Internet Users - Samara"
does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 4 "Internet Users -
PanicBox" in hex UTF-8 is 496e7465726e6574205573657273202d2050616e6963426f78
2012/07/31 01:27:52| squid_kerb_ldap: Entry 4 "Internet Users -
PanicBox" does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 5 "Internet Users - SPb" in
hex UTF-8 is 496e7465726e6574205573657273202d20535062
2012/07/31 01:27:52| squid_kerb_ldap: Entry 5 "Internet Users - SPb"
does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 6 "Internet Users - Proxy2"
in hex UTF-8 is 496e7465726e6574205573657273202d2050726f787932
2012/07/31 01:27:52| squid_kerb_ldap: Entry 6 "Internet Users - Proxy2"
does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 7 "Internet Users - Proxy1"
in hex UTF-8 is 496e7465726e6574205573657273202d2050726f787931
2012/07/31 01:27:52| squid_kerb_ldap: Entry 7 "Internet Users - Proxy1"
matches group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 8 "п÷п╬п╩я▄пЇп╬п╡п╟я┌п╣п╩п╦
VPN" in hex UTF-8 is
d09fd0bed0bbd18cd0b7d0bed0b2d0b0d182d0b5d0bbd0b82056504e
2012/07/31 01:27:52| squid_kerb_ldap: Entry 8 "п÷п╬п╩я▄пЇп╬п╡п╟я┌п╣п╩п╦
VPN" does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 9 "Warez-RW" in hex UTF-8 is
576172657a2d5257
2012/07/31 01:27:52| squid_kerb_ldap: Entry 9 "Warez-RW" does not match
group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 10 "п·п░п≤п╒" in hex UTF-8
is d09ed090d098d0a2
2012/07/31 01:27:52| squid_kerb_ldap: Entry 10 "п·п░п≤п╒" does not match
group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 11
"п░пЄп╪п╦пҐп╦я│я┌я─п╟я┌п╬я─я▀ п©я─п╣пЄп©я─п╦я▐я┌п╦я▐" in hex UTF-8 is
d090d0b4d0bcd0b8d0bdd0b8d181d182d180d0b0d182d0bed180d18b20d0bfd180d0b5d0b4d0bfd180d0b8d18fd182d0b8d18f
2012/07/31 01:27:52| squid_kerb_ldap: Entry 11
"п░пЄп╪п╦пҐп╦я│я┌я─п╟я┌п╬я─я▀ п©я─п╣пЄп©я─п╦я▐я┌п╦я▐" does not match
group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 12
"п░пЄп╪п╦пҐп╦я│я┌я─п╟я┌п╬я─я▀" in hex UTF-8 is
d090d0b4d0bcd0b8d0bdd0b8d181d182d180d0b0d182d0bed180d18b
2012/07/31 01:27:52| squid_kerb_ldap: Entry 12
"п░пЄп╪п╦пҐп╦я│я┌я─п╟я┌п╬я─я▀" does not match group name "Internet Users
- Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 13
"п░пЄп╪п╦пҐп╦я│я┌я─п╟я┌п╬я─я▀ пЄп╬п╪п╣пҐп╟" in hex UTF-8 is
d090d0b4d0bcd0b8d0bdd0b8d181d182d180d0b0d182d0bed180d18b20d0b4d0bed0bcd0b5d0bdd0b0
2012/07/31 01:27:52| squid_kerb_ldap: Entry 13
"п░пЄп╪п╦пҐп╦я│я┌я─п╟я┌п╬я─я▀ пЄп╬п╪п╣пҐп╟" does not match group name
"Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Entry 14 "Exchange Organization
Administrators" in hex UTF-8 is
45786368616e6765204f7267616e697a6174696f6e2041646d696e6973747261746f7273
2012/07/31 01:27:52| squid_kerb_ldap: Entry 14 "Exchange Organization
Administrators" does not match group name "Internet Users - Proxy1"
2012/07/31 01:27:52| squid_kerb_ldap: Unbind ldap server
2012/07/31 01:27:52| squid_kerb_ldap: User emz is member of group_at_domain
Internet Users - Proxy1@
OK
2012/07/31 01:27:52| squid_kerb_ldap: OK
===Cut===

This time, as you can see, I'm able to bind to one of my DCs. But still
most of the binding fail.
Last time Markus said me to capture the tcpdump output and look for TGS
REQs, and I did.
I can post the entire output, but I think I figured out when the 'Local
error' failures arise.
So, as you can see, I got three 'Local errors' and then a successful
bind. When I was examining the pcap file in wireshark, I notcied a weird
thing: I have two TGS REQs with weird server names:

===Cut===
# grep Server\ Name pcap.txt
         Server Name (Principal): krbtgt/NORMA.COM
     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): krbtgt/NORMA.COM
                     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): krbtgt/168.180.26
     Server Name (Principal): krbtgt/168.180.26
                     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): krbtgt/168.92.189
     Server Name (Principal): krbtgt/168.92.189
                     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): ldap/fd00::322
     Server Name (Principal): ldap/fd00::322
                     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): ldap/hq-gc.norma.com
         Server Name (Principal): ldap/hq-gc.norma.com
                                         Server Name (Principal):
ldap/hq-gc.norma.com
         Server Name (Principal): krbtgt/NORMA.COM
     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): krbtgt/NORMA.COM
                     Server Name (Principal): krbtgt/NORMA.COM
         Server Name (Principal): cifs/HQ-GC.norma.com
         Server Name (Principal): cifs/HQ-GC.norma.com
===Cut===

168.180.26 and 168.92.189 - these are spb-gc.norma.com (first 'Local
error') and sad-srv.norma.com (second 'Local error'), and something
eated their leading octets. Can this lead to 'local errors' ? Third
'local error' was with the hq-dc.norma.com, it's fd00::322, and it's not
corrupted. And the first reference by name was a success.

Thanks.
Eugene.
Received on Mon Jul 30 2012 - 20:10:22 MDT

This archive was generated by hypermail 2.2.0 : Tue Jul 31 2012 - 12:00:02 MDT