Hello,
we are using hosts with CentOS 7.5 - physical and virtual. And we have three IPA server.
We are using Cadence CAD/EDA applications and we have a lot of simulations running.
After a while we have two problems:
- login is very slow
- access of NFS mounted data and applications is slow
This happens normally after two or more weeks.
After a reboot everything is ok again.
This problems occurs not on all hosts at the same time, so the other hosts are ok, when some hosts have this problems.
Here i will ask for my login problem:
Her comes a debug output from sssd:
I am using "ssh hostname".
#… (deleted) (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [sysdb_set_entry_attr] (0x0200): Entry [name=habicht@imsmx.intern,cn=users,cn=imsmx.intern,cn=sysdb] has set [ts_cache] attrs. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [check_wait_queue] (0x1000): Wait queue for user [habicht@imsmx.intern] is empty. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [krb5_auth_queue_done] (0x1000): krb5_auth_queue request [0x55d411a08150] done. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_req_done] (0x0400): DP Request [PAM Preauth #28]: Request handler finished [0]: Success (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [_dp_req_recv] (0x0400): DP Request [PAM Preauth #28]: Receiving request data. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): DP Request [PAM Preauth #28]: Request removed. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_method_enabled] (0x0400): Target selinux is not configured (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_pam_reply] (0x1000): DP Request [PAM Preauth #28]: Sending result [0][imsmx.intern] ### ### Doing Return after entry of password - first debug output at first 30:37 ### (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): dbus conn: 0x55d4119e04e0 (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=habicht@imsmx.intern] (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sss_domain_get_state] (0x1000): Domain imsmx.intern is Active (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55d4119fedf0
(Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55d4119f85b0
(Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Running timer event 0x55d4119fedf0 „ltdb_callback" #… (deleted) (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [hbac_evaluate] (0x0100): ALLOWED by rule [allow_all]. (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [hbac_evaluate] (0x0100): hbac_evaluate() >] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [ipa_hbac_evaluate_rules] (0x0080): Access granted by HBAC rule [allow_all] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_req_done] (0x0400): DP Request [PAM Account #31]: Request handler finished [0]: Success (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [_dp_req_recv] (0x0400): DP Request [PAM Account #31]: Receiving request data. (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): DP Request [PAM Account #31]: Request removed. (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_method_enabled] (0x0400): Target selinux is not configured (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_pam_reply] (0x1000): DP Request [PAM Account #31]: Sending result [0][imsmx.intern] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: sh[0x55d411a00330], connected[1], ops[(nil)], ldap[0x55d4119e4300] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ### ### Between last 30:38 and first 31:03 no debug output appears ### (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): dbus conn: 0x55d4119e04e0 (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=habicht@imsmx.intern] (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sss_domain_get_state] (0x1000): Domain imsmx.intern is Active (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55d411a054c0 #… (deleted) (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Running timer event 0x55d4119fedf0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Destroying timer event 0x55d411a0bee0 "ltdb_timeout"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Ending timer event 0x55d4119fedf0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55d4119f85b0
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55d4119fedf0
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Running timer event 0x55d4119f85b0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Destroying timer event 0x55d4119fedf0 "ltdb_timeout"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Ending timer event 0x55d4119f85b0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_done] (0x0400): DP Request [Account #35]: Request handler finished [0]: Success (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [_dp_req_recv] (0x0400): DP Request [Account #35]: Receiving request data. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #35]: Finished. Success. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_reply_std] (0x1000): DP Request [Account #35]: Returning [Success]: 0,0,Success (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::imsmx.intern:name=nnn@imsmx.intern] from reply table (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): DP Request [Account #35]: Request removed. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: sh[0x55d411a00330], connected[1], ops[(nil)], ldap[0x55d4119e4300] (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ### ### Prompt appears ###
Here i have to wait 59 seconds for a prompt. Sometimes it is longer. A look with tcpdump shows only traffic on LDAP-ports.
With ipa commands or ldapsearch i have no problems.
Any idea why my problem happens?
Thank you for any help.
Detlev
-- Detlev | Institut fuer Mikroelektronische Systeme Habicht | D-30167 Hannover +49 511 76219662 habicht@ims.uni-hannover.de --------+-------- Handy +49 172 5415752 ---------------------------
Well,
i found one info. This was helpful for my login problems:
When i delete the systemd entries in /etc/pam.d, my logins are working immediately fine.
For my NFS problems i have still no idea.
Detlev
-- Detlev | Institut fuer Mikroelektronische Systeme Habicht | D-30167 Hannover +49 511 76219662 habicht@ims.uni-hannover.de --------+-------- Handy +49 172 5415752 ---------------------------
Am 15.01.2020 um 14:39 schrieb Detlev Habicht via FreeIPA-users freeipa-users@lists.fedorahosted.org:
Hello,
we are using hosts with CentOS 7.5 - physical and virtual. And we have three IPA server.
We are using Cadence CAD/EDA applications and we have a lot of simulations running.
After a while we have two problems:
login is very slow
access of NFS mounted data and applications is slow
This happens normally after two or more weeks.
After a reboot everything is ok again.
This problems occurs not on all hosts at the same time, so the other hosts are ok, when some hosts have this problems.
Here i will ask for my login problem:
Her comes a debug output from sssd:
I am using "ssh hostname".
#… (deleted) (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [sysdb_set_entry_attr] (0x0200): Entry [name=habicht@imsmx.intern,cn=users,cn=imsmx.intern,cn=sysdb] has set [ts_cache] attrs. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [check_wait_queue] (0x1000): Wait queue for user [habicht@imsmx.intern] is empty. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [krb5_auth_queue_done] (0x1000): krb5_auth_queue request [0x55d411a08150] done. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_req_done] (0x0400): DP Request [PAM Preauth #28]: Request handler finished [0]: Success (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [_dp_req_recv] (0x0400): DP Request [PAM Preauth #28]: Receiving request data. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): DP Request [PAM Preauth #28]: Request removed. (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_method_enabled] (0x0400): Target selinux is not configured (Wed Jan 15 13:30:02 2020) [sssd[be[imsmx.intern]]] [dp_pam_reply] (0x1000): DP Request [PAM Preauth #28]: Sending result [0][imsmx.intern] ### ### Doing Return after entry of password - first debug output at first 30:37 ### (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): dbus conn: 0x55d4119e04e0 (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=habicht@imsmx.intern] (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [sss_domain_get_state] (0x1000): Domain imsmx.intern is Active (Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55d4119fedf0
(Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55d4119f85b0
(Wed Jan 15 13:30:37 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Running timer event 0x55d4119fedf0 „ltdb_callback" #… (deleted) (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [hbac_evaluate] (0x0100): ALLOWED by rule [allow_all]. (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [hbac_evaluate] (0x0100): hbac_evaluate() >] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [ipa_hbac_evaluate_rules] (0x0080): Access granted by HBAC rule [allow_all] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_req_done] (0x0400): DP Request [PAM Account #31]: Request handler finished [0]: Success (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [_dp_req_recv] (0x0400): DP Request [PAM Account #31]: Receiving request data. (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): DP Request [PAM Account #31]: Request removed. (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_method_enabled] (0x0400): Target selinux is not configured (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [dp_pam_reply] (0x1000): DP Request [PAM Account #31]: Sending result [0][imsmx.intern] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: sh[0x55d411a00330], connected[1], ops[(nil)], ldap[0x55d4119e4300] (Wed Jan 15 13:30:38 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ### ### Between last 30:38 and first 31:03 no debug output appears ### (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): dbus conn: 0x55d4119e04e0 (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=habicht@imsmx.intern] (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sss_domain_get_state] (0x1000): Domain imsmx.intern is Active (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55d411a054c0 #… (deleted) (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Running timer event 0x55d4119fedf0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Destroying timer event 0x55d411a0bee0 "ltdb_timeout"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Ending timer event 0x55d4119fedf0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55d4119f85b0
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x55d4119fedf0
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Running timer event 0x55d4119f85b0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Destroying timer event 0x55d4119fedf0 "ltdb_timeout"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): Ending timer event 0x55d4119f85b0 "ltdb_callback"
(Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_done] (0x0400): DP Request [Account #35]: Request handler finished [0]: Success (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [_dp_req_recv] (0x0400): DP Request [Account #35]: Receiving request data. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #35]: Finished. Success. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_reply_std] (0x1000): DP Request [Account #35]: Returning [Success]: 0,0,Success (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::imsmx.intern:name=nnn@imsmx.intern] from reply table (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): DP Request [Account #35]: Request removed. (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: sh[0x55d411a00330], connected[1], ops[(nil)], ldap[0x55d4119e4300] (Wed Jan 15 13:31:03 2020) [sssd[be[imsmx.intern]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list ### ### Prompt appears ###
Here i have to wait 59 seconds for a prompt. Sometimes it is longer. A look with tcpdump shows only traffic on LDAP-ports.
With ipa commands or ldapsearch i have no problems.
Any idea why my problem happens?
Thank you for any help.
Detlev
-- Detlev | Institut fuer Mikroelektronische Systeme Habicht | D-30167 Hannover +49 511 76219662 habicht@ims.uni-hannover.de --------+-------- Handy +49 172 5415752 ---------------------------
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahoste...
freeipa-users@lists.fedorahosted.org
-
Detlev Habicht