Bug 707997

Summary:	The IPA provider does not work with IPv6
Product:	Red Hat Enterprise Linux 6	Reporter:	Jakub Hrozek <jhrozek>
Component:	sssd	Assignee:	Stephen Gallagher <sgallagh>
Status:	CLOSED ERRATA	QA Contact:	Chandrasekar Kannan <ckannan>
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	6.1	CC:	benl, dpal, grajaiya, jgalipea, prc
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	sssd-1.5.1-39.el6	Doc Type:	Bug Fix
Doc Text:	Cause: The IPA provider internally constructs an LDAP URI based on what the host name specified in ipa_server parameter resolves to. However, when the host name resolved to an IPv6 address, the LDAP URI routines returned an error Consequence: The IPA provider was unable to function correctly in an IPv6 environment Fix: The IPA provider escapes all IPv6 addresses so that they can be consumed by the LDAP routines correctly Result: The IPA provider is able to function in an IPv6 environment	Story Points:	---
Clone Of:
Clones:	707999 (view as bug list)		Environment:
Last Closed:	2011-12-06 16:38:35 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	707999

Description Jakub Hrozek 2011-05-26 14:09:42 UTC

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

Comment 1 Jakub Hrozek 2011-05-26 14:10:10 UTC

Upstream ticket:
https://fedorahosted.org/sssd/ticket/880

Comment 5 Gowrishankar Rajaiyan 2011-10-03 08:39:46 UTC

# cat /etc/resolv.conf 
nameserver 2620:52:0:41c9:5054:ff:fea8:b669


# getent passwd admin
admin:*:63600000:63600000:Administrator:/home/admin:/bin/bash


# /var/log/sssd/sssd_lab.eng.pnq.redhat.com.log
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): dbus conn: 154C810
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_dispatch] (9): Dispatching.
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_get_account_info] (4): Got request for [4097][1][name=admin]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_step] (9): beginning to connect
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_port_status] (7): Port status of port 0 for server '(no name)' is 'neutral'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_srv_send] (6): The status of SRV lookup is neutral
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_get_domain_send] (7): Host name is: ratchet.lab.eng.pnq.redhat.com
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_is_address] (9): [ratchet.lab.eng.pnq.redhat.com] does not look like an IP address
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files
(Mon Oct  3 04:36:58 2011) [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
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files
(Mon Oct  3 04:36:58 2011) [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
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_get_domain_done] (7): The full FQDN is: ratchet.lab.eng.pnq.redhat.com
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_srv_cont] (4): Searching for servers via SRV query '_ldap._tcp.lab.eng.pnq.redhat.com'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_getsrv_send] (4): Trying to resolve SRV record of '_ldap._tcp.lab.eng.pnq.redhat.com'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [schedule_timeout_watcher] (9): Scheduling DNS timeout watcher
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [unschedule_timeout_watcher] (9): Unscheduling DNS timeout watcher
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolve_srv_done] (6): Inserted server 'jetfire.lab.eng.pnq.redhat.com:389' for service IPA
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [set_srv_data_status] (4): Marking SRV lookup of service 'IPA' as 'resolved'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name not resolved'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_is_address] (9): [jetfire.lab.eng.pnq.redhat.com] does not look like an IP address
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files
(Mon Oct  3 04:36:58 2011) [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
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [set_server_common_status] (4): Marking server 'jetfire.lab.eng.pnq.redhat.com' as 'resolving name'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [resolv_gethostbyname_step] (8): Querying files
(Mon Oct  3 04:36:58 2011) [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
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [set_server_common_status] (4): Marking server 'jetfire.lab.eng.pnq.redhat.com' as 'name resolved'
(Mon Oct  3 04:36:58 2011) [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
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ipa_resolve_callback] (6): Constructed uri 'ldap://jetfire.lab.eng.pnq.redhat.com'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sss_ldap_init_send] (9): Using file descriptor [27] for LDAP connection.
(Mon Oct  3 04:36:58 2011) [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 [27].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_rootdse_send] (9): Getting rootdse
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (6): calling ldap_search_ext with [(objectclass=*)][].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [*]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [altServer]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [namingContexts]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedControl]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedExtension]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedFeatures]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedLDAPVersion]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [supportedSASLMechanisms]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [defaultNamingContext]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [lastUSN]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [highestCommittedUSN]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (8): ldap_search_ext called, msgid = 1
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[0x15500d0], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_parse_entry] (9): OriginalDN: [].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[0x15500d0], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_rootdse_done] (9): Got rootdse
(Mon Oct  3 04:36:58 2011) [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)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_next_kdc] (7): Resolving next KDC for service IPA
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [fo_resolve_service_send] (4): Trying to resolve service 'IPA'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved'
(Mon Oct  3 04:36:58 2011) [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'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [get_server_status] (7): Status of server 'jetfire.lab.eng.pnq.redhat.com' is 'name resolved'
(Mon Oct  3 04:36:58 2011) [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
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ipa_resolve_callback] (6): Constructed uri 'ldap://jetfire.lab.eng.pnq.redhat.com'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_kinit_kdc_resolved] (7): KDC resolved, attempting to get TGT...
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [create_tgt_req_send_buffer] (7): buffer size: 73
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_handler_setup] (8): Setting up signal handler up for pid [13726]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_handler_setup] (8): Signal handler set up for pid [13726]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [set_tgt_child_timeout] (6): Setting 6 seconds timeout for tgt child
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[(nil)], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [write_pipe_handler] (6): All data has been sent!
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [read_pipe_handler] (6): EOF received, client finished
(Mon Oct  3 04:36:58 2011) [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 [1317717397]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sasl_bind_send] (4): Executing sasl bind mech: GSSAPI, user: host/ratchet.lab.eng.pnq.redhat.com
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_sig_handler] (7): Waiting for child [13726].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [child_sig_handler] (4): child [13726] finished successfully.
(Mon Oct  3 04:36:58 2011) [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'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [set_server_common_status] (4): Marking server 'jetfire.lab.eng.pnq.redhat.com' as 'working'
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (9): notify connected to op #1
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (6): calling ldap_search_ext with [(&(uid=admin)(objectclass=posixAccount))][cn=accounts,dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [objectClass]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [uid]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [userPassword]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [uidNumber]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [gidNumber]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [gecos]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [homeDirectory]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [loginShell]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [krbPrincipalName]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [cn]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [memberOf]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [nsUniqueId]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [modifyTimestamp]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowLastChange]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowMin]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowMax]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowWarning]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowInactive]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowExpire]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [shadowFlag]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [krbLastPwdChange]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [krbPasswordExpiration]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [pwdAttribute]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [authorizedService]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [accountExpires]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [userAccountControl]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (7): Requesting attrs: [nsAccountLock]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_step] (8): ldap_search_ext called, msgid = 5
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_connect_done] (9): caching successful connection after 1 notifies
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [be_run_online_cb] (3): Going online. Running callbacks.
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[0x1564c40], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[0x1564c40], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_parse_entry] (9): OriginalDN: [uid=admin,cn=users,cn=accounts,dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[0x1564c40], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_generic_done] (7): Total count [0]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_users_process] (6): Search for users, returned 1 results.
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 0)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Save user
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Adding original DN [uid=admin,cn=users,cn=accounts,dc=lab,dc=eng,dc=pnq,dc=redhat,dc=com] to attributes of [admin].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Adding original memberOf attributes to [admin].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Original USN value is not available for [admin].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (7): Adding user principal [admin.PNQ.REDHAT.COM] to attributes of [admin].
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Adding [krbLastPwdChange]=[20111003080729Z] to user attributes.
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Adding [krbPasswordExpiration]=[20120101080729Z] to user attributes.
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (9): Adding [nsAccountLock]=[False] to user attributes.
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_user] (6): Storing info for user admin
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 1)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x1576630

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1576750

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0x1576750 "ltdb_timeout"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0x1576630 "ltdb_callback"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sysdb_search_user_by_name] (6): Error: 2 (No such file or directory)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 2)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x1577870

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1577990

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0x1577990 "ltdb_timeout"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0x1577870 "ltdb_callback"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sysdb_search_user_by_uid] (6): Error: 2 (No such file or directory)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 3)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x1579de0

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1579f00

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0x1579f00 "ltdb_timeout"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0x1579de0 "ltdb_callback"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 3)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): start ldb transaction (nesting: 3)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x1582f00

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x1582fb0

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Destroying timer event 0x1582fb0 "ltdb_timeout"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): tevent: Ending timer event 0x1582f00 "ltdb_callback"

(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 3)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_save_users] (9): User 0 processed!
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_get_users_process] (9): Saving 1 Users - Done
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_id_op_done] (9): releasing operation connection
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: sh[0x154f780], connected[1], ops[(nil)], ldap[0x1550810]
(Mon Oct  3 04:36:58 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Mon Oct  3 04:36:59 2011) [sssd[be[lab.eng.pnq.redhat.com]]] [delayed_online_authentication_callback] (5): Backend is online, starting delayed online authentication

Verified.
# rpm -qi sssd | head
Name        : sssd                         Relocations: (not relocatable)
Version     : 1.5.1                             Vendor: Red Hat, Inc.
Release     : 53.el6                        Build Date: Fri 30 Sep 2011 10:10:28 AM EDT
Install Date: Mon 03 Oct 2011 08:54:42 AM EDT      Build Host: hs20-bc2-3.build.redhat.com
Group       : Applications/System           Source RPM: sssd-1.5.1-53.el6.src.rpm
Size        : 3551489                          License: GPLv3+
Signature   : (none)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
URL         : http://fedorahosted.org/sssd/
Summary     : System Security Services Daemon

Comment 6 Jakub Hrozek 2011-10-26 16:35:14 UTC

    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
Cause: The IPA provider internally constructs an LDAP URI based on what the host name specified in ipa_server parameter resolves to. However, when the host name resolved to an IPv6 address, the LDAP URI routines returned an error
Consequence: The IPA provider was unable to function correctly in an IPv6 environment
Fix: The IPA provider escapes all IPv6 addresses so that they can be consumed by the LDAP routines correctly
Result: The IPA provider is able to function in an IPv6 environment

Comment 7 errata-xmlrpc 2011-12-06 16:38:35 UTC

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-2011-1529.html