[Freeipa-users] FreeIPA - AD trust - SSH Public Keys

Taras Drach tsdrach at gmail.com
Fri Nov 4 11:41:40 UTC 2016


Hello Sumit,
I’ve tried to use this attr, but still no success

Also I found the solutions where sss_ssh_authorizedkeys replaced with custom scripts for queuing ldap and get necessary attribute
I think there is hardcoded “sshPublicKey" in sss_ssh_authorizedkeys. 
Is there any other way to create some kind of mapping in IPA for this attribute? 
I see that AD attribute requested and printed its content in the log, but still sss_ssh_authorizedkeys did not print this key to stdout

Full trace of 
sss_ssh_authorizedkeys -d test.loc rr
==
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_get_account_info] (0x0200): Got request for [0x1][1][name=rr]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_req_set_domain] (0x0400): Changing request domain from [ipa.test.loc] to [test.loc]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ipa_get_ad_override_connect_done] (0x4000): Searching for overrides in view [Default Trust View] with filter [(&(objectClass=ipaUserOverride)(uid=rr))].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_print_server] (0x2000): Searching 10.100.0.4
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaUserOverride)(uid=rr))][cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 6
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_add] (0x2000): New operation 6 timeout 60
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de1415190], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_destructor] (0x2000): Operation 6 finished
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ipa_get_ad_override_done] (0x4000): No override found with filter [(&(objectClass=ipaUserOverride)(uid=rr))].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ipa_srv_ad_acct_lookup_step] (0x0400): Looking up AD account
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_step] (0x4000): beginning to connect
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [get_server_status] (0x1000): Status of server 'dc01.test.loc' is 'working'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc01.test.loc' is 'working'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolve_srv_send] (0x0200): The status of SRV lookup is expired
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [collapse_srv_lookup] (0x0100): Need to refresh SRV lookup for domain Default-First-Site-Name._sites.test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[(nil)], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_getsrv_done] (0x1000): Using TTL [600]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [request_watch_destructor] (0x0400): Deleting request watch
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_srv_done] (0x0400): Got answer. Processing...
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_srv_done] (0x0400): Got 1 servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_get_dc_servers_done] (0x0400): Found 1 domain controllers in domain test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_connect_host_send] (0x0400): Resolving host dc01.test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_is_address] (0x4000): [dc01.test.loc] does not look like an IP address
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc01.test.loc' in files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc01.test.loc' in files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_step] (0x2000): Querying DNS
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc01.test.loc' in DNS
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [request_watch_destructor] (0x0400): Deleting request watch
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://dc01.test.loc:389
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sss_ldap_init_send] (0x4000): Using file descriptor [27] for LDAP connection.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc01.test.loc:389/??base] with fd [27].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://dc01.test.loc:389
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_print_server] (0x2000): Searching 10.100.0.148
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=test.loc)(NtVer=\14\00\00\00))][].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_add] (0x2000): New operation 1 timeout 6
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1417710], connected[1], ops[0x7f0de1411070], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1417710], connected[1], ops[0x7f0de1411070], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_destructor] (0x2000): Operation 1 finished
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_handle_release] (0x2000): Trace: sh[0x7f0de1417710], connected[1], ops[(nil)], ldap[0x7f0de13fc080], destructor_lock[0], release_memory[0]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [remove_connection_callback] (0x4000): Successfully removed connection callback.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_get_client_site_done] (0x0400): Found site: Default-First-Site-Name
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_servers_send] (0x0400): Looking up primary servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'Default-First-Site-Name._sites.test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.Default-First-Site-Name._sites.test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_getsrv_done] (0x1000): Using TTL [600]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [request_watch_destructor] (0x0400): Deleting request watch
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_srv_done] (0x0400): Got answer. Processing...
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_srv_done] (0x0400): Got 1 servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_getsrv_done] (0x1000): Using TTL [600]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [request_watch_destructor] (0x0400): Deleting request watch
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_srv_done] (0x0400): Got answer. Processing...
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_discover_srv_done] (0x0400): Got 1 servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_srv_plugin_servers_done] (0x0400): Got 1 primary and 1 backup servers
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'dc01.test.loc:389' to service 'test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_add_server_to_list] (0x0400): Server 'dc01.test.loc:389' for service 'test.loc' is already present
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'test.loc' as 'resolved'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [get_server_status] (0x1000): Status of server 'dc01.test.loc' is 'name not resolved'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_is_address] (0x4000): [dc01.test.loc] does not look like an IP address
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'dc01.test.loc' in files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [set_server_common_status] (0x0100): Marking server 'dc01.test.loc' as 'resolving name'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_step] (0x2000): Querying files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'dc01.test.loc' in files
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_step] (0x2000): Querying DNS
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'dc01.test.loc' in DNS
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [request_watch_destructor] (0x0400): Deleting request watch
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [set_server_common_status] (0x0100): Marking server 'dc01.test.loc' as 'name resolved'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_resolve_server_process] (0x0200): Found address for server dc01.test.loc: [10.100.0.148] TTL 2108
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://dc01.test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://dc01.test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sss_ldap_init_send] (0x4000): Using file descriptor [27] for LDAP connection.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://dc01.test.loc:389/??base] with fd [27].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_print_server] (0x2000): Searching 10.100.0.148
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_add] (0x2000): New operation 1 timeout 6
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13fc730], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13fc730], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_destructor] (0x2000): Operation 1 finished
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_rootdse_done] (0x2000): Got rootdse
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 16849 (int: 16849)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [6]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/ipa42.ipa.test.loc, AWS.SLT.LOC, 86400)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'test.loc'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [get_server_status] (0x1000): Status of server 'dc01.test.loc' is 'name resolved'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [get_server_status] (0x1000): Status of server 'dc01.test.loc' is 'name resolved'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_resolve_server_process] (0x0200): Found address for server dc01.test.loc: [10.100.0.148] TTL 2108
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT...
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 57
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [31250]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [child_handler_setup] (0x2000): Signal handler set up for pid [31250]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[(nil)], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [write_pipe_handler] (0x0400): All data has been sent!
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [child_sig_handler] (0x1000): Waiting for child [31250].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [child_sig_handler] (0x0100): child [31250] finished successfully.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [read_pipe_handler] (0x0400): EOF received, client finished
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_AWS.SLT.LOC], expired on [1478344941]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1478259441
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: host/ipa42.ipa.test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_WORKING. Called from: src/providers/ldap/sdap_async_connection.c: sdap_cli_connect_recv: 2036
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'dc01.test.loc' as 'working'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [set_server_common_status] (0x0100): Marking server 'dc01.test.loc' as 'working'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ad_user_data_cmp] (0x1000): Comparing LDAP with LDAP
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'dc01.test.loc' as 'working'
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_done] (0x2000): Old USN: 16844, New USN: 16849
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [dc=test,dc=loc]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_print_server] (0x2000): Searching 10.100.0.148
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=rr)(objectclass=user)(sAMAccountName=*)(objectSID=*))][dc=test,dc=loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altSecurityIdentities]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_add] (0x2000): New operation 5 timeout 6
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [be_run_unconditional_online_cb] (0x0400): Running unconditional online callbacks.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=rr,CN=Users,DC=test,DC=loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [name]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [accountExpires]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [altSecurityIdentities]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://ForestDnsZones.test.loc/DC=ForestDnsZones,DC=test,DC=loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://DomainDnsZones.test.loc/DC=DomainDnsZones,DC=test,DC=loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_add_references] (0x1000): Additional References: ldap://test.loc/CN=Configuration,DC=test,DC=loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_destructor] (0x2000): Operation 5 finished
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [generic_ext_search_handler] (0x4000): Request included referrals which were ignored.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [generic_ext_search_handler] (0x4000):     Ref: ldap://ForestDnsZones.test.loc/DC=ForestDnsZones,DC=test,DC=loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [generic_ext_search_handler] (0x4000):     Ref: ldap://DomainDnsZones.test.loc/DC=DomainDnsZones,DC=test,DC=loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [generic_ext_search_handler] (0x4000):     Ref: ldap://test.loc/CN=Configuration,DC=test,DC=loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_search_user_process] (0x0400): Search for users, returned 1 results.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_search_user_process] (0x4000): Retrieved total 1 users
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x0400): Save user
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_primary_name] (0x0400): Processing object rr at test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x0400): Processing user rr at test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x1000): Mapping user [rr at test.loc] objectSID [S-1-5-21-237804563-1161820721-801220523-1106] to unix ID
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x2000): Adding originalDN [CN=rr,CN=Users,DC=test,DC=loc] to attributes of [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x0400): Original memberOf is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20161103142350.0Z] to attributes of [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x0400): Adding user principal [rr at SLT.LOC] to attributes of [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adAccountExpires [9223372036854775807] to attributes of [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [66048] to attributes of [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): authType is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): userCertificate is not available for [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding originalADsshPublicKey [ssh-rsa\20AAAAB3NzaC1yc2EAAAADAQABAAABAQDQydFCKx/r5idp3U0EY0fMJdu0eHNuIc6xvZudQJm/mbf3TflLNH+mj/Jr7yQaPj0C6z7V8my+D0f6JK1cCntxfhLQto92xUZhhKoLHVO34f5DhC5etqZ4EtaD6j9QuXYc5U8GovHgzmdH+JSeIOSpSqFzTkFR6sSmhjypfCDPCP8JKHxwI9LJvfgCRv0qKJBjELhUpZYUW3Mrcpp+bJcX8Iuz0QPDkO2VdqIcwapC+h6AhdH+Sm6PjG8FplH6/5SDlQ2LOVTnY4xMuS48RXzgtJImN+o7syrxjPTQU5/PWXiIH/Hawa6n75kREv6B4AHtQKxqDoxhNdzQ1+xiLs4H\20user at test.loc] to attributes of [rr at test.loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_user] (0x0400): Storing info for user rr at test.loc
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1434da0
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1434ed0
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1434da0 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1434ed0 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1434da0 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sysdb_search_by_name] (0x0400): No such entry
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1445110
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1435ae0
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1445110 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1435ae0 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1445110 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sysdb_search_by_name] (0x0400): No such entry
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de143b020
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de13f5b20
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de143b020 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de13f5b20 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de143b020 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sysdb_search_user_by_uid] (0x0400): No such entry
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1445690
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1444c50
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1445690 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1444c50 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1445690 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 3)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1440550
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1435c90
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1440550 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1435c90 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1440550 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 3)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1445d20
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de13f5b20
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1445d20 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de13f5b20 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1445d20 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_save_users] (0x4000): User 0 processed!
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_users_done] (0x4000): Saving 1 Users - Done
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_done] (0x4000): releasing operation connection
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de13fa1b0
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de13fa2e0
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de13fa1b0 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de13fa2e0 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de13fa1b0 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [apply_subdomain_homedir] (0x4000): Missing homedir of rr at test.loc.
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1419a10
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1435570
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1419a10 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1435570 "ltdb_timeout"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1419a10 "ltdb_callback"
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ipa_get_ad_override_connect_done] (0x4000): Searching for overrides in view [Default Trust View] with filter [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-237804563-1161820721-801220523-1106))].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_print_server] (0x2000): Searching 10.100.0.4
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-237804563-1161820721-801220523-1106))][cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 7
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_op_add] (0x2000): New operation 7 timeout 60
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de1411070], connected[1], ops[(nil)], ldap[0x7f0de13fc080]
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri Nov  4 11:22:21 2016) [sssd[be[ipa.test.loc]]] [ipa_subdom_reset_timeouts_cb] (0x4000): Resetting last_refreshed and disabled_until.
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de1415190], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_op_destructor] (0x2000): Operation 7 finished
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ipa_get_ad_override_done] (0x4000): No override found with filter [(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-237804563-1161820721-801220523-1106))].
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de13fa4e0
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1419d50
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de13fa4e0 "ltdb_callback"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1419d50 "ltdb_timeout"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de13fa4e0 "ltdb_callback"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_print_server] (0x2000): Searching 10.100.0.4
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [objectClass=ipaexternalgroup][dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 8
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_op_add] (0x2000): New operation 8 timeout 60
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [cn=ab,cn=groups,cn=compat,dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [gidNumber]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaAnchorUUID]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [cn]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [cn=Default SMB Group,cn=groups,cn=compat,dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [gidNumber]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaAnchorUUID]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [cn]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [cn=editors,cn=groups,cn=compat,dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [gidNumber]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaAnchorUUID]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [cn]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_entry] (0x1000): OriginalDN: [cn=admins,cn=groups,cn=compat,dc=ipa,dc=test,dc=loc].
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [gidNumber]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [ipaAnchorUUID]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [memberUid]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_parse_range] (0x2000): No sub-attributes for [cn]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[0x7f0de13eb710], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_op_destructor] (0x2000): Operation 8 finished
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ipa_get_ext_groups_done] (0x0400): [4] external groups found.
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1444a10
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de1444b40
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1444a10 "ltdb_callback"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de1444b40 "ltdb_timeout"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1444a10 "ltdb_callback"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f0de1444a10
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f0de14457f0
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Running timer event 0x7f0de1444a10 "ltdb_callback"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Destroying timer event 0x7f0de14457f0 "ltdb_timeout"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ldb] (0x4000): Ending timer event 0x7f0de1444a10 "ltdb_callback"
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [find_ipa_ext_memberships] (0x4000): SID [S-1-5-21-237804563-1161820721-801220523-1106] not found in ext group hash.
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [find_ipa_ext_memberships] (0x0400): No external groupmemberships found.
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [ipa_add_ext_groups_step] (0x4000): No external groups memberships found.
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success)
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: sh[0x7f0de13ebfe0], connected[1], ops[(nil)], ldap[0x7f0de13e8be0]
(Fri Nov  4 11:22:22 2016) [sssd[be[ipa.test.loc]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!


> On Nov 4, 2016, at 12:51 PM, Sumit Bose <sbose at redhat.com> wrote:
> 
> On Thu, Nov 03, 2016 at 05:23:06PM +0200, Taras Drach wrote:
>> Thank for reply,
>> 
>> Unfortunately sssd won’t start with this configuration
>> 
>> Here is part of log
>> 
>> (Thu Nov  3 15:16:40 2016) [sssd[be[ipa.test.loc]]] [sdap_extend_map] (0x0200): 1 extra attributes
>> (Thu Nov  3 15:16:40 2016) [sssd[be[ipa.test.loc]]] [sdap_extend_map] (0x0010): Attribute sshPublicKey (altSecurityIdentities in LDAP) is already used by SSSD, please choose a different cache name
> 
> Can you check if 
> 
>    ldap_user_extra_attrs = originalADsshPublicKey:altSecurityIdentities
> 
> works any better?
> 
> bye,
> Sumit
> 
>> (Thu Nov  3 15:16:40 2016) [sssd[be[ipa.test.loc]]] [load_backend_module] (0x0010): Error (1432158241) in module (ipa) initialization (sssm_ipa_id_init)!
>> (Thu Nov  3 15:16:40 2016) [sssd[be[ipa.test.loc]]] [be_process_init] (0x0010): fatal error initializing data providers
>> (Thu Nov  3 15:16:40 2016) [sssd[be[ipa.test.loc]]] [sbus_remove_watch] (0x2000): 0x7f8183df2640/0x7f8183df2420
>> 
>> Config changes:
>> 
>>   ldap_user_extra_attrs = sshPublicKey:altSecurityIdentities
>> #   ldap_user_extra_attrs = altSecurityIdentities:altSecurityIdentities
>>   ldap_user_ssh_public_key = altSecurityIdentities
>>   ldap_id_mapping = False
>> 
>>> On Nov 3, 2016, at 5:05 PM, Sumit Bose <sbose at redhat.com> wrote:
>>> 
>>> sshPublicKey:
>> 
> 
> 





More information about the Freeipa-users mailing list