+++ This bug was initially created as a clone of Bug #707997 +++ Description of problem: The IP provider of SSSD fails to connect to an IPA server if the IPA server hostname resolves to an IPv6 address. Version-Release number of selected component (if applicable): 1.5.1-37 How reproducible: always Steps to Reproduce: 1. configure IPA backend so that ipa_server points to a hostname that resolves to an IPv6 address 2. start sssd 3. try to get user info, e.g. getent passwd admin Actual results: Nothing is returned, sssd goes offline. Expected results: sssd connects and returns the user Additional info: The problem is that in the resolve callback we construct the LDAP URI based on IP address. LDAP routines cannot parse IPv6 IP address in URI. We should use the server hostname instead. When you hit the bug, the logs would show something like this: [sdap_connect_send] (1): ldap_initialize failed: Bad parameter to an ldap routine --- Additional comment from jhrozek on 2011-05-26 10:10:10 EDT --- Upstream ticket: https://fedorahosted.org/sssd/ticket/880
Upstream ticket: https://fedorahosted.org/sssd/ticket/880
Server: [root@jetfire ~]# ifconfig eth0 eth0 Link encap:Ethernet HWaddr 52:54:00:A8:B6:69 inet6 addr: 2620:52:0:41c9:5054:ff:fea8:b669/64 Scope:Global inet6 addr: fe80::5054:ff:fea8:b669/64 Scope:Link UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:150910 errors:0 dropped:0 overruns:0 frame:0 TX packets:13182 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:74030720 (70.6 MiB) TX bytes:1810825 (1.7 MiB) [root@jetfire ~]# [root@jetfire ~]# service ipa status Directory Service: RUNNING KDC Service: RUNNING KPASSWD Service: RUNNING DNS Service: RUNNING HTTP Service: RUNNING CA Service: RUNNING [root@jetfire ~]# [root@jetfire ~]# ipa user-add shanks --first=Gowrishankar --last=Rajaiyan --password Password: Enter Password again to verify: ------------------- Added user "shanks" ------------------- User login: shanks First name: Gowrishankar Last name: Rajaiyan Full name: Gowrishankar Rajaiyan Display name: Gowrishankar Rajaiyan Initials: GR Home directory: /home/shanks GECOS field: Gowrishankar Rajaiyan Login shell: /bin/sh Kerberos principal: shanks.PNQ.REDHAT.COM UID: 1001200003 GID: 1001200003 Keytab: True Password: True [root@jetfire ~]# Client: [root@ratchet ~]# ifconfig eth0 eth0 Link encap:Ethernet HWaddr 52:54:00:A6:0E:C8 inet6 addr: 2620:52:0:41c9:5054:ff:fea6:ec8/64 Scope:Global inet6 addr: fe80::5054:ff:fea6:ec8/64 Scope:Link UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:19074 errors:0 dropped:0 overruns:0 frame:0 TX packets:1002 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:1477222 (1.4 MiB) TX bytes:197635 (193.0 KiB) [root@ratchet ~]# [root@ratchet ~]# ipa-client-install Discovery was successful! Hostname: ratchet.lab.eng.pnq.redhat.com Realm: LAB.ENG.PNQ.REDHAT.COM DNS Domain: lab.eng.pnq.redhat.com IPA Server: jetfire.lab.eng.pnq.redhat.com BaseDN: dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com Continue to configure the system with these values? [no]: yes User authorized to enroll computers: admin Synchronizing time with KDC... Unable to sync time with IPA NTP server, assuming the time is in sync. Password for admin.PNQ.REDHAT.COM: Enrolled in IPA realm LAB.ENG.PNQ.REDHAT.COM Created /etc/ipa/default.conf Configured /etc/sssd/sssd.conf Configured /etc/krb5.conf for IPA realm LAB.ENG.PNQ.REDHAT.COM SSSD enabled NTP enabled Client configuration complete. [root@ratchet ~]# Client: [root@ratchet ~]# getent -s sss passwd shanks shanks:*:1001200003:1001200003:Gowrishankar Rajaiyan:/home/shanks:/bin/sh [root@ratchet ~]# (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): dbus conn: D613510 (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): Dispatching. (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [be_get_account_info] (4): Got request for [4097][1][name=shanks] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_step] (9): beginning to connect (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (7): Port status of port 0 for server '(no name)' is 'neutral' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_srv_send] (6): The status of SRV lookup is neutral (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_get_domain_send] (7): Host name is: ratchet.lab.eng.pnq.redhat.com (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_is_address] (9): [ratchet.lab.eng.pnq.redhat.com] does not look like an IP address (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_files_send] (4): Trying to resolve A record of 'ratchet.lab.eng.pnq.redhat.com' in files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_files_send] (4): Trying to resolve AAAA record of 'ratchet.lab.eng.pnq.redhat.com' in files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_get_domain_done] (7): The full FQDN is: ratchet.lab.eng.pnq.redhat.com (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_srv_cont] (4): Searching for servers via SRV query '_ldap._tcp.lab.eng.pnq.redhat.com' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_getsrv_send] (4): Trying to resolve SRV record of '_ldap._tcp.lab.eng.pnq.redhat.com' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [schedule_timeout_watcher] (9): Scheduling DNS timeout watcher (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [unschedule_timeout_watcher] (9): Unscheduling DNS timeout watcher (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_srv_done] (6): Inserted server 'jetfire.lab.eng.pnq.redhat.com:389' for service IPA (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [set_srv_data_status] (4): Marking SRV lookup of service 'IPA' as 'resolved' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name not resolved' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_is_address] (9): [jetfire.lab.eng.pnq.redhat.com] does not look like an IP address (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_files_send] (4): Trying to resolve A record of 'jetfire.lab.eng.pnq.redhat.com' in files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [set_server_common_status] (4): Marking server 'jetfire.lab.eng.pnq.redhat.com' as 'resolving name' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_files_send] (4): Trying to resolve AAAA record of 'jetfire.lab.eng.pnq.redhat.com' in files (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [set_server_common_status] (4): Marking server 'jetfire.lab.eng.pnq.redhat.com' as 'name resolved' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [be_resolve_server_done] (4): Found address for server jetfire.lab.eng.pnq.redhat.com: [2620:52:0:41c9:5054:ff:fea8:b669] TTL 7200 (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ipa_resolve_callback] (6): Constructed uri 'ldap://jetfire.lab.eng.pnq.redhat.com' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sss_ldap_init_send] (9): Using file descriptor [26] for LDAP connection. (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sss_ldap_init_send] (6): Setting 6 seconds timeout for connecting (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://jetfire.lab.eng.pnq.redhat.com:389/??base] with fd [26]. (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_rootdse_send] (9): Getting rootdse (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (6): calling ldap_search_ext with [(objectclass=*)][]. (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [*] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [altServer] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [namingContexts] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedControl] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedExtension] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedFeatures] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedLDAPVersion] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedSASLMechanisms] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [defaultNamingContext] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [lastUSN] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [highestCommittedUSN] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (8): ldap_search_ext called, msgid = 1 (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0xd618bc0], connected[1], ops[0xd622990], ldap[0xd619300] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_parse_entry] (9): OriginalDN: []. (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0xd618bc0], connected[1], ops[0xd622990], ldap[0xd619300] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (6): Search result: Success(0), (null) (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_rootdse_done] (9): Got rootdse (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_send] (6): Attempting kinit ((null), host/ratchet.lab.eng.pnq.redhat.com, LAB.ENG.PNQ.REDHAT.COM, 86400) (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_next_kdc] (7): Resolving next KDC for service IPA (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (7): Port status of port 0 for server 'jetfire.lab.eng.pnq.redhat.com' is 'neutral' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [be_resolve_server_done] (4): Found address for server jetfire.lab.eng.pnq.redhat.com: [2620:52:0:41c9:5054:ff:fea8:b669] TTL 7200 (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ipa_resolve_callback] (6): Constructed uri 'ldap://jetfire.lab.eng.pnq.redhat.com' (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_kdc_resolved] (7): KDC resolved, attempting to get TGT... (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [create_tgt_req_send_buffer] (7): buffer size: 73 (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [child_handler_setup] (8): Setting up signal handler up for pid [3456] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [child_handler_setup] (8): Signal handler set up for pid [3456] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [set_tgt_child_timeout] (6): Setting 6 seconds timeout for tgt child (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0xd618bc0], connected[1], ops[(nil)], ldap[0xd619300] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: ldap_result found nothing! (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [write_pipe_handler] (6): All data has been sent! (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [read_pipe_handler] (6): EOF received, client finished (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_tgt_recv] (6): Child responded: 0 [FILE:/var/lib/sss/db/ccache_LAB.ENG.PNQ.REDHAT.COM], expired on [1326279657] (Tue Jan 10 06:01:08 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sasl_bind_send] (4): Executing sasl bind mech: GSSAPI, user: host/ratchet.lab.eng.pnq.redhat.com (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [child_sig_handler] (7): Waiting for child [3456]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [child_sig_handler] (4): child [3456] finished successfully. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_set_port_status] (4): Marking port 389 of server 'jetfire.lab.eng.pnq.redhat.com' as 'working' (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [set_server_common_status] (4): Marking server 'jetfire.lab.eng.pnq.redhat.com' as 'working' (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (9): notify connected to op #1 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (6): calling ldap_search_ext with [(&(uid=shanks)(objectclass=posixAccount))][cn=accounts,dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [objectClass] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [uid] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [userPassword] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [uidNumber] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [gidNumber] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [gecos] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [homeDirectory] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [loginShell] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [krbPrincipalName] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [cn] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [memberOf] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [nsUniqueId] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [modifyTimestamp] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowLastChange] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowMin] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowMax] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowWarning] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowInactive] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowExpire] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowFlag] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [krbLastPwdChange] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [krbPasswordExpiration] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [pwdAttribute] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [authorizedService] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [accountExpires] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [userAccountControl] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [nsAccountLock] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (8): ldap_search_ext called, msgid = 5 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (9): caching successful connection after 1 notifies (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [be_run_online_cb] (3): Going online. Running callbacks. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0xd618bc0], connected[1], ops[0xd623850], ldap[0xd619300] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_parse_entry] (9): OriginalDN: [uid=shanks,cn=users,cn=accounts,dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0xd618bc0], connected[1], ops[0xd623850], ldap[0xd619300] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (6): Search result: Success(0), (null) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (7): Total count [0] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_users_process] (6): Search for users, returned 1 results. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 0) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Save user (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Adding original DN [uid=shanks,cn=users,cn=accounts,dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com] to attributes of [shanks]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Adding original memberOf attributes to [shanks]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Original USN value is not available for [shanks]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Adding user principal [shanks.PNQ.REDHAT.COM] to attributes of [shanks]. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Adding [krbLastPwdChange]=[20120110105955Z] to user attributes. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Adding [krbPasswordExpiration]=[20120110105955Z] to user attributes. (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (6): Storing info for user shanks (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 1) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xd630120 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xd630240 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0xd630240 "ltdb_timeout" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0xd630120 "ltdb_callback" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sysdb_search_user_by_name] (6): Error: 2 (No such file or directory) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 2) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xd625ec0 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xd625fe0 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0xd625fe0 "ltdb_timeout" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0xd625ec0 "ltdb_callback" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sysdb_search_user_by_uid] (6): Error: 2 (No such file or directory) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 3) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xd63cda0 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xd63cec0 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0xd63cec0 "ltdb_timeout" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0xd63cda0 "ltdb_callback" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 3) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 3) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xd63d080 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xd63d1a0 (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0xd63d1a0 "ltdb_timeout" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0xd63d080 "ltdb_callback" (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 3) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 2) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 1) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_users] (9): User 0 processed! (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 0) (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_users_process] (9): Saving 1 Users - Done (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_done] (9): releasing operation connection (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0xd618bc0], connected[1], ops[(nil)], ldap[0xd619300] (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: ldap_result found nothing! (Tue Jan 10 06:01:09 2012) [sssd[be[lab.eng.pnq.redhat.com]]] [delayed_online_authentication_callback] (5): Backend is online, starting delayed online authentication. [root@ratchet ~]# ssh -l shanks $HOSTNAME shanks.eng.pnq.redhat.com's password: Warning: Your password will expire in less than one hour. Password expired. Change your password now. WARNING: Your password has expired. You must change your password now and login again! Changing password for user shanks. Current Password: New UNIX password: Retype new UNIX password: Warning: Your password will expire in less than one hour. passwd: Authentication token manipulation error Connection to ratchet.lab.eng.pnq.redhat.com closed. [root@ratchet ~]# [root@ratchet ~]# ssh -l shanks $HOSTNAME shanks.eng.pnq.redhat.com's password: Last login: Tue Jan 10 06:02:08 2012 from ratchet.lab.eng.pnq.redhat.com -sh-3.2$ Server: ipa-server-2.1.3-9.el6.x86_64 Client: sssd-1.5.1-47.el5
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. http://rhn.redhat.com/errata/RHBA-2012-0164.html