Re: [Freeipa-users] Slow logins on one ipa client- due to SSS_PAM_ACCT_MGMT
Justin, I verified that the pam.d files were as you documented, and they were the same between the two clients. However, I forgot that I had a local user defined that matched the account name. That was stupid of me. I removed the local user, and now it is doing the SSS_PAM_ACCT_MGMT, so at least I'm not chasing that anymore. The client speed is still much different, so I need to compare the logs again and see where its taking up so much time. Hopefully it will be more apparent now. Much Thanks !! Regards, Jim > -Original Message- > From: Justin Stephenson [mailto:jstep...@redhat.com] > Sent: Friday, March 17, 2017 1:12 PM > To: Kilborn, Jim <jim.kilb...@swri.org>; Jakub Hrozek > <jhro...@redhat.com>; freeipa-users@redhat.com > Subject: Re: [Freeipa-users] Slow logins on one ipa client- due to > SSS_PAM_ACCT_MGMT > > On 03/17/2017 11:27 AM, Kilborn, Jim wrote: > > Jakub, > > > > Thanks for the response... > > > > I already had the selinux_provider=none in the sssd.conf > > Tthe sssd.conf is identical on both clients, with the exception of > ipa_hostname > > > > > > [domain/ipa.mydomain.org] > > selinux_provider = none > > cache_credentials = True > > krb5_store_password_if_offline = True > > ipa_domain = ipa.mydomain.org > > id_provider = ipa > > auth_provider = ipa > > access_provider = ipa > > ldap_tls_cacert = /etc/ipa/ca.crt > > ipa_hostname = darkjedi-master01.div18.swri.edu > > chpass_provider = ipa > > ipa_server = _srv_, div18auth1.ipa.mydomain.org, > div18auth2.ipa.mydomain.org > > dns_discovery_domain = ipa.mydomain.org > > [sssd] > > services = nss, sudo, pam, ssh > > config_file_version = 2 > > domains = ipa.mydomain.org > > [nss] > > homedir_substring = /home > > [pam] > > [sudo] > > [autofs] > > [ssh] > > [pac] > > [ifp] > > > > I verified the all the files in /etc/pam.d are the same on both clients > > using > the checksum of the files. > > > > I turned logging up to 8 on both clients, and everything is fine until this > > part > appears. Can't figure out why the slow host receives an extra request. The > sssd_be client process is getting this request from where? > > It is expected for the login process to make a call into pam_acct_mgmt() > which should trigger pam_sss in the 'account' section of the PAM stack > for IPA users. This behavior is dependent on the PAM stack > configuration, I would say the system that never calls > SSS_PAM_ACCT_MGMT > is the non-working one in this case. > > I understand you said they are the exact same, but I would suggest > checking closely the 'account' section in /etc/pam.d/sshd and > /etc/pam.d/password-auth. > > In the version you are running, the password-auth account section should > look similar to: > > account required pam_unix.so > account sufficientpam_localuser.so > account sufficientpam_succeed_if.so uid < 1000 quiet > account [default=bad success=ok user_unknown=ignore] pam_sss.so > account required pam_permit.so > > > After it finished up the SSS_PAM_ACCT_MGMT request, the slow client > runs the SSS_PAM_OPEN_SESSION, which is fast, just like the fast client. Its > wasting time in the SSS_PAM_ACCT_MGMT request, and I don't understand > why that request is being received by sssd_be. > > Is it possible a local user exists with the same name that you are > trying to login as? In this case that may cause the pam_sss line entry > in the PAM stack to never be reached(they would 'succeed' the account > section in one of the previous modules). > > > > > Slow Client > > (Fri Mar 17 09:17:33 2017) [sssd[be[ipa.div18.swri.org]]] [dp_pam_handler] > (0x0100): Got request with the following data > > (Fri Mar 17 09:17:33 2017) [sssd[be[ipa.div18.swri.org]]] [pam_print_data] > (0x0100): command: SSS_PAM_ACCT_MGMT <- Why does the slow client > get this request first? > > > > Fast Client > > (Fri Mar 17 09:16:34 2017) [sssd[be[ipa.div18.swri.org]]] [dp_pam_handler] > (0x0100): Got request with the following data > > (Fri Mar 17 09:16:34 2017) [sssd[be[ipa.div18.swri.org]]] [pam_print_data] > (0x0100): command: SSS_PAM_OPEN_SESSION > > > > > > Also ipa version is 4.4.0 > > > > > > Regards, > > Jim > > > >> Greetings, > >> > >> My first post to the forum. > >> > >> We are running centos7 with freeipa. Syncing from AD, with one linux > replica. > >> The ipa clients are getting installed by puppet. All the clients are > p
Re: [Freeipa-users] Slow logins on one ipa client- due to SSS_PAM_ACCT_MGMT
On 03/17/2017 11:27 AM, Kilborn, Jim wrote: Jakub, Thanks for the response... I already had the selinux_provider=none in the sssd.conf Tthe sssd.conf is identical on both clients, with the exception of ipa_hostname [domain/ipa.mydomain.org] selinux_provider = none cache_credentials = True krb5_store_password_if_offline = True ipa_domain = ipa.mydomain.org id_provider = ipa auth_provider = ipa access_provider = ipa ldap_tls_cacert = /etc/ipa/ca.crt ipa_hostname = darkjedi-master01.div18.swri.edu chpass_provider = ipa ipa_server = _srv_, div18auth1.ipa.mydomain.org, div18auth2.ipa.mydomain.org dns_discovery_domain = ipa.mydomain.org [sssd] services = nss, sudo, pam, ssh config_file_version = 2 domains = ipa.mydomain.org [nss] homedir_substring = /home [pam] [sudo] [autofs] [ssh] [pac] [ifp] I verified the all the files in /etc/pam.d are the same on both clients using the checksum of the files. I turned logging up to 8 on both clients, and everything is fine until this part appears. Can't figure out why the slow host receives an extra request. The sssd_be client process is getting this request from where? It is expected for the login process to make a call into pam_acct_mgmt() which should trigger pam_sss in the 'account' section of the PAM stack for IPA users. This behavior is dependent on the PAM stack configuration, I would say the system that never calls SSS_PAM_ACCT_MGMT is the non-working one in this case. I understand you said they are the exact same, but I would suggest checking closely the 'account' section in /etc/pam.d/sshd and /etc/pam.d/password-auth. In the version you are running, the password-auth account section should look similar to: account required pam_unix.so account sufficientpam_localuser.so account sufficientpam_succeed_if.so uid < 1000 quiet account [default=bad success=ok user_unknown=ignore] pam_sss.so account required pam_permit.so After it finished up the SSS_PAM_ACCT_MGMT request, the slow client runs the SSS_PAM_OPEN_SESSION, which is fast, just like the fast client. Its wasting time in the SSS_PAM_ACCT_MGMT request, and I don't understand why that request is being received by sssd_be. Is it possible a local user exists with the same name that you are trying to login as? In this case that may cause the pam_sss line entry in the PAM stack to never be reached(they would 'succeed' the account section in one of the previous modules). Slow Client (Fri Mar 17 09:17:33 2017) [sssd[be[ipa.div18.swri.org]]] [dp_pam_handler] (0x0100): Got request with the following data (Fri Mar 17 09:17:33 2017) [sssd[be[ipa.div18.swri.org]]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT <- Why does the slow client get this request first? Fast Client (Fri Mar 17 09:16:34 2017) [sssd[be[ipa.div18.swri.org]]] [dp_pam_handler] (0x0100): Got request with the following data (Fri Mar 17 09:16:34 2017) [sssd[be[ipa.div18.swri.org]]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION Also ipa version is 4.4.0 Regards, Jim Greetings, My first post to the forum. We are running centos7 with freeipa. Syncing from AD, with one linux replica. The ipa clients are getting installed by puppet. All the clients are performing fine, except one. I am getting slow ssh logins to one host, as well as slow 'id' and 'who', etc. I turned up the sss-debuglevel to 6, and compared the slow client to another, and I am seeing a section in the logs that is unique to the slow system, basically its doing a SSS_PAM_ACCT_MGMT, and I don't have any clue why. Same user logging in to both clients, one client does the SSS_PAM_ACCT_MGMT, followed by the SSS_PAM_OPEN_SESSION. While the other client only does SSS_PAM_OPEN_SESSION, and is much faster. (1 second vs 2-8 seconds) It seems the SSS_PAM_ACCT_MGMT is the slow culprit, and I don't know why its running. Any idea what would cause this or where I should look? The timestamps from the logs are missing, so it's not clear which call is taking long. No server lookups should be performed in the account phase, though, so I can only think of the selinux label setting in libselinux, which is also done in the account phase to be taking long. can you try to disable the selinux provider for a test? selinux_provider=none btw why is the 'fast' client not running the account phase at all? Is pam_sss in the account stack in the PAM configuration? Is the access_provider set to anything else than IPA in the sssd.conf file? -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Slow logins on one ipa client- due to SSS_PAM_ACCT_MGMT
Jakub, Thanks for the response... I already had the selinux_provider=none in the sssd.conf Tthe sssd.conf is identical on both clients, with the exception of ipa_hostname [domain/ipa.mydomain.org] selinux_provider = none cache_credentials = True krb5_store_password_if_offline = True ipa_domain = ipa.mydomain.org id_provider = ipa auth_provider = ipa access_provider = ipa ldap_tls_cacert = /etc/ipa/ca.crt ipa_hostname = darkjedi-master01.div18.swri.edu chpass_provider = ipa ipa_server = _srv_, div18auth1.ipa.mydomain.org, div18auth2.ipa.mydomain.org dns_discovery_domain = ipa.mydomain.org [sssd] services = nss, sudo, pam, ssh config_file_version = 2 domains = ipa.mydomain.org [nss] homedir_substring = /home [pam] [sudo] [autofs] [ssh] [pac] [ifp] I verified the all the files in /etc/pam.d are the same on both clients using the checksum of the files. I turned logging up to 8 on both clients, and everything is fine until this part appears. Can't figure out why the slow host receives an extra request. The sssd_be client process is getting this request from where? After it finished up the SSS_PAM_ACCT_MGMT request, the slow client runs the SSS_PAM_OPEN_SESSION, which is fast, just like the fast client. Its wasting time in the SSS_PAM_ACCT_MGMT request, and I don't understand why that request is being received by sssd_be. Slow Client (Fri Mar 17 09:17:33 2017) [sssd[be[ipa.div18.swri.org]]] [dp_pam_handler] (0x0100): Got request with the following data (Fri Mar 17 09:17:33 2017) [sssd[be[ipa.div18.swri.org]]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT <- Why does the slow client get this request first? Fast Client (Fri Mar 17 09:16:34 2017) [sssd[be[ipa.div18.swri.org]]] [dp_pam_handler] (0x0100): Got request with the following data (Fri Mar 17 09:16:34 2017) [sssd[be[ipa.div18.swri.org]]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION Also ipa version is 4.4.0 Regards, Jim > Greetings, > > My first post to the forum. > > We are running centos7 with freeipa. Syncing from AD, with one linux replica. > The ipa clients are getting installed by puppet. All the clients are > performing fine, except one. I am getting slow ssh logins to one host, as > well as slow 'id' and 'who', etc. > > I turned up the sss-debuglevel to 6, and compared the slow client to > another, and I am seeing a section in the logs that is unique to the slow > system, basically its doing a SSS_PAM_ACCT_MGMT, and I don't have any clue > why. Same user logging in to both clients, one client does the > SSS_PAM_ACCT_MGMT, followed by the SSS_PAM_OPEN_SESSION. While the other > client only does SSS_PAM_OPEN_SESSION, and is much faster. (1 second vs 2-8 > seconds) It seems the SSS_PAM_ACCT_MGMT is the slow culprit, and I don't know > why its running. > > Any idea what would cause this or where I should look? The timestamps from the logs are missing, so it's not clear which call is taking long. No server lookups should be performed in the account phase, though, so I can only think of the selinux label setting in libselinux, which is also done in the account phase to be taking long. can you try to disable the selinux provider for a test? selinux_provider=none btw why is the 'fast' client not running the account phase at all? Is pam_sss in the account stack in the PAM configuration? Is the access_provider set to anything else than IPA in the sssd.conf file? -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
Re: [Freeipa-users] Slow logins on one ipa client- due to SSS_PAM_ACCT_MGMT
On Thu, Mar 16, 2017 at 08:24:42PM +, Kilborn, Jim wrote: > Greetings, > > My first post to the forum. > > We are running centos7 with freeipa. Syncing from AD, with one linux replica. > The ipa clients are getting installed by puppet. All the clients are > performing fine, except one. I am getting slow ssh logins to one host, as > well as slow 'id' and 'who', etc. > > I turned up the sss-debuglevel to 6, and compared the slow client to another, > and I am seeing a section in the logs that is unique to the slow system, > basically its doing a SSS_PAM_ACCT_MGMT, and I don't have any clue why. Same > user logging in to both clients, one client does the SSS_PAM_ACCT_MGMT, > followed by the SSS_PAM_OPEN_SESSION. While the other client only does > SSS_PAM_OPEN_SESSION, and is much faster. (1 second vs 2-8 seconds) > It seems the SSS_PAM_ACCT_MGMT is the slow culprit, and I don't know why its > running. > > Any idea what would cause this or where I should look? The timestamps from the logs are missing, so it's not clear which call is taking long. No server lookups should be performed in the account phase, though, so I can only think of the selinux label setting in libselinux, which is also done in the account phase to be taking long. can you try to disable the selinux provider for a test? selinux_provider=none btw why is the 'fast' client not running the account phase at all? Is pam_sss in the account stack in the PAM configuration? Is the access_provider set to anything else than IPA in the sssd.conf file? -- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project
[Freeipa-users] Slow logins on one ipa client- due to SSS_PAM_ACCT_MGMT
Greetings, My first post to the forum. We are running centos7 with freeipa. Syncing from AD, with one linux replica. The ipa clients are getting installed by puppet. All the clients are performing fine, except one. I am getting slow ssh logins to one host, as well as slow 'id' and 'who', etc. I turned up the sss-debuglevel to 6, and compared the slow client to another, and I am seeing a section in the logs that is unique to the slow system, basically its doing a SSS_PAM_ACCT_MGMT, and I don't have any clue why. Same user logging in to both clients, one client does the SSS_PAM_ACCT_MGMT, followed by the SSS_PAM_OPEN_SESSION. While the other client only does SSS_PAM_OPEN_SESSION, and is much faster. (1 second vs 2-8 seconds) It seems the SSS_PAM_ACCT_MGMT is the slow culprit, and I don't know why its running. Any idea what would cause this or where I should look? Below are the log for a good fast client, followed by the log from the slow client. Thanks!! Good Client [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=nob...@ipa.mydomain.org] [sysdb_get_real_name] (0x0040): Cannot find user [nob...@ipa.mydomain.org] in cache [ipa_id_get_account_info_orig_done] (0x0080): Object not found, ending request [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][1][name=myusern...@ipa.mydomain.org] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][1][name=myusern...@ipa.mydomain.org] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=myusern...@ipa.mydomain.org] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [dp_pam_handler] (0x0100): Got request with the following data [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION [pam_print_data] (0x0100): domain: ipa.mydomain.org [pam_print_data] (0x0100): user: myusern...@ipa.mydomain.org [pam_print_data] (0x0100): service: sshd [pam_print_data] (0x0100): tty: ssh [pam_print_data] (0x0100): ruser: [pam_print_data] (0x0100): rhost: myhost.mydomain.org [pam_print_data] (0x0100): authtok type: 0 [pam_print_data] (0x0100): newauthtok type: 0 [pam_print_data] (0x0100): priv: 1 [pam_print_data] (0x0100): cli_pid: 26697 [pam_print_data] (0x0100): logon name: not set Bad Client [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=nob...@ipa.mydomain.org] [sysdb_get_real_name] (0x0040): Cannot find user [nob...@ipa.mydomain.org] in cache [ipa_id_get_account_info_orig_done] (0x0080): Object not found, ending request [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][1][name=myusern...@ipa.mydomain.org] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [dp_get_account_info_handler] (0x0200): Got request for [0x1][BE_REQ_USER][1][name=myusern...@ipa.mydomain.org] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [dp_get_account_info_handler] (0x0200): Got request for [0x3][BE_REQ_INITGROUPS][1][name=myusern...@ipa.mydomain.org] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)] [sysdb_set_entry_attr] (0x0080): Cannot set ts attrs for name=myusern...@ipa.mydomain.org,cn=users,cn=ipa.mydomain.org,cn=sysdb [dp_pam_handler] (0x0100): Got request with the following data [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT [pam_print_data] (0x0100): domain: ipa.mydomain.org [pam_print_data] (0x0100): user:
