(Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][1][name=tbouillon@example.com] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_attach_req] (0x0400): DP Request [Account #1]: New request. Flags [0x0001]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_idmap_add_domain] (0x1000): Adding domain [S-1-5-21-295434276-257986190-2813935219] as slice [3747] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sysdb_idmap_store_mapping] (0x0100): Adding new ID mapping [child.example.com][S-1-5-21-295434276-257986190-2813935219][3747] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [get_port_status] (0x1000): Port status of port 0 for server '(no name)' is 'neutral' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is neutral (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain child.example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'child.example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.child.example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_srv_done] (0x0400): Got 2 servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_get_dc_servers_done] (0x0400): Found 2 domain controllers in domain child.example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_connect_host_send] (0x0400): Resolving host ff1pdc02.child.example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ff1pdc02.child.example.com' in files (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'ff1pdc02.child.example.com' in files (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'ff1pdc02.child.example.com' in DNS (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://ff1pdc02.child.example.com:389 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ff1pdc02.child.example.com:389/??base] with fd [30]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://ff1pdc02.child.example.com:389 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=child.example.com)(NtVer=\14\00\00\00))][]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_get_client_site_done] (0x0400): Found site: EuropeFF1 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_get_client_site_done] (0x0400): Found forest: example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_servers_send] (0x0400): Looking up primary servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'gc'. Will use DNS discovery domain 'EuropeFF1._sites.example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_gc._tcp.EuropeFF1._sites.example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_srv_done] (0x0400): Got 7 servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'gc'. Will use DNS discovery domain 'example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_gc._tcp.example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_discover_srv_done] (0x0400): Got 6 servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_srv_plugin_servers_done] (0x0400): Got 7 primary and 6 backup servers (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1pdc01.child.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1pdc02.child.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1prdc02.child.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1prdc01.child.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1gdc01.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1ldc02.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'ff1gdc02.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Server 'ff1pdc01.child.example.com:3268' for service 'AD_GC' is already present (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Server 'ff1pdc02.child.example.com:3268' for service 'AD_GC' is already present (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Server 'ff1ldc02.example.com:3268' for service 'AD_GC' is already present (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Inserted backup server 'ff1ldc01.example.com:3268' to service 'AD_GC' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Server 'ff1gdc01.example.com:3268' for service 'AD_GC' is already present (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_add_server_to_list] (0x0400): Server 'ff1gdc02.example.com:3268' for service 'AD_GC' is already present (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'AD_GC' as 'resolved' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [get_server_status] (0x1000): Status of server 'ff1pdc01.child.example.com' is 'name not resolved' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'ff1pdc01.child.example.com' in files (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [set_server_common_status] (0x0100): Marking server 'ff1pdc01.child.example.com' as 'resolving name' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'ff1pdc01.child.example.com' in files (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'ff1pdc01.child.example.com' in DNS (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [request_watch_destructor] (0x0400): Deleting request watch (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [set_server_common_status] (0x0100): Marking server 'ff1pdc01.child.example.com' as 'name resolved' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [be_resolve_server_process] (0x0200): Found address for server ff1pdc01.child.example.com: [10.189.1.161] TTL 3600 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://ff1pdc01.child.example.com' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://ff1pdc01.child.example.com:3268' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ff1pdc01.child.example.com:3268/??base] with fd [29]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [5] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, FF1PSPS01$, child.example.com, 86400) (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [get_server_status] (0x1000): Status of server 'ff1pdc02.child.example.com' is 'working' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [get_port_status] (0x1000): Port status of port 389 for server 'ff1pdc02.child.example.com' is 'working' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [get_server_status] (0x1000): Status of server 'ff1pdc02.child.example.com' is 'working' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [be_resolve_server_process] (0x0200): Found address for server ff1pdc02.child.example.com: [10.189.1.165] TTL 3600 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 48 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [write_pipe_handler] (0x0400): All data has been sent! (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [child_sig_handler] (0x1000): Waiting for child [7403]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [child_sig_handler] (0x0100): child [7403] finished successfully. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [read_pipe_handler] (0x0400): EOF received, client finished (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_child.example.com], expired on [1501724799] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1501689699 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: FF1PSPS01$ (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_set_port_status] (0x0100): Marking port 3268 of server 'ff1pdc01.child.example.com' as 'working' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [set_server_common_status] (0x0100): Marking server 'ff1pdc01.child.example.com' as 'working' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [fo_set_port_status] (0x0400): Marking port 3268 of duplicate server 'ff1pdc01.child.example.com' as 'working' (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [dc=example,dc=com] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=tbouillon)(objectclass=user)(sAMAccountName=*)(objectSID=*))][dc=example,dc=com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [be_run_online_cb] (0x0080): Going online. Running callbacks. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=Tristan Bouillon,OU=Users,OU=Europe,OU=Sites,dc=example,dc=com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_search_user_process] (0x0400): Search for users, returned 1 results. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Save user (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_primary_name] (0x0400): Processing object tbouillon (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Processing user tbouillon@example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x1000): Mapping user [tbouillon@example.com] objectSID [S-1-5-21-481120694-805105173-3562786754-5671] to unix ID (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Original memberOf is not available for [tbouillon@example.com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Adding user principal [tbouillon@example.com] to attributes of [tbouillon@example.com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Storing info for user tbouillon@example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sysdb_search_by_name] (0x0400): No such entry (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sysdb_store_user] (0x1000): User tbouillon@example.com does not exist. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sysdb_search_by_name] (0x0400): No such entry (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sysdb_search_user_by_uid] (0x0400): No such entry (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_req_done] (0x0400): DP Request [Account #1]: Request handler finished [0]: Success (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [_dp_req_recv] (0x0400): DP Request [Account #1]: Receiving request data. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1]: Finished. Success. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #1]: Returning [Success]: 0,0,Success (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:1::example.com:name=tbouillon@example.com] from reply table (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_req_destructor] (0x0400): DP Request [Account #1]: Request removed. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [ad_online_cb] (0x0400): The AD provider is online (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=tbouillon@example.com] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_attach_req] (0x0400): DP Request [Initgroups #2]: New request. Flags [0x0001]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [dc=example,dc=com] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=tbouillon)(objectclass=user)(objectSID=*))][dc=example,dc=com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=Tristan Bouillon,OU=Users,OU=Europe,OU=Sites,dc=example,dc=com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Save user (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_primary_name] (0x0400): Processing object tbouillon (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Processing user tbouillon@example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x1000): Mapping user [tbouillon@example.com] objectSID [S-1-5-21-481120694-805105173-3562786754-5671] to unix ID (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Original memberOf is not available for [tbouillon@example.com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Adding user principal [tbouillon@example.com] to attributes of [tbouillon@example.com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_save_user] (0x0400): Storing info for user tbouillon@example.com (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][CN=Tristan Bouillon,OU=Users,OU=Europe,OU=Sites,dc=example,dc=com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups] (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=Tristan Bouillon,OU=Users,OU=Europe,OU=Sites,dc=example,dc=com]. (Wed Aug 2 15:46:39 2017) [sssd[be[child.example.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set --- (Wed Aug 2 15:46:40 2017) [sssd[be[child.example.com]]] [dp_req_initgr_pp] (0x0400): Ordering NSS responder to update memory cache (Wed Aug 2 15:46:40 2017) [sssd[be[child.example.com]]] [dp_req_reply_list_success] (0x0400): DP Request [Initgroups #2]: Finished. Success. (Wed Aug 2 15:46:40 2017) [sssd[be[child.example.com]]] [dp_req_reply_std] (0x1000): DP Request [Initgroups #2]: Returning [Success]: 0,0,Success (Wed Aug 2 15:46:40 2017) [sssd[be[child.example.com]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:3:1::example.com:name=tbouillon@example.com] from reply table (Wed Aug 2 15:46:40 2017) [sssd[be[child.example.com]]] [dp_req_destructor] (0x0400): DP Request [Initgroups #2]: Request removed. (Wed Aug 2 15:46:40 2017) [sssd[be[child.example.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0