==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[40951]. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [get_client_cred] (0x0080): The following failure is expected to happen in case SELinux is disabled: SELINUX_getpeercon failed [92][Protocol not available]. Please, consider enabling SELinux in your system. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x55f3afb57a40][21] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [accept_fd_handler] (0x0400): Client connected! (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #585: Setting "User by name" plugin (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #585: New request 'User by name' (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #585: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #585: Setting name [myuser] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #585: Performing a single domain search (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #585: Search will check the cache and check the data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #585: Using domain [domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #585: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #585: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #585: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #585: [myuser@domain.acme.com] is not present in negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3afb588c0 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3afb58980 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Running timer event 0x55f3afb588c0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Destroying timer event 0x55f3afb58980 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x55f3afb588c0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Object [myuser@domain.acme.com] was not found in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request for [0x55f3adcd5f00:1:myuser@domain.acme.com@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request for [domain.acme.com][0x1][BE_REQ_USER][name=myuser@domain.acme.com:-] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x55f3afb4ca30 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering request [0x55f3adcd5f00:1:myuser@domain.acme.com@domain.acme.com] ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x55b6a51cc380 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_attach_req] (0x0400): DP Request [Account #31]: New request. Flags [0x0001]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_get_ad_override_connect_done] (0x4000): Searching for overrides in view [Default Trust View] with filter [(&(objectClass=ipaUserOverride)(uid=myuser))]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_print_server] (0x2000): Searching 172.18.181.132:389 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectClass=ipaUserOverride)(uid=myuser))][cn=Default Trust View,cn=views,cn=accounts,dc=ipa,dc=domain,dc=acme,dc=com]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 9 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_add] (0x2000): New operation 9 timeout 30 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[0x55b6a51d8680], ldap[0x55b6a51cb9c0] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_destructor] (0x2000): Operation 9 finished (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_get_ad_override_done] (0x4000): No override found with filter [(&(objectClass=ipaUserOverride)(uid=myuser))]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [myuser] to IPA server (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 10 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_add] (0x2000): New operation 10 timeout 30 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[0x55b6a51f5410], ldap[0x55b6a51cb9c0] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[0x55b6a51f5410], ldap[0x55b6a51cb9c0] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_EXTENDED] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: No such object(32), (null). (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_destructor] (0x2000): Operation 10 finished (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_done] (0x4000): releasing operation connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_done] (0x0400): DP Request [Account #31]: Request handler finished [0]: Success (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [_dp_req_recv] (0x0400): DP Request [Account #31]: Receiving request data. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #31]: Finished. Success. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #31]: Returning [Success]: 0,0,Success (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::domain.acme.com:name=myuser@domain.acme.com] from reply table (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_destructor] (0x0400): DP Request [Account #31]: Request removed. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x55f3afb4ca30 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn: 0x55f3afb46f40 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in cache ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[(nil)], ldap[0x55b6a51cb9c0] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ==> /var/log/sssd/sssd_nss.log <== ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3afb591c0 ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3afb59280 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Running timer event 0x55f3afb591c0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Destroying timer event 0x55f3afb59280 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x55f3afb591c0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Object [myuser@domain.acme.com] was not found in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache_add_to_domain] (0x0400): CR #585: Adding [myuser@domain.acme.com] to negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/domain.acme.com/myuser@domain.acme.com] to negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #585: Setting "User by UPN" plugin (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #585: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #585: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #585: Performing a multi-domain search (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #585: Search will check the cache and check the data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #585: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #585: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #585: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #585: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #585: [myuser@domain.acme.com] is not present in negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3afb59260 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3afb59320 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Running timer event 0x55f3afb59260 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Destroying timer event 0x55f3afb59320 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x55f3afb59260 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Object [myuser@domain.acme.com] was not found in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request for [0x55f3adcd5f00:1:myuser@domain.acme.com:U@ipa.domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request for [ipa.domain.acme.com][0x1][BE_REQ_USER][name=myuser@domain.acme.com:U] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x55f3afb45850 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering request [0x55f3adcd5f00:1:myuser@domain.acme.com:U@ipa.domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x55f3adcd5f00:1:myuser@domain.acme.com@domain.acme.com] ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x55b6a51cc380 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_attach_req] (0x0400): DP Request [Account #32]: New request. Flags [0x0001]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_search_user_next_base] (0x0400): Searching for users with base [cn=accounts,dc=ipa,dc=domain,dc=acme,dc=com] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_print_server] (0x2000): Searching 172.18.181.132:389 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(|(krbPrincipalName=myuser@domain.acme.com)(mail=myuser@domain.acme.com)(krbPrincipalName=myuser\\@domain.acme.com@IPA.domain.acme.com))(objectclass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=ipa,dc=domain,dc=acme,dc=com]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaUniqueID] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaNTSecurityIdentifier] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaUserAuthType] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userCertificate;binary] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [mail] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 11 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_add] (0x2000): New operation 11 timeout 30 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[0x55b6a51f1360], ldap[0x55b6a51cb9c0] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_destructor] (0x2000): Operation 11 finished (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_search_user_process] (0x0400): Search for users, returned 0 results. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_search_user_process] (0x2000): Retrieved total 0 users (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_done] (0x4000): releasing operation connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55b6a51e6570 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55b6a51e6630 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Running timer event 0x55b6a51e6570 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Destroying timer event 0x55b6a51e6630 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Ending timer event 0x55b6a51e6570 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sysdb_search_by_name] (0x0400): No such entry (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sysdb_cache_search_groups] (0x2000): Search groups with filter: (&(objectCategory=group)(ghost=myuser@domain.acme.com)) (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55b6a5219b40 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55b6a51fa180 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Running timer event 0x55b6a5219b40 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Destroying timer event 0x55b6a51fa180 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Ending timer event 0x55b6a5219b40 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sysdb_cache_search_groups] (0x2000): No such entry (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sysdb_delete_user] (0x0400): Error: 2 (No such file or directory) (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55b6a51e60e0 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55b6a5219b40 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Running timer event 0x55b6a51e60e0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Destroying timer event 0x55b6a5219b40 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ldb] (0x4000): Ending timer event 0x55b6a51e60e0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sysdb_search_user_by_upn] (0x0400): No entry with upn [myuser@domain.acme.com] found. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_id_get_account_info_orig_done] (0x0080): Object not found, ending request (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_done] (0x0400): DP Request [Account #32]: Request handler finished [0]: Success (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [_dp_req_recv] (0x0400): DP Request [Account #32]: Receiving request data. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #32]: Finished. Success. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #32]: Returning [Success]: 0,0,Success (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:U:ipa.domain.acme.com:name=myuser@domain.acme.com] from reply table (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_destructor] (0x0400): DP Request [Account #32]: Request removed. ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x55f3afb45850 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn: 0x55f3afb46f40 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching. ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[(nil)], ldap[0x55b6a51cb9c0] ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3afb58e30 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3afb58ef0 ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Running timer event 0x55f3afb58e30 "ltdb_callback" ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== ==> /var/log/sssd/sssd_nss.log <== ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Destroying timer event 0x55f3afb58ef0 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x55f3afb58e30 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Object [myuser@domain.acme.com] was not found in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache_add_to_domain] (0x0400): CR #585: Adding [myuser@domain.acme.com] to negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] to negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #585: Using domain [domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #585: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #585: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #585: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #585: [myuser@domain.acme.com] is not present in negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3afb58af0 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3afb59430 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Running timer event 0x55f3afb58af0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Destroying timer event 0x55f3afb59430 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x55f3afb58af0 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Object [myuser@domain.acme.com] was not found in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request for [0x55f3adcd5f00:1:myuser@domain.acme.com:U@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request for [domain.acme.com][0x1][BE_REQ_USER][name=myuser@domain.acme.com:U] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x55f3afb56e20 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering request [0x55f3adcd5f00:1:myuser@domain.acme.com:U@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x55f3adcd5f00:1:myuser@domain.acme.com:U@ipa.domain.acme.com] ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_dispatch] (0x4000): dbus conn: 0x55b6a51cc380 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][name=myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_attach_req] (0x0400): DP Request [Account #33]: New request. Flags [0x0001]. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_attach_req] (0x0400): Number of active DP request: 1 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [myuser@domain.acme.com] to IPA server (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 12 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_add] (0x2000): New operation 12 timeout 30 (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[0x55b6a51d5d70], ldap[0x55b6a51cb9c0] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_EXTENDED] (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: No such object(32), (null). (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_op_destructor] (0x2000): Operation 12 finished (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_id_op_done] (0x4000): releasing operation connection (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_done] (0x0400): DP Request [Account #33]: Request handler finished [0]: Success (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [_dp_req_recv] (0x0400): DP Request [Account #33]: Receiving request data. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #33]: Finished. Success. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #33]: Returning [Success]: 0,0,Success (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:U:domain.acme.com:name=myuser@domain.acme.com] from reply table ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x55f3afb56e20 ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_destructor] (0x0400): DP Request [Account #33]: Request removed. (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn: 0x55f3afb46f40 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching. ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: sh[0x55b6a51e5060], connected[1], ops[(nil)], ldap[0x55b6a51cb9c0] ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success ==> /var/log/sssd/sssd_ipa.domain.acme.com.log <== (Mon Apr 29 18:14:17 2019) [sssd[be[ipa.domain.acme.com]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ==> /var/log/sssd/sssd_nss.log <== (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Looking up [myuser@domain.acme.com] in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f3afb58a50 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55f3afb58b10 (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Running timer event 0x55f3afb58a50 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Destroying timer event 0x55f3afb58b10 "ltdb_timeout" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x55f3afb58a50 "ltdb_callback" (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #585: Object [myuser@domain.acme.com] was not found in cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache_add_to_domain] (0x0400): CR #585: Adding [myuser@domain.acme.com] to negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/domain.acme.com/@myuser@domain.acme.com] to negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_global_ncache_add] (0x2000): CR #585: This request type does not support global negative cache (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #585: Finished: Not found (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x55f3adcd5f00:1:myuser@domain.acme.com:U@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[40953]. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [get_client_cred] (0x0080): The following failure is expected to happen in case SELinux is disabled: SELINUX_getpeercon failed [92][Protocol not available]. Please, consider enabling SELinux in your system. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x55f3afb40500][23] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [accept_fd_handler] (0x0400): Client connected! (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Mon Apr 29 18:14:17 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #586: Setting "User by name" plugin (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #586: New request 'User by name' (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #586: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #586: Setting name [myuser] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #586: Performing a single domain search (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #586: Search will check the cache and check the data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #586: Using domain [domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #586: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #586: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #586: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #586: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #586: Setting "User by UPN" plugin (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #586: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #586: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #586: Performing a multi-domain search (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #586: Search will check the cache and check the data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #586: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #586: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #586: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #586: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #586: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #586: Using domain [domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #586: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #586: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #586: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #586: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #586: Finished: Not found (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found (Mon Apr 29 18:14:17 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #587: Setting "User by name" plugin (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #587: New request 'User by name' (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #587: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #587: Setting name [myuser] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #587: Performing a single domain search (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #587: Search will check the cache and check the data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #587: Using domain [domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #587: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #587: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #587: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #587: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #587: Setting "User by UPN" plugin (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #587: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #587: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #587: Performing a multi-domain search (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #587: Search will check the cache and check the data provider (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #587: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #587: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #587: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #587: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #587: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #587: Using domain [domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #587: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #587: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #587: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #587: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:17 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #587: Finished: Not found (Mon Apr 29 18:14:17 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:17 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found (Mon Apr 29 18:14:26 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #588: Setting "User by name" plugin (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #588: New request 'User by name' (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #588: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #588: Setting name [myuser] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #588: Performing a single domain search (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #588: Search will check the cache and check the data provider (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #588: Using domain [domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #588: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #588: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #588: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #588: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #588: Setting "User by UPN" plugin (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #588: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #588: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #588: Performing a multi-domain search (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #588: Search will check the cache and check the data provider (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #588: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #588: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #588: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #588: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #588: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #588: Using domain [domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #588: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #588: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #588: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #588: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #588: Finished: Not found (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found (Mon Apr 29 18:14:26 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #589: Setting "User by name" plugin (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #589: New request 'User by name' (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #589: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #589: Setting name [myuser] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #589: Performing a single domain search (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #589: Search will check the cache and check the data provider (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #589: Using domain [domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #589: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #589: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #589: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #589: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #589: Setting "User by UPN" plugin (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #589: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #589: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #589: Performing a multi-domain search (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #589: Search will check the cache and check the data provider (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #589: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #589: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #589: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #589: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #589: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #589: Using domain [domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #589: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #589: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #589: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #589: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:26 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #589: Finished: Not found (Mon Apr 29 18:14:26 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:26 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found (Mon Apr 29 18:14:28 2019) [sssd[nss]] [client_recv] (0x0200): Client disconnected! (Mon Apr 29 18:14:28 2019) [sssd[nss]] [client_close_fn] (0x2000): Terminated client [0x55f3afb40500][23] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[40963]. (Mon Apr 29 18:14:28 2019) [sssd[nss]] [get_client_cred] (0x0080): The following failure is expected to happen in case SELinux is disabled: SELINUX_getpeercon failed [92][Protocol not available]. Please, consider enabling SELinux in your system. (Mon Apr 29 18:14:28 2019) [sssd[nss]] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x55f3afb40500][23] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [accept_fd_handler] (0x0400): Client connected! (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1]. (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1]. (Mon Apr 29 18:14:28 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #590: Setting "User by name" plugin (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #590: New request 'User by name' (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #590: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #590: Setting name [myuser] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #590: Performing a single domain search (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #590: Search will check the cache and check the data provider (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #590: Using domain [domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #590: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #590: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #590: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #590: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #590: Setting "User by UPN" plugin (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #590: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #590: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #590: Performing a multi-domain search (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #590: Search will check the cache and check the data provider (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #590: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #590: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #590: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #590: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #590: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #590: Using domain [domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #590: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #590: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #590: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #590: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #590: Finished: Not found (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found (Mon Apr 29 18:14:28 2019) [sssd[nss]] [nss_getby_name] (0x0400): Input name: myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #591: Setting "User by name" plugin (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_send] (0x0400): CR #591: New request 'User by name' (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_process_input] (0x0400): CR #591: Parsing input name [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name 'myuser@domain.acme.com' matched expression for domain 'domain.acme.com', user is myuser (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #591: Setting name [myuser] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #591: Performing a single domain search (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain ipa.domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #591: Search will check the cache and check the data provider (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #591: Using domain [domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #591: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #591: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #591: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #591: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #591: Setting "User by UPN" plugin (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_name] (0x0400): CR #591: Setting name [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_assume_upn] (0x0400): CR #591: Assuming UPN [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #591: Performing a multi-domain search (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #591: Search will check the cache and check the data provider (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain ipa.domain.acme.com type POSIX is valid (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #591: Using domain [ipa.domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #591: Preparing input data for domain [ipa.domain.acme.com] rules (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #591: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #591: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/ipa.domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #591: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain domain.acme.com type POSIX is valid (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #591: Using domain [domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR #591: Preparing input data for domain [domain.acme.com] rules (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_send] (0x0400): CR #591: Looking up myuser@domain.acme.com (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #591: Checking negative cache for [myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/domain.acme.com/@myuser@domain.acme.com] (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #591: [myuser@domain.acme.com] does not exist (negative cache) (Mon Apr 29 18:14:28 2019) [sssd[nss]] [cache_req_process_result] (0x0400): CR #591: Finished: Not found (Mon Apr 29 18:14:28 2019) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain domain.acme.com is Active (Mon Apr 29 18:14:28 2019) [sssd[nss]] [nss_protocol_done] (0x4000): Sending reply: not found ^C [root@freeipa-client ~]# tail /var/log/secure Apr 29 18:04:54 freeipa-client sshd[40434]: pam_unix(sshd:session): session opened for user root by (uid=0) Apr 29 18:14:17 freeipa-client sshd[40951]: Invalid user myuser@domain.acme.com from 172.18.181.46 port 51254 Apr 29 18:14:17 freeipa-client sshd[40951]: input_userauth_request: invalid user myuser@domain.acme.com [preauth] Apr 29 18:14:17 freeipa-client sshd[40951]: Postponed keyboard-interactive for invalid user myuser@domain.acme.com from 172.18.181.46 port 51254 ssh2 [preauth] Apr 29 18:14:26 freeipa-client sshd[40953]: pam_unix(sshd:auth): check pass; user unknown Apr 29 18:14:26 freeipa-client sshd[40953]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=some-server.domain.acme.com Apr 29 18:14:28 freeipa-client sshd[40951]: error: PAM: User not known to the underlying authentication module for illegal user myuser@domain.acme.com from some-server.domain.acme.com Apr 29 18:14:28 freeipa-client sshd[40951]: Failed keyboard-interactive/pam for invalid user myuser@domain.acme.com from 172.18.181.46 port 51254 ssh2 Apr 29 18:14:28 freeipa-client sshd[40951]: Postponed keyboard-interactive for invalid user myuser@domain.acme.com from 172.18.181.46 port 51254 ssh2 [preauth] Apr 29 18:14:31 freeipa-client sshd[40951]: Connection closed by 172.18.181.46 port 51254 [preauth]