Hi Justin,
Thanks for answering. Here is an instance where it has a mark_offline event (and everything that happens before it with the same time stamp.
(Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_async_sys_connect_timeout] (0x0100): The LDAP connection timed out (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_sys_connect_done] (0x0020): sdap_async_sys_connect request failed: [110]: Connection timed out. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_state_destructor] (0x0400): closing socket [24] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_sys_connect_done] (0x0020): sdap_async_connect_call request failed: [110]: Connection timed out. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_handle_release] (0x2000): Trace: sh[0x13d9300], connected[0], ops[(nil)], ldap[(nil)], destructor_lock[0], release_memory[0] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_NOT_WORKING. Called from: ../src/providers/ldap/sdap_async_connection.c: sdap_cli_connect_done: 1567 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_set_port_status] (0x0100): Marking port 3268 of server 'charity.encs.concordia.ca' as 'not working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_set_port_status] (0x0400): Marking port 3268 of duplicate server 'charity.encs.concordia.ca' as 'not working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD_GC' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-4.concordia.ca' is 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_port_status] (0x1000): Port status of port 3268 for server 'int-con-dc-4.concordia.ca' is 'neutral' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-4.concordia.ca' is 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x0200): Found address for server int-con-dc-4.concordia.ca: [132.205.123.31] TTL 86400 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://int-con-dc-4.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://int-con-dc-4.concordia.ca:3268' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_send] (0x4000): Using file descriptor [24] for LDAP connection. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://int-con-dc-4.concordia.ca:3268/??base] with fd [24]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_print_server] (0x2000): Searching 132.205.123.31 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[0x13e51e0], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[0x13e51e0], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[0x13e51e0], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 206406385 (int: 206406385) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, PERF-IMGLAB08$, CONCORDIA.CA, 86400) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-4.concordia.ca' is 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_port_status] (0x1000): Port status of port 389 for server 'int-con-dc-4.concordia.ca' is 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolve_srv_send] (0x0200): The status of SRV lookup is expired (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [collapse_srv_lookup] (0x0100): Need to refresh SRV lookup for domain Default-First-Site-Name._sites.concordia.ca (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_srv_plugin_send] (0x0400): About to find domain controllers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_get_dc_servers_send] (0x0400): Looking up domain controllers in domain concordia.ca (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[(nil)], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_srv_done] (0x0400): Got 5 servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_get_dc_servers_done] (0x0400): Found 5 domain controllers in domain concordia.ca (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_srv_plugin_dcs_done] (0x0400): About to locate suitable site (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_connect_host_send] (0x0400): Resolving host int-con-dc-2.concordia.ca (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_is_address] (0x4000): [int-con-dc-2.concordia.ca] does not look like an IP address (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_step] (0x2000): Querying files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'int-con-dc-2.concordia.ca' in files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_step] (0x2000): Querying files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'int-con-dc-2.concordia.ca' in files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'int-con-dc-2.concordia.ca' in DNS (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_connect_host_resolv_done] (0x0400): Connecting to ldap://int-con-dc-2.concordia.ca:389 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_send] (0x4000): Using file descriptor [27] for LDAP connection. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://int-con-dc-2.concordia.ca:389/??base] with fd [27]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_connect_host_done] (0x0400): Successful connection to ldap://int-con-dc-2.concordia.ca:389 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_print_server] (0x2000): Searching 132.205.123.22 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(DnsDomain=concordia.ca)(NtVer=\14\00\00\00))][]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [netlogon] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e4e00], connected[1], ops[0x13dc2e0], ldap[0x13dac70] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [netlogon] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e4e00], connected[1], ops[0x13dc2e0], ldap[0x13dac70] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_handle_release] (0x2000): Trace: sh[0x13e4e00], connected[1], ops[(nil)], ldap[0x13dac70], destructor_lock[0], release_memory[0] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_get_client_site_done] (0x0400): Found site: Default-First-Site-Name (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_srv_plugin_site_done] (0x0400): About to discover primary and backup servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_servers_send] (0x0400): Looking up primary servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'Default-First-Site-Name._sites.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.Default-First-Site-Name._sites.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_srv_done] (0x0400): Got 5 servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_servers_primary_done] (0x0400): Looking up backup servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain 'concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_getsrv_done] (0x1000): Using TTL [600] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_discover_srv_done] (0x0400): Got 5 servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_srv_plugin_servers_done] (0x0400): Got 5 primary and 5 backup servers (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'int-con-dc-5.concordia.ca:389' to service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'int-con-dc-3.concordia.ca:389' to service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'int-con-dc-1.concordia.ca:389' to service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'int-con-dc-2.concordia.ca:389' to service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'int-con-dc-4.concordia.ca:389' to service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Server 'int-con-dc-4.concordia.ca:389' for service 'AD' is already present (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Server 'int-con-dc-5.concordia.ca:389' for service 'AD' is already present (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Server 'int-con-dc-3.concordia.ca:389' for service 'AD' is already present (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Server 'int-con-dc-1.concordia.ca:389' for service 'AD' is already present (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_add_server_to_list] (0x0400): Server 'int-con-dc-2.concordia.ca:389' for service 'AD' is already present (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'AD' as 'resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-5.concordia.ca' is 'name not resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_is_address] (0x4000): [int-con-dc-5.concordia.ca] does not look like an IP address (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_step] (0x2000): Querying files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of 'int-con-dc-5.concordia.ca' in files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [set_server_common_status] (0x0100): Marking server 'int-con-dc-5.concordia.ca' as 'resolving name' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_step] (0x2000): Querying files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of 'int-con-dc-5.concordia.ca' in files (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_step] (0x2000): Querying DNS (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'int-con-dc-5.concordia.ca' in DNS (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_request_timeout] (0x2000): Scheduling a timeout of 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [schedule_timeout_watcher] (0x2000): Scheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unschedule_timeout_watcher] (0x4000): Unscheduling DNS timeout watcher (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolv_gethostbyname_dns_parse] (0x1000): Parsing an A reply (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [set_server_common_status] (0x0100): Marking server 'int-con-dc-5.concordia.ca' as 'name resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x0200): Found address for server int-con-dc-5.concordia.ca: [132.205.123.32] TTL 86400 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://int-con-dc-5.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_resolve_callback] (0x0100): Constructed GC uri 'ldap://int-con-dc-5.concordia.ca' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/pubconf/.krb5info_dummy_NhdMtd] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/pubconf/.krb5info_dummy_NhdMtd] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 50 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [29943] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_handler_setup] (0x2000): Signal handler set up for pid [29943] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_sig_handler] (0x1000): Waiting for child [29943]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_sig_handler] (0x0100): child [29943] finished successfully. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA], expired on [1485210908] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1485175808 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: PERF-IMGLAB08$ (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_WORKING. Called from: ../src/providers/ldap/sdap_async_connection.c: sdap_cli_connect_recv: 2052 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_set_port_status] (0x0100): Marking port 3268 of server 'int-con-dc-4.concordia.ca' as 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [set_server_common_status] (0x0100): Marking server 'int-con-dc-4.concordia.ca' as 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_set_port_status] (0x0400): Marking port 3268 of duplicate server 'int-con-dc-4.concordia.ca' as 'working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_id_op_connect_done] (0x2000): Old USN: 206405159, New USN: 206406385 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_id_op_connect_done] (0x4000): notify connected to op #1 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=concordia,DC=ca] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_print_server] (0x2000): Searching 132.205.123.31 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=man)(objectclass=user)(objectSID=*))][DC=concordia,DC=ca]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 5 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_add] (0x2000): New operation 5 timeout 6 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_id_op_connect_done] (0x4000): caching successful connection after 1 notifies (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[0x13db2b0], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_entry] (0x1000): OriginalDN: [CN=man,OU=People,DC=concordia,DC=ca]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [memberOf] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [name] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [uidNumber] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [gidNumber] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[0x13db2b0], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_destructor] (0x2000): Operation 5 finished (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_initgr_user] (0x4000): Storing the user (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x0400): Save user (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_primary_name] (0x0400): Processing object man (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x0400): Processing user man (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x1000): Mapping user [man] objectSID [S-1-5-21-2025429265-616249376-725345543-2599092] to unix ID (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x2000): Adding originalDN [CN=man,OU=People,DC=concordia,DC=ca] to attributes of [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x0400): Adding original memberOf attributes to [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20170114155523.0Z] to attributes of [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x0400): Adding user principal [man@CONCORDIA.CA] to attributes of [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [544] to attributes of [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): authType is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_attrs_add_ldap_attr] (0x2000): userCertificate is not available for [man]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_save_user] (0x0400): Storing info for user man (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 1) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x13e36c0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x13e3780 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x13e36c0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x13e3780 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x13e36c0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 2) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x13dd720 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x13e3600 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x13dd720 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x13e3600 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x13dd720 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 2) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [man] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x2408670 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x13e27b0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x2408670 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x13e27b0 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x2408670 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sysdb_remove_attrs] (0x2000): Removing attribute [homeDirectory] from [man] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x13e46c0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x2409650 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x13e46c0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x2409650 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x13e46c0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sysdb_remove_attrs] (0x2000): Removing attribute [loginShell] from [man] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x13e27b0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x240a6b0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x13e27b0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x240a6b0 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x13e27b0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adAccountExpires] from [man] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x24110b0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x13f1320 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x24110b0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x13f1320 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x24110b0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_initgr_user] (0x4000): Commit change (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x13e35e0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x13e36a0 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Running timer event 0x13e35e0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Destroying timer event 0x13e36a0 "ltdb_timeout" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ldb] (0x4000): Ending timer event 0x13e35e0 "ltdb_callback" (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_initgr_user] (0x4000): Process user's groups (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_id_op_connect_step] (0x4000): beginning to connect (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-5.concordia.ca' is 'name resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-5.concordia.ca' is 'name resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x0200): Found address for server int-con-dc-5.concordia.ca: [132.205.123.32] TTL 86400 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_send] (0x4000): Using file descriptor [26] for LDAP connection. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e7e30], connected[1], ops[(nil)], ldap[0x1389710] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://int-con-dc-5.concordia.ca:389/??base] with fd [26]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_rootdse_send] (0x4000): Getting rootdse (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_print_server] (0x2000): Searching 132.205.123.32 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 1 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_add] (0x2000): New operation 1 timeout 6 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e44f0], connected[1], ops[0x13de9f0], ldap[0x23fd560] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e44f0], connected[1], ops[0x13de9f0], ldap[0x23fd560] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_entry] (0x1000): OriginalDN: []. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [currentTime] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [subschemaSubentry] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [dsServiceName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [namingContexts] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [defaultNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [schemaNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [configurationNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [rootDomainNamingContext] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedControl] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPVersion] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedLDAPPolicies] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [highestCommittedUSN] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedSASLMechanisms] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [dnsHostName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [ldapServiceName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [serverName] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedCapabilities] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [isSynchronized] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [isGlobalCatalogReady] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [supportedExtension] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [forestFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_parse_range] (0x2000): No sub-attributes for [domainControllerFunctionality] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e44f0], connected[1], ops[0x13de9f0], ldap[0x23fd560] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_op_destructor] (0x2000): Operation 1 finished (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_rootdse_done] (0x2000): Got rootdse (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_rootdse_done] (0x2000): Skipping auto-detection of match rule (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_server_opts_from_rootdse] (0x4000): USN value: 193586616 (int: 193586616) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, PERF-IMGLAB08$, CONCORDIA.CA, 86400) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-5.concordia.ca' is 'name resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [get_server_status] (0x1000): Status of server 'int-con-dc-5.concordia.ca' is 'name resolved' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_resolve_server_process] (0x0200): Found address for server int-con-dc-5.concordia.ca: [132.205.123.32] TTL 86400 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 50 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [29944] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_handler_setup] (0x2000): Signal handler set up for pid [29944] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: sh[0x13e44f0], connected[1], ops[(nil)], ldap[0x23fd560] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_sig_handler] (0x1000): Waiting for child [29944]. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [child_sig_handler] (0x0100): child [29944] finished successfully. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA], expired on [1485210908] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_cli_auth_step] (0x1000): the connection will expire at 1485175808 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: PERF-IMGLAB08$ (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [ad_sasl_log] (0x0040): SASL: GSSAPI Error: An invalid name was supplied (Success) (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sasl_bind_send] (0x0020): ldap_sasl_bind failed (-2)[Local error] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sasl_bind_send] (0x0080): Extended failure message: [SASL(-1): generic failure: GSSAPI Error: An invalid name was supplied (Success)] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [_be_fo_set_port_status] (0x8000): Setting status: PORT_NOT_WORKING. Called from: ../src/providers/ldap/sdap_async_connection.c: sdap_cli_connect_recv: 2039 (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'int-con-dc-5.concordia.ca' as 'not working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'int-con-dc-5.concordia.ca' as 'not working' (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [sdap_handle_release] (0x2000): Trace: sh[0x13e44f0], connected[1], ops[(nil)], ldap[0x23fd560], destructor_lock[0], release_memory[0] (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [remove_connection_callback] (0x4000): Successfully removed connection callback. (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_mark_offline] (0x2000): Going offline! (Mon Jan 23 07:35:08 2017) [sssd[be[concordia.ca]]] [be_mark_offline] (0x2000): Enable check_if_online_ptask.
Thanks! Thomas ________________________________________ From: Justin Stephenson jstephen@redhat.com Sent: Thursday, January 26, 2017 4:26 PM To: End-user discussions about the System Security Services Daemon Subject: [SSSD-users] Re: SSSD - user id mapping
Hello,
This message below indicates SSSD may be in an offline state, this can happen for a number of different reasons.
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0100): Request processed. Returned 1,11,Fast reply - offline
Could you search the sssd_concordia.ca.log for text such as 'mark_offline'? Once found, the messages above this point in the logs should indicate why SSSD was set into an offline state.
Kind regards, Justin Stephenson
On 01/26/2017 12:21 PM, Thomas Beaudry wrote:
? Hi Everyone,
I am running into a problem with usernames disappearing (and being replaced by their uids). The prompt in the terminal also changes to "i have no name!@<HOST>"
Jakub suggested that it could be that the getgr* is failing for some reason
Here is the timestamp for when the error happens:
I have no name!@perf-imglab08:~$ date Wed Jan 18 17:22:19 EST 2017 I have no name!@perf-imglab08:~$ getent group 1234 I have no name!@perf-imglab08:~$ date Wed Jan 18 17:22:36 EST 2017
and here are my sssd logs:
*sssd.log*
(Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca (Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging nss (Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging pam (Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh (Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs (Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping (Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to ping (Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping (Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping (Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30 (Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping (Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca (Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging nss (Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging pam (Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh (Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs (Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping (Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping (Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping (Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to ping (Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30 (Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping (Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca (Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging nss (Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging pam (Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh (Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs (Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping (Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping (Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to ping (Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping (Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30 (Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping (Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca (Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging nss (Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging pam (Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh (Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs (Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping (Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping (Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to ping (Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping (Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30 (Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping
*sssd_concordia.ca.log*
(Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn: 0xaa5740 (Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn: 0xaa5740 (Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn: 0xaa5740 (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn: 0xaeeb80 (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0200): Got request for [0x1002][FAST BE_REQ_GROUP][1][idnumber=1234] (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0100): Request processed. Returned 1,11,Fast reply - offline (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_req_set_domain] (0x0400): Changing request domain from [concordia.ca] to [concordia.ca] (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn: 0xaeeb80 (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0200): Got request for [0x1002][FAST BE_REQ_GROUP][1][idnumber=1234] (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0100): Request processed. Returned 1,11,Fast reply - offline (Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_req_set_domain] (0x0400): Changing request domain from [concordia.ca] to [forestroot.concordia.montreal.qc.ca] (Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn: 0xaa5740 (Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
*ldap_child.log*
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x0400): ldap_child started. (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): context initialized (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): total buffer size: 50 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): got realm_str: CONCORDIA.CA (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): princ_str size: 14 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): got princ_str: PERF-IMGLAB08$ (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x0200): Will run as [0][0]. (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [privileged_krb5_setup] (0x2000): Kerberos context initialized (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): Kerberos context initialized (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [become_user] (0x0200): Trying to become user [0][0]. (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [become_user] (0x0200): Already user [0]. (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): Running as [0][0]. (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): getting TGT sync (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [CONCORDIA.CA] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [PERF-IMGLAB08$@CONCORDIA.CA] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.728189: Getting initial credentials for PERF-IMGLAB08$@CONCORDIA.CA (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.728262: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc, rc4-hmac, aes128-cts, aes256-cts (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.728291: Sending request (195 bytes) to CONCORDIA.CA (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.728317: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.729762: Sending initial UDP request to dgram 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.731123: Received answer (210 bytes) from dgram 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734046: Response was not from master KDC (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734082: Received error from KDC: -1765328359/Additional pre-authentication required (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734104: Processing preauth types: 16, 15, 19, 2 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734112: Selected etype info: etype aes256-cts, salt "CONCORDIA.CAhostperf-imglab08.concordia.ca", params "" (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734127: Retrieving PERF-IMGLAB08$@CONCORDIA.CA from MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734137: AS key obtained for encrypted timestamp: aes256-cts/FC36 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734161: Encrypted timestamp (for 1484778122.795789): plain 301AA011180F32303137303131383232323230325AA10502030C248D, encrypted 77571640DED5412F7668B68A1684793B574BFD047B5D9F7CC62D4197B088FB59018B3BB6E748E651507780452E6B4E8CC31F67FF4A31EEBD (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734168: Preauth module encrypted_timestamp (2) (real) returned: 0/Success (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734173: Produced preauth for next request: 2 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734189: Sending request (275 bytes) to CONCORDIA.CA (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.734196: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.735879: Sending initial UDP request to dgram 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.737712: Received answer (96 bytes) from dgram 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.739940: Response was not from master KDC (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.739968: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.739978: Request or response is too big for UDP; retrying with TCP (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.739986: Sending request (275 bytes) to CONCORDIA.CA (tcp only) (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.739996: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.741680: Initiating TCP connection to stream 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.742475: Sending TCP request to stream 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.744227: Received answer (1508 bytes) from stream 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.744240: Terminating TCP connection to stream 132.205.123.21:88 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745376: Response was not from master KDC (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745404: Processing preauth types: 19 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745412: Selected etype info: etype aes256-cts, salt "CONCORDIA.CAhostperf-imglab08.concordia.ca", params "" (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745419: Produced preauth for next request: (empty) (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745425: AS key determined by preauth: aes256-cts/FC36 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745450: Decrypted AS reply; session key is: aes256-cts/7A2A (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745455: FAST negotiation: unavailable (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745483: Initializing FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl with default princ PERF-IMGLAB08$@CONCORDIA.CA (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000): [25844] 1484778122.745537: Storing PERF-IMGLAB08$@CONCORDIA.CA -> krbtgt/CONCORDIA.CA@CONCORDIA.CA in FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000): Renaming [/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl] to [/var/lib/sss/db/ccache_CONCORDIA.CA] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [prepare_response] (0x0400): Building response for result [0] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [pack_buffer] (0x2000): response size: 60 (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA] (Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x0400): ldap_child completed successfully (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x0400): ldap_child started. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): context initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): total buffer size: 50 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): got realm_str: CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): princ_str size: 14 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): got princ_str: PERF-IMGLAB08$ (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x0200): Will run as [0][0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [privileged_krb5_setup] (0x2000): Kerberos context initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): Kerberos context initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [become_user] (0x0200): Trying to become user [0][0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [become_user] (0x0200): Already user [0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): Running as [0][0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): getting TGT sync (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [PERF-IMGLAB08$@CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.791179: Getting initial credentials for PERF-IMGLAB08$@CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.791382: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc, rc4-hmac, aes128-cts, aes256-cts (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.791490: Sending request (195 bytes) to CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.791569: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.793862: Sending initial UDP request to dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.795622: Received answer (210 bytes) from dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798139: Response was not from master KDC (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798175: Received error from KDC: -1765328359/Additional pre-authentication required (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798194: Processing preauth types: 16, 15, 19, 2 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798201: Selected etype info: etype aes256-cts, salt "CONCORDIA.CAhostperf-imglab08.concordia.ca", params "" (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798214: Retrieving PERF-IMGLAB08$@CONCORDIA.CA from MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798226: AS key obtained for encrypted timestamp: aes256-cts/FC36 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798251: Encrypted timestamp (for 1484778188.864327): plain 301AA011180F32303137303131383232323330385AA10502030D3047, encrypted D1207C76AB678F2BBC0336F2F2EE373DF28682250D27A98B1249180CF5319FC7199D6018C0A44399945C235ECF9B295704D6EAEC3F5FF5FD (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798259: Preauth module encrypted_timestamp (2) (real) returned: 0/Success (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798264: Produced preauth for next request: 2 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798278: Sending request (275 bytes) to CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.798286: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.799446: Sending initial UDP request to dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.801292: Received answer (96 bytes) from dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.803814: Response was not from master KDC (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.803836: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.803844: Request or response is too big for UDP; retrying with TCP (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.803850: Sending request (275 bytes) to CONCORDIA.CA (tcp only) (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.803858: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.805392: Initiating TCP connection to stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.806522: Sending TCP request to stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.808296: Received answer (1508 bytes) from stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.808314: Terminating TCP connection to stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809712: Response was not from master KDC (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809737: Processing preauth types: 19 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809747: Selected etype info: etype aes256-cts, salt "CONCORDIA.CAhostperf-imglab08.concordia.ca", params "" (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809755: Produced preauth for next request: (empty) (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809763: AS key determined by preauth: aes256-cts/FC36 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809790: Decrypted AS reply; session key is: aes256-cts/A0EB (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809796: FAST negotiation: unavailable (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809829: Initializing FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5 with default princ PERF-IMGLAB08$@CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000): [25873] 1484778188.809880: Storing PERF-IMGLAB08$@CONCORDIA.CA -> krbtgt/CONCORDIA.CA@CONCORDIA.CA in FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000): Renaming [/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5] to [/var/lib/sss/db/ccache_CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [prepare_response] (0x0400): Building response for result [0] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [pack_buffer] (0x2000): response size: 60 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x0400): ldap_child completed successfully (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x0400): ldap_child started. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): context initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): total buffer size: 50 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): got realm_str: CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): princ_str size: 14 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): got princ_str: PERF-IMGLAB08$ (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x0200): Will run as [0][0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [privileged_krb5_setup] (0x2000): Kerberos context initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): Kerberos context initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [become_user] (0x0200): Trying to become user [0][0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [become_user] (0x0200): Already user [0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): Running as [0][0]. (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): getting TGT sync (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [PERF-IMGLAB08$@CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [MEMORY:/etc/krb5.keytab] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.911434: Getting initial credentials for PERF-IMGLAB08$@CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.911637: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc, rc4-hmac, aes128-cts, aes256-cts (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.911713: Sending request (195 bytes) to CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.911787: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.914393: Sending initial UDP request to dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.915860: Received answer (210 bytes) from dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.918866: Response was not from master KDC (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.918976: Received error from KDC: -1765328359/Additional pre-authentication required (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919054: Processing preauth types: 16, 15, 19, 2 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919087: Selected etype info: etype aes256-cts, salt "CONCORDIA.CAhostperf-imglab08.concordia.ca", params "" (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919141: Retrieving PERF-IMGLAB08$@CONCORDIA.CA from MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919180: AS key obtained for encrypted timestamp: aes256-cts/FC36 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919280: Encrypted timestamp (for 1484778188.973670): plain 301AA011180F32303137303131383232323330385AA10502030EDB66, encrypted D33317E3C9292ABF582F8D1E389DF6A3B5FFABFC7E0420B45A45B610EFD80E1D9C19CE9AAE0D7959B44E0773747AC7B0DCB56C9DFBF97DA3 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919315: Preauth module encrypted_timestamp (2) (real) returned: 0/Success (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919337: Produced preauth for next request: 2 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919431: Sending request (275 bytes) to CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.919472: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.921847: Sending initial UDP request to dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.924168: Received answer (96 bytes) from dgram 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.927183: Response was not from master KDC (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.927216: Received error from KDC: -1765328332/Response too big for UDP, retry with TCP (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.927222: Request or response is too big for UDP; retrying with TCP (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.927227: Sending request (275 bytes) to CONCORDIA.CA (tcp only) (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.927234: Resolving hostname Int-con-dc-1.concordia.ca (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.928427: Initiating TCP connection to stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.929201: Sending TCP request to stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.931067: Received answer (1508 bytes) from stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.931080: Terminating TCP connection to stream 132.205.123.21:88 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932326: Response was not from master KDC (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932365: Processing preauth types: 19 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932374: Selected etype info: etype aes256-cts, salt "CONCORDIA.CAhostperf-imglab08.concordia.ca", params "" (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932380: Produced preauth for next request: (empty) (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932387: AS key determined by preauth: aes256-cts/FC36 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932409: Decrypted AS reply; session key is: aes256-cts/C509 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932415: FAST negotiation: unavailable (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932442: Initializing FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c with default princ PERF-IMGLAB08$@CONCORDIA.CA (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000): [25874] 1484778188.932486: Storing PERF-IMGLAB08$@CONCORDIA.CA -> krbtgt/CONCORDIA.CA@CONCORDIA.CA in FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000): Renaming [/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c] to [/var/lib/sss/db/ccache_CONCORDIA.CA] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unique_filename_destructor] (0x2000): Unlinking [/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unlink_dbg] (0x2000): File already removed: [/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [prepare_response] (0x0400): Building response for result [0] (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [pack_buffer] (0x2000): response size: 60 (Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA]
Any help would be greatly appreciated, I've been trying to solve this problem over the last 2 weeks to no success.
Thanks! Thomas
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
_______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org