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-larg...
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!