Thank you. When I was getting the SSSD logs it pointed me to an ID range error. I had adjusted the ID ranges as required but it turns out that sss_cache -E doesn't properly clear the SSSD cache. After I deleted the cache files and restarted SSSD I was able to add the global group to an external group properly.
However, these users can now authenticate against the IdM servers without issue ( provided HBAC is applied ), but not to any clients for some reason. debug level 6 SSSD log from a client I'm trying to log in to is below.
I applied the optimization settings from https://jhrozek.wordpress.com/2015/08/19/performance-tuning-sssd-for-large-i... I set the timeouts to 15 seconds, any longer and I simply time out prior to getting a password prompt. Even with default timeouts it takes an extraordinarily long time to receive a password prompt now for servers that are part of an HBAC rule that has a posix group which contains an external group.
(Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=<MY USERNAME>@<AD DOMAIN>] (Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): DP Request [Initgroups #29]: New request. Flags [0x0001]. (Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaUserOverride)(uid=<MY USERNAME>))][cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=ipa,dc=ipa,dc=ipa]. (Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:15:37 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is expired (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [collapse_srv_lookup] (0x0100): Need to refresh SRV lookup for domain <IPA DOMAIN> (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain '<IPA DOMAIN>' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.<IPA DOMAIN>' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_discover_srv_done] (0x0400): Got 4 servers (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 1>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 2>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 3>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 4>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'IPA' as 'resolved' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of '<IdM Server 1>.<IPA DOMAIN>' in files (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 1>.<IPA DOMAIN>' as 'resolving name' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of '<IdM Server 1>.<IPA DOMAIN>' in files (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of '<IdM Server 1>.<IPA DOMAIN>' in DNS (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 1>.<IPA DOMAIN>' as 'name resolved' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 1>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 1>.<IPA DOMAIN>' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN>, <IPA DOMAIN>, 86400) (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 1>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 84 (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Aug 19 15:15:43 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0100): child [25667] finished successfully. (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_<IPA DOMAIN>], expired on [1566328544] (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN> (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 389 of server '<IdM Server 1>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 1>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server '<IdM Server 1>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:15:44 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of '<IdM Server 2>.<IPA DOMAIN>' in files (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 2>.<IPA DOMAIN>' as 'resolving name' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of '<IdM Server 2>.<IPA DOMAIN>' in files (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of '<IdM Server 2>.<IPA DOMAIN>' in DNS (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 2>.<IPA DOMAIN>' as 'name resolved' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 2>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 2>.<IPA DOMAIN>' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN>, <IPA DOMAIN>, 86400) (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 2>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 84 (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0100): child [25686] finished successfully. (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_<IPA DOMAIN>], expired on [1566328550] (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN> (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 389 of server '<IdM Server 2>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 2>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server '<IdM Server 2>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:15:50 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of '<IdM Server 3>.<IPA DOMAIN>' in files (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 3>.<IPA DOMAIN>' as 'resolving name' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of '<IdM Server 3>.<IPA DOMAIN>' in files (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of '<IdM Server 3>.<IPA DOMAIN>' in DNS (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 3>.<IPA DOMAIN>' as 'name resolved' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 3>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 3>.<IPA DOMAIN>' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN>, <IPA DOMAIN>, 86400) (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 3>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 84 (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0100): child [25694] finished successfully. (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_<IPA DOMAIN>], expired on [1566328556] (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN> (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 389 of server '<IdM Server 3>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 3>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server '<IdM Server 3>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:15:56 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of '<IdM Server 4>.<IPA DOMAIN>' in files (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 4>.<IPA DOMAIN>' as 'resolving name' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of '<IdM Server 4>.<IPA DOMAIN>' in files (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of '<IdM Server 4>.<IPA DOMAIN>' in DNS (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 4>.<IPA DOMAIN>' as 'name resolved' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 4>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 4>.<IPA DOMAIN>' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN>, <IPA DOMAIN>, 86400) (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 4>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 84 (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0100): child [25702] finished successfully. (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_<IPA DOMAIN>], expired on [1566328562] (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN> (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 389 of server '<IdM Server 4>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 4>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server '<IdM Server 4>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:16:02 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_id_op_done] (0x0200): communication error on cached connection, moving to next server (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 2>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 2>.<IPA DOMAIN>' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sssd_async_socket_init_send] (0x0400): Setting 6 seconds timeout for connecting (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(objectclass=*)][]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_kinit_send] (0x0400): Attempting kinit (default, host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN>, <IPA DOMAIN>, 86400) (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 2>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [create_tgt_req_send_buffer] (0x0400): buffer size: 84 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [set_tgt_child_timeout] (0x0400): Setting 6 seconds timeout for tgt child (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0100): child [25708] finished successfully. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_tgt_recv] (0x0400): Child responded: 0 [FILE:/var/lib/sss/db/ccache_<IPA DOMAIN>], expired on [1566328568] (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_auth_step] (0x0100): expire timeout is 900 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: GSSAPI, user: host/<HOST I'M ATTEMPTING TO LOG IN TO>.<IPA DOMAIN> (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_cli_connect_recv] (0x0400): Connection established. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 0 of server '<IdM Server 2>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 2>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server '<IdM Server 2>.<IPA DOMAIN>' as 'working' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): Received [22] groups in group list from IPA Server (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<MY USERNAME>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>n@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<POSIX group>s@<IPA DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<POSIX group>@<IPA DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_list_step] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for object [<MY USERNAME>@<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_list_next] (0x0400): Received [<MY USERNAME>@<AD DOMAIN>] attributes from IPA server. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_set_entry_attr] (0x0200): Entry [name=<MY USERNAME>@<AD DOMAIN>,cn=users,cn=<AD DOMAIN>,cn=sysdb] has set [ts_cache] attrs. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [get_groups_dns] (0x0400): sysdb_search_group_by_name failed with [2], generating DN for [<MY USERNAME>@<AD DOMAIN>] in domain [<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait from ldb_modify with LDB_WAIT_ALL: No such object (32)] (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0400): Error: 2 (No such file or directory) (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_update_members_ex] (0x0020): Could not add member [<MY USERNAME>@<AD DOMAIN>] to group [name=<MY USERNAME>@<AD DOMAIN>,cn=groups,cn=<AD DOMAIN>,cn=sysdb]. Skipping. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_set_entry_attr] (0x0200): Entry [name=<MY USERNAME>@<AD DOMAIN>,cn=users,cn=<AD DOMAIN>,cn=sysdb] has set [ts_cache] attrs. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [get_groups_dns] (0x0400): sysdb_search_group_by_name failed with [2], generating DN for [<MY USERNAME>@<AD DOMAIN>] in domain [<AD DOMAIN>]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait from ldb_modify with LDB_WAIT_ALL: No such object (32)] (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0400): Error: 2 (No such file or directory) (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_update_members_ex] (0x0020): Could not add member [<MY USERNAME>@<AD DOMAIN>] to group [name=<MY USERNAME>@<AD DOMAIN>,cn=groups,cn=<AD DOMAIN>,cn=sysdb]. Skipping. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_done] (0x0400): DP Request [Initgroups #29]: Request handler finished [0]: Success (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [_dp_req_recv] (0x0400): DP Request [Initgroups #29]: Receiving request data. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_initgr_pp_nss_notify] (0x0400): Ordering NSS responder to update memory cache (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_reply_list_success] (0x0400): DP Request [Initgroups #29]: Finished. Success. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:3::<AD DOMAIN>:name=<MY USERNAME>@<AD DOMAIN>] from reply table (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): DP Request [Initgroups #29]: Request removed. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_pam_handler] (0x0100): Got request with the following data (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): command: SSS_PAM_PREAUTH (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): domain: <AD DOMAIN> (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): user: <MY USERNAME>@<AD DOMAIN> (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): service: sshd (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): tty: ssh (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): ruser: (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): rhost: <MY WORKSTATION>.<AD DOMAIN> (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): authtok type: 0 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): priv: 1 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): cli_pid: 25661 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): logon name: not set (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): DP Request [PAM Preauth #30]: New request. Flags [0000]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 2>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 2>.<IPA DOMAIN>' (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): DP Request [AccountDomain #31]: New request. Flags [0000]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): Number of active DP request: 2 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_done] (0x0400): DP Request [AccountDomain #31]: Request handler finished [0]: Success (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [_dp_req_recv] (0x0400): DP Request [AccountDomain #31]: Receiving request data. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_reply_list_success] (0x0400): DP Request [AccountDomain #31]: Finished. Success. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_table_value_destructor] (0x0400): Removing [0:10:0000:0x55addac4b8f0] from reply table (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): DP Request [AccountDomain #31]: Request removed. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): Number of active DP request: 1 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_get_account_info_handler] (0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=3361432] (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): DP Request [Account #32]: New request. Flags [0x0001]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): Number of active DP request: 2 (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [cn=accounts,dc=ipa,dc=ipa,dc=ipa,dc=ipa] (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(gidNumber=3361432)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=ipa,dc=ipa,dc=ipa,dc=ipa]. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 0 results. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_group_by_gid] (0x0400): No such entry (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_delete_group] (0x0400): Error: 2 (No such file or directory) (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_group_by_gid] (0x0400): No such entry (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_id_get_account_info_orig_done] (0x0080): Object not found, ending request (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_done] (0x0400): DP Request [Account #32]: Request handler finished [0]: Success (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [_dp_req_recv] (0x0400): DP Request [Account #32]: Receiving request data. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #32]: Finished. Success. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:2::<IPA DOMAIN>:idnumber=3361432] from reply table (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): DP Request [Account #32]: Request removed. (Mon Aug 19 15:16:08 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): Number of active DP request: 1 (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_child_timeout] (0x0040): Timeout for child [25709] reached. In case KDC is distant or network is slow you may consider increasing value of krb5_auth_timeout. (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_auth_done] (0x0020): child timed out! (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_done] (0x0400): DP Request [PAM Preauth #30]: Request handler finished [0]: Success (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [_dp_req_recv] (0x0400): DP Request [PAM Preauth #30]: Receiving request data. (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): DP Request [PAM Preauth #30]: Request removed. (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Mon Aug 19 15:16:23 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0020): child [25709] was terminated by signal [9]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=<MY USERNAME>@<AD DOMAIN>] (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): DP Request [Initgroups #33]: New request. Flags [0x0001]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaUserOverride)(uid=<MY USERNAME>))][cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=ipa,dc=ipa,dc=ipa]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [<MY USERNAME>] to IPA server (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): Received [22] groups in group list from IPA Server (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<MY USERNAME>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>n@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<AD GROUP>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<POSIX group>s@<IPA DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_user_done] (0x0400): [<POSIX group>@<IPA DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_list_step] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for object [<MY USERNAME>@<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_exop_done] (0x0400): ldap_extended_operation result: Success(0), (null). (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_s2n_get_list_next] (0x0400): Received [<MY USERNAME>@<AD DOMAIN>] attributes from IPA server. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_set_entry_attr] (0x0200): Entry [name=<MY USERNAME>@<AD DOMAIN>,cn=users,cn=<AD DOMAIN>,cn=sysdb] has set [ts_cache] attrs. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [get_groups_dns] (0x0400): sysdb_search_group_by_name failed with [2], generating DN for [<MY USERNAME>@<AD DOMAIN>] in domain [<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait from ldb_modify with LDB_WAIT_ALL: No such object (32)] (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0400): Error: 2 (No such file or directory) (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_update_members_ex] (0x0020): Could not add member [<MY USERNAME>@<AD DOMAIN>] to group [name=<MY USERNAME>@<AD DOMAIN>,cn=groups,cn=<AD DOMAIN>,cn=sysdb]. Skipping. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_set_entry_attr] (0x0200): Entry [name=<MY USERNAME>@<AD DOMAIN>,cn=users,cn=<AD DOMAIN>,cn=sysdb] has set [ts_cache] attrs. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [get_groups_dns] (0x0400): sysdb_search_group_by_name failed with [2], generating DN for [<MY USERNAME>@<AD DOMAIN>] in domain [<AD DOMAIN>]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait from ldb_modify with LDB_WAIT_ALL: No such object (32)] (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_mod_group_member] (0x0400): Error: 2 (No such file or directory) (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [sysdb_update_members_ex] (0x0020): Could not add member [<MY USERNAME>@<AD DOMAIN>] to group [name=<MY USERNAME>@<AD DOMAIN>,cn=groups,cn=<AD DOMAIN>,cn=sysdb]. Skipping. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_done] (0x0400): DP Request [Initgroups #33]: Request handler finished [0]: Success (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [_dp_req_recv] (0x0400): DP Request [Initgroups #33]: Receiving request data. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_initgr_pp_nss_notify] (0x0400): Ordering NSS responder to update memory cache (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_reply_list_success] (0x0400): DP Request [Initgroups #33]: Finished. Success. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:3::<AD DOMAIN>:name=<MY USERNAME>@<AD DOMAIN>] from reply table (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): DP Request [Initgroups #33]: Request removed. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_pam_handler] (0x0100): Got request with the following data (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): domain: <AD DOMAIN> (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): user: <MY USERNAME>@<AD DOMAIN> (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): service: sshd (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): tty: ssh (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): ruser: (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): rhost: <MY WORKSTATION>.<AD DOMAIN> (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): authtok type: 1 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): priv: 1 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): cli_pid: 25661 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [pam_print_data] (0x0100): logon name: not set (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): DP Request [PAM Authenticate #34]: New request. Flags [0000]. (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 2>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:26 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_child_timeout] (0x0040): Timeout for child [25744] reached. In case KDC is distant or network is slow you may consider increasing value of krb5_auth_timeout. (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_auth_done] (0x0020): child timed out! (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 0 of server '<IdM Server 2>.<IPA DOMAIN>' as 'not working' (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 0 of duplicate server '<IdM Server 2>.<IPA DOMAIN>' as 'not working' (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [get_port_status] (0x0100): Resetting the status of port 389 for server '<IdM Server 1>.<IPA DOMAIN>' (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 1>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 1>.<IPA DOMAIN>' (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0020): waitpid did not found a child with changed status. (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0020): child [25744] was terminated by signal [9]. (Mon Aug 19 15:16:41 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_child_timeout] (0x0040): Timeout for child [25762] reached. In case KDC is distant or network is slow you may consider increasing value of krb5_auth_timeout. (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_auth_done] (0x0020): child timed out! (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 389 of server '<IdM Server 1>.<IPA DOMAIN>' as 'not working' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server '<IdM Server 1>.<IPA DOMAIN>' as 'not working' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [get_port_status] (0x0080): SSSD is unable to complete the full connection request, this internal status does not necessarily indicate network port issues. (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [get_port_status] (0x0100): Resetting the status of port 389 for server '<IdM Server 2>.<IPA DOMAIN>' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is expired (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [collapse_srv_lookup] (0x0100): Need to refresh SRV lookup for domain <IPA DOMAIN> (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_discover_srv_next_domain] (0x0400): SRV resolution of service 'ldap'. Will use DNS discovery domain '<IPA DOMAIN>' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_getsrv_send] (0x0100): Trying to resolve SRV record of '_ldap._tcp.<IPA DOMAIN>' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_discover_srv_done] (0x0400): Got answer. Processing... (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_discover_srv_done] (0x0400): Got 4 servers (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 3>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 4>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 1>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [fo_add_server_to_list] (0x0400): Inserted primary server '<IdM Server 2>.<IPA DOMAIN>:389' to service 'IPA' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_srv_data_status] (0x0100): Marking SRV lookup of service 'IPA' as 'resolved' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of '<IdM Server 3>.<IPA DOMAIN>' in files (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 3>.<IPA DOMAIN>' as 'resolving name' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0020): child [25762] was terminated by signal [9]. (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of '<IdM Server 3>.<IPA DOMAIN>' in files (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of '<IdM Server 3>.<IPA DOMAIN>' in DNS (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 3>.<IPA DOMAIN>' as 'name resolved' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 3>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 3>.<IPA DOMAIN>' (Mon Aug 19 15:16:56 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_child_timeout] (0x0040): Timeout for child [25794] reached. In case KDC is distant or network is slow you may consider increasing value of krb5_auth_timeout. (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [krb5_auth_done] (0x0020): child timed out! (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0100): Marking port 389 of server '<IdM Server 3>.<IPA DOMAIN>' as 'not working' (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server '<IdM Server 3>.<IPA DOMAIN>' as 'not working' (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve A record of '<IdM Server 4>.<IPA DOMAIN>' in files (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 4>.<IPA DOMAIN>' as 'resolving name' (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_files_send] (0x0100): Trying to resolve AAAA record of '<IdM Server 4>.<IPA DOMAIN>' in files (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of '<IdM Server 4>.<IPA DOMAIN>' in DNS (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [request_watch_destructor] (0x0400): Deleting request watch (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [set_server_common_status] (0x0100): Marking server '<IdM Server 4>.<IPA DOMAIN>' as 'name resolved' (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [child_sig_handler] (0x0020): child [25794] was terminated by signal [9]. (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [be_resolve_server_process] (0x0200): Found address for server <IdM Server 4>.<IPA DOMAIN>: [<IP>] TTL 1200 (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://<IdM Server 4>.<IPA DOMAIN>' (Mon Aug 19 15:17:11 2019) [sssd[be[<IPA DOMAIN>]]] [write_pipe_handler] (0x0400): All data has been sent!