It is "ad_hostname=VICTORIA$@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@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
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" ???
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$@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$@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]
Longina -----Original Message----- From: sssd-users-bounces@lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub Hrozek Sent: 8. november 2012 18:41 To: sssd-users@lists.fedorahosted.org Subject: Re: [SSSD-users] startup problem/port status 0
On Thu, Nov 08, 2012 at 03:38:47PM +0000, Longina Przybyszewska wrote:
In /etc/sssd/sssd.conf
...... Ad_hostname = VICTORIA$@NAT.C.SDU.DK ......
It should be "ad_hostname" (note the capital A) and it's only useful for specifying the machine hostname in case the output of hostname command wouldn't reflect the real host name..
Does it work if you set:
ad_hostname = VICTORIA$ krb5_realm = NAT.C.SDU.DK
(VICTORIA$@NAT.C.SDU.DK was the one that worked for you, right?)
If it doesn't, can you raise debugging in the domain section, restart the sssd, try again and look for lines that mention "ldap_child" ? You would see the principal used there.
IT is obviously confusing about principal names...
Longina
-----Original Message----- From: sssd-users-bounces@lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub Hrozek Sent: 8. november 2012 10:54 To: sssd-users@lists.fedorahosted.org Subject: Re: [SSSD-users] startup problem/port status 0
On Tue, Nov 06, 2012 at 02:16:26PM +0000, Longina Przybyszewska wrote:
Hi again, Thanks a lot for guiding me so far :)
I have got sssd-1.9.2 package from Timo, Ubuntu sssd package maintainer for Ubuntu Quantal.
SSSD is configured against AD as auth/id - provider
sssd.conf
[sssd] debug_level = 0x1310 config_file_version = 2 services = nss, pam domains = nat.c.sdu.dk
[nss] filter_groups = root filter_users = root
[pam]
[domain/nat.c.sdu.dk]
debug_level = 0x1310
enumerate = False min_id = 1000 max_id = 20000
auth_provider = ad id_provider = ad access_provider = ad chpass_provider = ad
ad_server = nat.c.sdu.dk ad_hostname = testina4$.nat.c.sdu.dk ad_domain = nat.c.sdu.dk
From log: (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.18] TTL 455 (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: testina4$ (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'nat.c.sdu.dk' as 'not working (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' (Tue Nov 6 13:42:35 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' (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Tue Nov 6 13:42:35 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
There is not all the information in the log, raising the debug_level might provide more info, but I think the problem is in the kinit.
Can you kinit as the principal specified in the ad_hostname and then ldapsearch the directory?
Are you sure about the principal in ad_hostname? I think it is typically HOST$@DOMAIN, your principal doesn't contain the at-sign. _______________________________________________ sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users _______________________________________________ sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
_______________________________________________ sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
On Fri, Nov 09, 2012 at 11:15:25AM +0000, Longina Przybyszewska wrote:
It is "ad_hostname=VICTORIA$@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@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$@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$@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?
root@victoria:/var/log/sssd# cat /etc/sssd/sssd.conf | grep -v ^#
[sssd] debug_level = 0x1310 config_file_version = 2 services = nss, pam domains = nat.c.sdu.dk
[nss] filter_groups = root filter_users = root
[pam]
[domain/nat.c.sdu.dk]
debug_level = 10
enumerate = False min_id = 1000 max_id = 20000
auth_provider = ad krb5_realm = NAT.C.SDU.DK
id_provider = ad access_provider = ad chpass_provider = ad ldap_user_search_base = ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk ldap_user_object_class = person
ldap_group_object_class = group ldap_group_search_base = ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk
ad_server = nat.c.sdu.dk ad_hostname = VICTORIA$@NAT.C.SDU.DK ad_domain = nat.c.sdu.dk
....... Krb5_child. Log empty ..... Sssd-nat.c.sdu.dk.log .......................... Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 2221550 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_nat.c.sdu.dk.5678 to a link /var/lib/sss/pipes/private/s bus-dp_nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Loading backend [ad] with path [/usr/lib/x86_64-linux-gnu/sssd/libsss_ad.so]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_common_options] (0x0100): Setting domain case-insensitive (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_servers_init] (0x0100): Added failover server nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [USER][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [match_principal] (0x1000): Principal matched to the sample (*$@NAT.C.SDU.DK). (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected primary: VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected realm: NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_authid set to VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_server set to nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): ccache is of type FILE (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x222bab0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 222BAB0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x22336b0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 22336B0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [PAM] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [NSS] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=imadatestuser] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13: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 'neutral' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'resolving name' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in DNS (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'name resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk' (Fri Nov 9 13: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 [23]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [5683]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [5683] finished successfully. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Fri Nov 9 13: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]
Ldap_child.log ...... (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$@NAT.C.SDU.DK] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
......
Sssd.log ...... Fri Nov 9 13:06:36 2012) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nat.c.sdu.dk for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2640e50. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2640E50 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nat.c.sdu.dk as started. (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0100): Now starting services! (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nss for startup (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service pam for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643fa0. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643FA0 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643e60. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643E60 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (pam,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking pam as started. (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nss as started. (Fri Nov 9 13:06:39 2012) [sssd] [message_type] (0x0200): netlink Message type: 25 (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nat.c.sdu.dk (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nss (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging pam (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nat.c.sdu.dk replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nss replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service pam replied to ping
.... Sssd_nss.log ....
(Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 237E690 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [monitor_common_send_id] (0x0100): Sending ID: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_names_init] (0x0100): Using re [(((?P<domain>[^\]+)\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\]+)$))]. (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 2380600 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_common_send_id] (0x0100): Sending ID to DP: (1,NSS) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [8192] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_id_callback] (0x0100): Got id ack and version (1) from DP (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for [imadatestuser] from [<ALL>] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 19 error message: Subdomains back end target is not configured (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for [imadatestuser@nat.c.sdu.dk] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 1 errno: 11 error message: Offline (Fri Nov 9 13:07:00 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
That’s all... Longina -----Original Message----- From: sssd-users-bounces@lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub Hrozek Sent: 9. november 2012 12:48 To: sssd-users@lists.fedorahosted.org Subject: Re: [SSSD-users] startup problem/port 0 not working
On Fri, Nov 09, 2012 at 11:15:25AM +0000, Longina Przybyszewska wrote:
It is "ad_hostname=VICTORIA$@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@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$@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$@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? _______________________________________________ sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
Hi again,
Here you are all logs after 'getent passwd imadatestuser'
root@victoria:/var/log/sssd# cat /etc/sssd/sssd.conf | grep -v ^#
[sssd] debug_level = 0x1310 config_file_version = 2 services = nss, pam domains = nat.c.sdu.dk
[nss] filter_groups = root filter_users = root
[pam]
[domain/nat.c.sdu.dk]
debug_level = 10
enumerate = False min_id = 1000 max_id = 20000
auth_provider = ad krb5_realm = NAT.C.SDU.DK
id_provider = ad access_provider = ad chpass_provider = ad ldap_user_search_base = ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk ldap_user_object_class = person
ldap_group_object_class = group ldap_group_search_base = ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk
ad_server = nat.c.sdu.dk ad_hostname = VICTORIA$@NAT.C.SDU.DK ad_domain = nat.c.sdu.dk
....... Krb5_child. Log empty ..... Sssd-nat.c.sdu.dk.log .......................... Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 2221550 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_nat.c.sdu.dk.5678 to a link /var/lib/sss/pipes/private/s bus-dp_nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Loading backend [ad] with path [/usr/lib/x86_64-linux-gnu/sssd/libsss_ad.so]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_common_options] (0x0100): Setting domain case-insensitive (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_servers_init] (0x0100): Added failover server nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [USER][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [match_principal] (0x1000): Principal matched to the sample (*$@NAT.C.SDU.DK). (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected primary: VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected realm: NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_authid set to VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_server set to nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): ccache is of type FILE (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x222bab0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 222BAB0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x22336b0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 22336B0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [PAM] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [NSS] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=imadatestuser] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13: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 'neutral' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'resolving name' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in DNS (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'name resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk' (Fri Nov 9 13: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 [23]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [5683]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [5683] finished successfully. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Fri Nov 9 13: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]
Ldap_child.log ...... (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$@NAT.C.SDU.DK] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
......
Sssd.log ...... Fri Nov 9 13:06:36 2012) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nat.c.sdu.dk for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2640e50. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2640E50 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nat.c.sdu.dk as started. (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0100): Now starting services! (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nss for startup (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service pam for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643fa0. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643FA0 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643e60. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643E60 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (pam,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking pam as started. (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nss as started. (Fri Nov 9 13:06:39 2012) [sssd] [message_type] (0x0200): netlink Message type: 25 (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nat.c.sdu.dk (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nss (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging pam (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nat.c.sdu.dk replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nss replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service pam replied to ping
.... Sssd_nss.log ....
(Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 237E690 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [monitor_common_send_id] (0x0100): Sending ID: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_names_init] (0x0100): Using re [(((?P<domain>[^\]+)\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\]+)$))]. (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 2380600 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_common_send_id] (0x0100): Sending ID to DP: (1,NSS) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [8192] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_id_callback] (0x0100): Got id ack and version (1) from DP (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for [imadatestuser] from [<ALL>] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 19 error message: Subdomains back end target is not configured (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for [imadatestuser@nat.c.sdu.dk] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 1 errno: 11 error message: Offline (Fri Nov 9 13:07:00 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
That’s all... Longina
On 11/09/2012 07:27 AM, Longina Przybyszewska wrote:
Hi again,
Here you are all logs after 'getent passwd imadatestuser'
root@victoria:/var/log/sssd# cat /etc/sssd/sssd.conf | grep -v ^#
[sssd] debug_level = 0x1310 config_file_version = 2 services = nss, pam domains = nat.c.sdu.dk
[nss] filter_groups = root filter_users = root
[pam]
[domain/nat.c.sdu.dk]
debug_level = 10
enumerate = False min_id = 1000 max_id = 20000
auth_provider = ad krb5_realm = NAT.C.SDU.DK
id_provider = ad access_provider = ad chpass_provider = ad ldap_user_search_base = ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk ldap_user_object_class = person
ldap_group_object_class = group ldap_group_search_base = ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk
ad_server = nat.c.sdu.dk ad_hostname = VICTORIA$@NAT.C.SDU.DK ad_domain = nat.c.sdu.dk
....... Krb5_child. Log empty ..... Sssd-nat.c.sdu.dk.log .......................... Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 2221550 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_nat.c.sdu.dk.5678 to a link /var/lib/sss/pipes/private/s bus-dp_nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Loading backend [ad] with path [/usr/lib/x86_64-linux-gnu/sssd/libsss_ad.so]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_common_options] (0x0100): Setting domain case-insensitive (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_servers_init] (0x0100): Added failover server nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [USER][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [match_principal] (0x1000): Principal matched to the sample (*$@NAT.C.SDU.DK). (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected primary: VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected realm: NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_authid set to VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_server set to nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): ccache is of type FILE (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x222bab0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 222BAB0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x22336b0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 22336B0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [PAM] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [NSS] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=imadatestuser] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13: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 'neutral' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'resolving name' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in DNS (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'name resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk' (Fri Nov 9 13: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 [23]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [5683]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [5683] finished successfully. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Fri Nov 9 13: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]
Ldap_child.log ...... (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$@NAT.C.SDU.DK] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
......
Sssd.log ...... Fri Nov 9 13:06:36 2012) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nat.c.sdu.dk for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2640e50. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2640E50 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nat.c.sdu.dk as started. (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0100): Now starting services! (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nss for startup (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service pam for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643fa0. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643FA0 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643e60. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643E60 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (pam,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking pam as started. (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nss as started. (Fri Nov 9 13:06:39 2012) [sssd] [message_type] (0x0200): netlink Message type: 25 (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nat.c.sdu.dk (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nss (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging pam (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nat.c.sdu.dk replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nss replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service pam replied to ping
.... Sssd_nss.log ....
(Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 237E690 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [monitor_common_send_id] (0x0100): Sending ID: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_names_init] (0x0100): Using re [(((?P<domain>[^\]+)\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\]+)$))]. (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 2380600 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_common_send_id] (0x0100): Sending ID to DP: (1,NSS) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [8192] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_id_callback] (0x0100): Got id ack and version (1) from DP (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for [imadatestuser] from [<ALL>] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 19 error message: Subdomains back end target is not configured (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for [imadatestuser@nat.c.sdu.dk] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 1 errno: 11 error message: Offline (Fri Nov 9 13:07:00 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
That’s all... Longina
sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
Do I read it right that SSSD thinks that the system is offline and thus does not return anything for the user? Can you actually access AD at the moment of the test with other tools like LDAP search or do kinit?
On Fri, Nov 09, 2012 at 03:23:55PM -0500, Dmitri Pal wrote:
On 11/09/2012 07:27 AM, Longina Przybyszewska wrote:
Hi again,
Here you are all logs after 'getent passwd imadatestuser'
root@victoria:/var/log/sssd# cat /etc/sssd/sssd.conf | grep -v ^#
[sssd] debug_level = 0x1310 config_file_version = 2 services = nss, pam domains = nat.c.sdu.dk
[nss] filter_groups = root filter_users = root
[pam]
[domain/nat.c.sdu.dk]
debug_level = 10
enumerate = False min_id = 1000 max_id = 20000
auth_provider = ad krb5_realm = NAT.C.SDU.DK
id_provider = ad access_provider = ad chpass_provider = ad ldap_user_search_base = ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk ldap_user_object_class = person
ldap_group_object_class = group ldap_group_search_base = ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk
ad_server = nat.c.sdu.dk ad_hostname = VICTORIA$@NAT.C.SDU.DK ad_domain = nat.c.sdu.dk
....... Krb5_child. Log empty ..... Sssd-nat.c.sdu.dk.log .......................... Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_get_family_order] (0x1000): Lookup order: ipv4_first (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 2221550 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [monitor_common_send_id] (0x0100): Sending ID: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [create_socket_symlink] (0x1000): Symlinking the dbus path /var/lib/sss/pipes/private/sbus-dp_nat.c.sdu.dk.5678 to a link /var/lib/sss/pipes/private/s bus-dp_nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Loading backend [ad] with path [/usr/lib/x86_64-linux-gnu/sssd/libsss_ad.so]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_common_options] (0x0100): Setting domain case-insensitive (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_servers_init] (0x0100): Added failover server nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_set_search_bases] (0x0100): Search base not set. SSSD will attempt to discover it later, when connecting to the LDAP server. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [USER][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [GROUP][ou=ADGroups,dc=nat,dc=c,dc=sdu,dc=dk][SUBTREE][] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): trying to select the most appropriate principal from keytab (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [match_principal] (0x1000): Principal matched to the sample (*$@NAT.C.SDU.DK). (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected primary: VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [select_principal_from_keytab] (0x0200): Selected realm: NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_authid set to VICTORIA$ (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_id_options] (0x0100): Option ldap_sasl_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_server set to nat.c.sdu.dk (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [ad_get_auth_options] (0x0100): Option krb5_realm set to NAT.C.SDU.DK (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_lifetime] (0x0200): No lifetime configured. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): No kpasswd server explicitly configured, using the KDC or defaults. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [check_and_export_options] (0x0100): ccache is of type FILE (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x0200): no module name found in confdb, using [ad]. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [load_backend_module] (0x1000): Backend [ad] already loaded. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x222bab0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 222BAB0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x22336b0. (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_init_connection] (0x0200): Adding connection 22336B0 (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [be_client_init] (0x0100): Set-up Backend ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x222cb90] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [PAM] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Cancel DP ID timeout [0x2233ef0] (Fri Nov 9 13:06:36 2012) [sssd[be[nat.c.sdu.dk]]] [client_registration] (0x0100): Added Frontend client [NSS] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=imadatestuser] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13: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 'neutral' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name not resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'resolving name' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'nat.c.sdu.dk' in files (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'nat.c.sdu.dk' in DNS (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [set_server_common_status] (0x0100): Marking server 'nat.c.sdu.dk' as 'name resolved' (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk' (Fri Nov 9 13: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 [23]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_naming_context] (0x0200): Using value from [defaultNamingContext] as naming context. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [DEFAULT][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_netgroup_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [NETGROUP][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_sudo_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_service_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [SERVICE][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_set_search_base] (0x0100): Setting option [ldap_autofs_search_base] to [DC=nat,DC=c,DC=sdu,DC=dk]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [common_parse_search_base] (0x0100): Search base added: [AUTOFS][DC=nat,DC=c,DC=sdu,DC=dk][SUBTREE][] (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 13: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.18] TTL 190 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [5683]. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [5683] finished successfully. (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 13: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 13: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 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 1,11,Offline (Fri Nov 9 13: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]
Ldap_child.log ...... (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$@NAT.C.SDU.DK] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
......
Sssd.log ...... Fri Nov 9 13:06:36 2012) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nat.c.sdu.dk for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2640e50. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2640E50 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (%BE_nat.c.sdu.dk,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nat.c.sdu.dk as started. (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0100): Now starting services! (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service nss for startup (Fri Nov 9 13:06:36 2012) [sssd] [start_service] (0x0100): Queueing service pam for startup (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643fa0. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643FA0 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Entering. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Adding connection 0x2643e60. (Fri Nov 9 13:06:36 2012) [sssd] [sbus_init_connection] (0x0200): Adding connection 2643E60 (Fri Nov 9 13:06:36 2012) [sssd] [sbus_server_init_new_connection] (0x0200): Got a connection (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (pam,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking pam as started. (Fri Nov 9 13:06:36 2012) [sssd] [client_registration] (0x0100): Received ID registration: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd] [mark_service_as_started] (0x0200): Marking nss as started. (Fri Nov 9 13:06:39 2012) [sssd] [message_type] (0x0200): netlink Message type: 25 (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nat.c.sdu.dk (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging nss (Fri Nov 9 13:06:46 2012) [sssd] [service_send_ping] (0x0100): Pinging pam (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nat.c.sdu.dk replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service nss replied to ping (Fri Nov 9 13:06:46 2012) [sssd] [ping_check] (0x0100): Service pam replied to ping
.... Sssd_nss.log ....
(Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 237E690 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [monitor_common_send_id] (0x0100): Sending ID: (nss,1) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_names_init] (0x0100): Using re [(((?P<domain>[^\]+)\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\]+)$))]. (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sbus_init_connection] (0x0200): Adding connection 2380600 (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_common_send_id] (0x0100): Sending ID to DP: (1,NSS) (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sysdb_domain_init_internal] (0x0200): DB File for nat.c.sdu.dk: /var/lib/sss/db/cache_nat.c.sdu.dk.ldb (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'root' matched without domain, user is root (Fri Nov 9 13:06:36 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [8192] (Fri Nov 9 13:06:36 2012) [sssd[nss]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Fri Nov 9 13:06:36 2012) [sssd[nss]] [dp_id_callback] (0x0100): Got id ack and version (1) from DP (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for [imadatestuser] from [<ALL>] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 3 errno: 19 error message: Subdomains back end target is not configured (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'imadatestuser' matched without domain, user is imadatestuser (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): using default domain [(null)] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info for [imadatestuser@nat.c.sdu.dk] (Fri Nov 9 13:07:00 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 1 errno: 11 error message: Offline (Fri Nov 9 13:07:00 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
That’s all... Longina
sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
Do I read it right that SSSD thinks that the system is offline and thus does not return anything for the user? Can you actually access AD at the moment of the test with other tools like LDAP search or do kinit?
It seems that the ldap_child completed successfully, according to this:
(Fri Nov 9 13:07:00 2012) [[sssd[ldap_child[5683]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK]
That message is saying that the ldap_child was able to retrieve ccache correctly. But then the backend set the status to not working, but the logs don't tell why:
(Fri Nov 9 13:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 13: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'
I think it might be prudent to supply Longina with a build that would include more debugging.
-----Original Message----- From: sssd-users-bounces@lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Dmitri Pal Sent: 9. november 2012 21:24 To: sssd-users@lists.fedorahosted.org Subject: Re: [SSSD-users] FW: startup problem/port 0 not working
Do I read it right that SSSD thinks that the system is offline and thus does not return anything for the user? Can you actually access AD at the moment of the test with other tools like LDAP search or do kinit?
Yes, I do - I can do ldapsearch as admin aduser, ordinary user and using computer's keytab&GSSAPI.
Regards Longina
-- Thank you, Dmitri Pal
Sr. Engineering Manager for IdM portfolio Red Hat Inc.
------------------------------- Looking to carve out IT costs? www.redhat.com/carveoutcosts/
_______________________________________________ sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
Hi Jakub, How can I get more debugging level as you suggested? I got my packages Could my problem be related to DNS- resolution configuration? Old resolv.conf seems to be changed in Ubuntu Quantal - there is only reference to loopback.
But I have no problems with resolving names on that machine.
alongina@victoria:~$ cat /etc/resolv.conf # Dynamic resolv.conf(5) file for glibc resolver(3) generated by resolvconf(8) # DO NOT EDIT THIS FILE BY HAND -- YOUR CHANGES WILL BE OVERWRITTEN nameserver 127.0.1.1
regards Longina
-----Original Message----- From: sssd-users-bounces@lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub Hrozek Sent: 9. november 2012 12:48 To: sssd-users@lists.fedorahosted.org Subject: Re: [SSSD-users] startup problem/port 0 not working
On Fri, Nov 09, 2012 at 11:15:25AM +0000, Longina Przybyszewska wrote:
It is "ad_hostname=VICTORIA$@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@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$@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$@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? _______________________________________________ sssd-users mailing list sssd-users@lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users
sssd-users@lists.fedorahosted.org