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@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@xxxxxxxxx
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@domain
Internet Users - Proxy1@
2012/07/31 01:27:52| squid_kerb_ldap: Default domain loop: group@domain
Internet Users - Proxy1@
2012/07/31 01:27:52| squid_kerb_ldap: Found group@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.@xxxxxxxxx
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.@xxxxxxxxx
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@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.
