We have many workstation with fedora 27 and freeipa, and every 10-18 days one of user can't log in. I do not understand why this happens. Reinstalling free-ipa, cleaning /var/lib/sssd folder does not help, only totally reinstall with / wipe (user /home does not change) solve this problem.
Some logs with debug 9 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #2: Returning [test1@example.com] from cache (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #2: This request type does not support filtering result by negative cache (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #2: Found 2 entries in domain example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #2: Finished: Success (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is test1@example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [test1] added to PAM initgroup cache (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): user: test1@example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): service: login (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: tty4 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 3012 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: test1 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55f5f30fb5d0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55f5f30fb5d0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x55f5f30e7620 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][example.com] (Tue Feb 6 13:13:43 2018) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x55f5f30fde90
pam system-auth #%PAM-1.0 # This file is auto-generated. # User changes will be destroyed the next time authconfig is run. auth required pam_env.so auth required pam_faildelay.so delay=2000000 auth [default=1 ignore=ignore success=ok] pam_succeed_if.so uid >= 1000 quiet auth [default=1 ignore=ignore success=ok] pam_localuser.so auth sufficient pam_unix.so nullok try_first_pass auth requisite pam_succeed_if.so uid >= 1000 quiet_success auth sufficient pam_sss.so forward_pass auth required pam_deny.so
account required pam_unix.so account sufficient pam_localuser.so account sufficient pam_succeed_if.so uid < 1000 quiet account [default=bad success=ok user_unknown=ignore] pam_sss.so account required pam_permit.so
password requisite pam_pwquality.so try_first_pass local_users_only retry=3 authtok_type= password sufficient pam_unix.so sha512 shadow nullok try_first_pass use_authtok password sufficient pam_sss.so use_authtok password required pam_deny.so
session optional pam_keyinit.so revoke session required pam_limits.so -session optional pam_systemd.so session optional pam_oddjob_mkhomedir.so umask=0077 session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid session required pam_unix.so session optional pam_sss.so
sssd.conf [domain/example.com]
id_provider = ipa ipa_server = _srv_, ipa1.example.com ipa_domain = example.com ipa_hostname = dell03.example.com auth_provider = ipa chpass_provider = ipa access_provider = ipa cache_credentials = True ldap_tls_cacert = /etc/ipa/ca.crt krb5_store_password_if_offline = True autofs_provider = ipa ipa_automount_location = default [sssd] services = nss, pam, ssh, sudo, autofs debug_level = 9 domains = example.com [nss] homedir_substring = /home debug_level = 9 [pam] debug_level = 9 [sudo] debug_level = 9 [autofs]
[ssh] debug_level = 9 [pac]
[ifp]
[secrets]
[session_recording]
On (06/02/18 11:37), Iaroslav wrote:
We have many workstation with fedora 27 and freeipa, and every 10-18 days one of user can't log in. I do not understand why this happens. Reinstalling free-ipa, cleaning /var/lib/sssd folder does not help, only totally reinstall with / wipe (user /home does not change) solve this problem.
Some logs with debug 9 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #2: Returning [test1@example.com] from cache (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400): CR #2: This request type does not support filtering result by negative cache (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #2: Found 2 entries in domain example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #2: Finished: Success (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is test1@example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [test1] added to PAM initgroup cache (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): user: test1@example.com (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): service: login (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: tty4 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 3012 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: test1 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55f5f30fb5d0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55f5f30fb5d0 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x55f5f30e7620 (Tue Feb 6 13:13:43 2018) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Tue Feb 6 13:13:43 2018) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [4 (System error)][example.com]
PAM system error is an unexpected situation in sssd with authentication.
Unfortunately there are missing domain log files in this mail thread. Could you provide them?
https://docs.pagure.org/SSSD.sssd/users/troubleshooting.html https://docs.pagure.org/SSSD.sssd/users/troubleshooting.html#troubleshooting...
LS
System on that PC was reinstalled, so no more logs, if this happens again I need to provide sssd.conf [domain/example.com] debug_level = 9
log?
it happened again with one of our server after power lost.
full logs of all sections with debug_level=10 https://drive.google.com/open?id=1Yq2EQ0W9kSz7NhbrB-sv9EkQ2WD4mdXL
sssctl user-checks test1 user: test1 action: acct service: system-auth
SSSD nss user lookup result: - user name: test1 - user id: 1400000070 - group id: 1400000070 - gecos: test1 test - home directory: /home/test1 - shell: /bin/bash
SSSD InfoPipe user lookup result: - name: test1 - uidNumber: 1400000070 - gidNumber: 1400000070 - gecos: test1 test - homeDirectory: /home/test1 - loginShell: /bin/bash
testing pam_acct_mgmt
pam_acct_mgmt: Permission denied
PAM Environment: - no env -
sssctl user-checks pontostroy user: pontostroy action: acct service: system-auth
SSSD nss user lookup result: - user name: pontostroy - user id: 1400000014 - group id: 1400000014 - gecos: Iaroslav Andrusyak - home directory: /home/pontostroy - shell: /bin/bash
SSSD InfoPipe user lookup result: - name: pontostroy - uidNumber: 1400000014 - gidNumber: 1400000014 - gecos: Iaroslav Andrusyak - homeDirectory: /home/pontostroy - loginShell: /bin/bash
testing pam_acct_mgmt
pam_acct_mgmt: System error
PAM Environment: - no env -
The selinux_child failed: (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [seuser_needs_update] (0x2000): getseuserbyname: ret: 0 seuser: unconfined_u mls: unknown (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): could not cache policy database (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): could not cache join database (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): could not enter read-only section (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): Error while reading kernel policy from /var/lib/selinux/targeted/active/policy.linked. (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [set_seuser] (0x0020): Cannot commit SELinux transaction (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [main] (0x0020): Cannot set SELinux login context. (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [main] (0x0020): selinux_child failed!
What is 'sestatus' telling you? If you don't use the SELInux login mapping, you can set selinux_provider=none to work around tihs.
On Thu, Feb 15, 2018 at 09:45:43AM -0000, Iaroslav wrote:
it happened again with one of our server after power lost.
full logs of all sections with debug_level=10 https://drive.google.com/open?id=1Yq2EQ0W9kSz7NhbrB-sv9EkQ2WD4mdXL
sssctl user-checks test1 user: test1 action: acct service: system-auth
SSSD nss user lookup result:
- user name: test1
- user id: 1400000070
- group id: 1400000070
- gecos: test1 test
- home directory: /home/test1
- shell: /bin/bash
SSSD InfoPipe user lookup result:
- name: test1
- uidNumber: 1400000070
- gidNumber: 1400000070
- gecos: test1 test
- homeDirectory: /home/test1
- loginShell: /bin/bash
testing pam_acct_mgmt
pam_acct_mgmt: Permission denied
PAM Environment:
- no env -
sssctl user-checks pontostroy user: pontostroy action: acct service: system-auth
SSSD nss user lookup result:
- user name: pontostroy
- user id: 1400000014
- group id: 1400000014
- gecos: Iaroslav Andrusyak
- home directory: /home/pontostroy
- shell: /bin/bash
SSSD InfoPipe user lookup result:
- name: pontostroy
- uidNumber: 1400000014
- gidNumber: 1400000014
- gecos: Iaroslav Andrusyak
- homeDirectory: /home/pontostroy
- loginShell: /bin/bash
testing pam_acct_mgmt
pam_acct_mgmt: System error
PAM Environment:
- no env -
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
sestatus SELinux status: disabled
and with selinux_provider=none
sssctl user-checks pontostroy user: pontostroy action: acct service: system-auth
SSSD nss user lookup result: - user name: pontostroy - user id: 1400000014 - group id: 1400000014 - gecos: Iaroslav Andrusyak - home directory: /home/pontostroy - shell: /bin/bash
SSSD InfoPipe user lookup result: - name: pontostroy - uidNumber: 1400000014 - gidNumber: 1400000014 - gecos: Iaroslav Andrusyak - homeDirectory: /home/pontostroy - loginShell: /bin/bash
testing pam_acct_mgmt
pam_acct_mgmt: Success
PAM Environment: - no env -
Thank you very much for your help.
On (15/02/18 16:40), Jakub Hrozek wrote:
The selinux_child failed: (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [seuser_needs_update] (0x2000): getseuserbyname: ret: 0 seuser: unconfined_u mls: unknown (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): could not cache policy database (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): could not cache join database (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): could not enter read-only section (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [libsemanage] (0x0020): Error while reading kernel policy from /var/lib/selinux/targeted/active/policy.linked. (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [set_seuser] (0x0020): Cannot commit SELinux transaction (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [main] (0x0020): Cannot set SELinux login context. (Thu Feb 15 11:18:05 2018) [[sssd[selinux_child[20961]]]] [main] (0x0020): selinux_child failed!
What is 'sestatus' telling you? If you don't use the SELInux login mapping, you can set selinux_provider=none to work around tihs.
That workaround should not be required.
It might be related to https://pagure.io/SSSD/sssd/issue/3618 And backported to sssd-1.16.0-6.fc27 which is already in stable on f27 for 3 days.
Does it fails even with sssd-1.16.0-6.fc27 ? BTW If directory /var/lib/selinux/targeted/active/ is in weird state then you might call "semodule --build" and it might repair it. But you should not get to such state with sssd-1.16.0-6.fc27
LS
sssd-users@lists.fedorahosted.org
-
Iaroslav -
Jakub Hrozek -
Lukas Slebodnik