On Fri, Nov 09, 2012 at 11:15:25AM +0000, Longina Przybyszewska wrote:
It is "ad_hostname=VICTORIA$(a)NAT.C.SDU.DK" - this is my
mail editor starting with capital letter after "." ;(
I joined domain (again, again..) from scratch.
ad_hostname = VICTORIA$NAT.C.SDU.DK
I have the following principal names bound to computer victoria.nat.sdu.dk
root@victoria:/var/log/sssd# ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y
GSSAPI -b 'ou=Linux computers,ou=ADResources,dc=nat,dc=c,dc=sdu,dc=dk'
'(&(objectClass=computer)(name=victoria))'
....
# VICTORIA, Linux computers, ADResources, nat.c.sdu.dk
dn: CN=VICTORIA,OU=Linux computers,OU=ADResources,DC=nat,DC=c,DC=sdu,DC=dk
objectClass: top
objectClass: person
objectClass: organizationalPerson
objectClass: user
objectClass: computer
cn: VICTORIA
distinguishedName: CN=VICTORIA,OU=Linux computers,OU=ADResources,DC=nat,DC=c,D
C=sdu,DC=dk
...
name: VICTORIA
...
sAMAccountName: VICTORIA$
sAMAccountType: 805306369
dNSHostName: victoria.nat.c.sdu.dk
userPrincipalName: victoria.nat.sdu.dk(a)NAT.C.SDU.DK
servicePrincipalName: host/victoria.nat.c.sdu.dk
...
I can kinit as admin aduser.
I can kinit as principal VICTORIA$ and VICTORIA$NAT.C.SDU.DK
OK, then the keytab seems fine.
I can as local root get info on computer 'victoria' and ad user
'imadatestuser':
ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=Linux
computers,ou=ADResources,dc=nat,dc=c,dc=sdu,dc=dk'
'(&(objectClass=computer)(name=victoria))'
root@victoria:/var/log/sssd# ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y
GSSAPI -b 'ou=ADusers,dc=nat,dc=c,dc=sdu,dc=dk'
'(&(objectClass=person)(sAMAccountName=imadatestuser))'
I can kinit imadatestuser
BUT login as imadatestuser and ' getent passwd imadatestuser' doesn't work -
still the same error on "port 0"
What is "port 0" ???
For server that "aggregate" LDAP and Kerberos such as AD or IPA, we don't
want to be talking to a different box in the same domain on LDAP port and
different box on Kerberos port.
So instead of using 389 for LDAP and 88 for Kerberos separately, we use
kind of a hack of using port 0 in the fail over code only to force the SSSD
to talk to a single AD/IPA server for both LDAP and Kerberos. Internally,
when establishing the network connection, we use the real ports of 389
and 88 of course.
Ldap_child.log
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): total
buffer size: 37
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): realm_str
size: 12
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): got
realm_str: NAT.C.SDU.DK
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): princ_str
size: 9
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): got
princ_str: VICTORIA$
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000):
keytab_name size: 0
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): lifetime:
86400
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [ldap_child_get_tgt_sync] (0x0100):
Principal name is: [VICTORIA$(a)NAT.C.SDU.DK]
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [ldap_child_get_tgt_sync] (0x0100):
Using keytab [default]
(Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [pack_buffer] (0x1000): result [0]
krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): total
buffer size: 37
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): realm_str
size: 12
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): got
realm_str: NAT.C.SDU.DK
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): princ_str
size: 9
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): got
princ_str: VICTORIA$
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000):
keytab_name size: 0
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): lifetime:
86400
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [ldap_child_get_tgt_sync] (0x0100):
Principal name is: [VICTORIA$(a)NAT.C.SDU.DK]
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [ldap_child_get_tgt_sync] (0x0100):
Using keytab [default]
(Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [pack_buffer] (0x1000): result [0]
krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
......
Sssd_nat.c.sdu.dk.log
.....
Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got
request for [4097][1][name=imadatestuser]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100):
Request processed. Returned 1,11,Fast reply - offline
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100):
Trying to resolve service 'AD'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status
of server 'nat.c.sdu.dk' is 'name resolved'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port
status of port 0 for server 'nat.c.sdu.dk' is 'not working'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x0100): Reseting
the status of port 0 for server 'nat.c.sdu.dk'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status
of server 'nat.c.sdu.dk' is 'name resolved'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000):
Saving the first resolved server
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200):
Found address for server nat.c.sdu.dk: [10.144.5.17] TTL 271
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100):
Constructed uri 'ldap://nat.c.sdu.dk'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_ldap_connect_callback_add]
(0x1000): New LDAP connection to [ldap://nat.c.sdu.dk:389/??base] with fd [22].
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [*]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [altServer]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [namingContexts]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [supportedControl]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [supportedExtension]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [supportedFeatures]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [supportedLDAPVersion]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [supportedSASLMechanisms]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [domainControllerFunctionality]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [defaultNamingContext]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [lastUSN]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000):
Requesting attrs: [highestCommittedUSN]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_server_opts_from_rootdse]
(0x0100): Setting AD compatibility level to [4]
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000):
Resolving next KDC for service AD
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100):
Trying to resolve service 'AD'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status
of server 'nat.c.sdu.dk' is 'name resolved'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status
of server 'nat.c.sdu.dk' is 'name resolved'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000):
Saving the first resolved server
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200):
Found address for server nat.c.sdu.dk: [10.144.5.17] TTL 271
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000):
KDC resolved, attempting to get TGT...
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer]
(0x1000): buffer size: 37
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting
for child [4471].
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child
[4471] finished successfully.
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing
sasl bind mech: gssapi, user: VICTORIA$
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100):
Marking port 0 of server 'nat.c.sdu.dk' as 'not working'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100):
Trying to resolve service 'AD'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status
of server 'nat.c.sdu.dk' is 'name resolved'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port
status of port 0 for server 'nat.c.sdu.dk' is 'not working'
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000):
Server resolution failed: 5
(Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [remove_krb5_info_files] (0x0200):
Could not remove [/var/lib/sss/pubconf/kpasswdinfo.NAT.C.SDU.DK], [2][No such file or
directory]
Hm, I still don't see the failure, what debug level are you using? Can
you bump it up to 10, please?