[Freeipa-users] FreeIPA - AD trust - SSH Public Keys
Sumit Bose
sbose at redhat.com
Fri Nov 4 14:25:27 UTC 2016
On Fri, Nov 04, 2016 at 01:41:40PM +0200, Taras Drach wrote:
> 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.
yes, sshPublicKey is hardcoded but originalADsshPublicKey should be
handled as well. I just found that there is a bug which prevents the ssh
responder to handle it as expected.
In general the attribute names in SSSD's cache are hardcoded. What is
configurable is which server side LDAP attributed is stored in a
specific cache attribute (all the ldap_user_* and ldap_group_*
attributes can be used for this.
ldap_user_extra_attrs is special to allow to stored arbitrary attributes
in the cache. But since the hardcoded cache attributes typically have
special use-cases they cannot be overridden, this is why you have seen
the error message with sshPublicKey. originalADsshPublicKey has some
special instal use-case as well, but currently it is not in the list of
attributes which is checked. Nevertheless there is the bug I mentioned
earlier which make the lookup fail as well.
The intended way to solve all this is to use "ldap_user_ssh_public_key =
altSecurityIdentities" which I expect to work in the case where the
client is joined directly to an AD domain. With IPA and trust this is
unfortunately a bit different. The ldap_user_ssh_public_key will only
change the attribute name for the IPA domain but not for the trusted AD
domain because options are not inherited by default. Additionally
changing the attribute name for the IPA domain will prevent SSSD from
reading the SSH keys stored in the IPA server. The proper solution would
be domain specific configuration options which is tracked by
https://fedorahosted.org/sssd/ticket/2599 .
Nevertheless I try to fix the bug I mentioned earlier and will prepare a
test-build with a fix at the beginning of the next week.
HTH
bye,
Sumit
> 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