We see random user permission denied issues on RHEL8 client, that resolves itself after about 10 minutes. In this case, the user is authenticating using the remote desktop software NoMachine (nx).
journalctl:
Sep 26 12:41:35 server1.id.int nxexec[3011890]: pam_sss(nx:auth): authentication failure; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith Sep 26 12:41:35 server1.id.int nxexec[3011890]: pam_sss(nx:auth): received for user rsmith: 6 (Permission denied) Sep 26 12:41:47 server1.id.int krb5_child[3011927]: Client's credentials have been revoked Sep 26 12:41:47 server1.id.int krb5_child[3011927]: Client's credentials have been revoked Sep 26 12:41:47 server1.id.int nxexec[3011925]: pam_sss(nx:auth): authentication failure; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith Sep 26 12:41:47 server1.id.int nxexec[3011925]: pam_sss(nx:auth): received for user rsmith: 6 (Permission denied) Sep 26 12:42:11 server1.id.int krb5_child[3011965]: Client's credentials have been revoked Sep 26 12:42:11 server1.id.int krb5_child[3011965]: Client's credentials have been revoked Sep 26 12:42:11 server1.id.int nxexec[3011963]: pam_sss(nx:auth): authentication failure; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith Sep 26 12:42:11 server1.id.int nxexec[3011963]: pam_sss(nx:auth): received for user rsmith: 6 (Permission denied) Sep 26 12:43:35 server1.id.int nxexec[3012022]: pam_sss(nx:auth): authentication success; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith Sep 26 12:45:15 server1.id.int systemd-logind[4695]: New session 526 of user rsmith. Sep 26 12:45:15 server1.id.int systemd[1]: Started Session 526 of user rsmith. Sep 26 12:45:15 server1.id.int nxexec[3012073]: pam_unix(nx:session): session opened for user rsmith by (uid=969)
krb5_child.log:
(2024-09-26 12:41:24): [krb5_child[3011820]] [map_krb5_error] (0x0020): [RID#12745] 2399: [-1765328366][Client's credentials have been revoked] (2024-09-26 12:41:35): [krb5_child[3011892]] [get_and_save_tgt] (0x0020): [RID#12751] 2270: [-1765328366][Client's credentials have been revoked] ********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE: * (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x0400): [RID#12751] krb5_child started. * (2024-09-26 12:41:35): [krb5_child[3011892]] [unpack_buffer] (0x1000): [RID#12751] total buffer size: [124] * (2024-09-26 12:41:35): [krb5_child[3011892]] [unpack_buffer] (0x0100): [RID#12751] cmd [241 (auth)] uid [866900186] gid [2070] validate [true] enterprise principal [false] offline [false] UPN [rsmith@ID.INT] * (2024-09-26 12:41:35): [krb5_child[3011892]] [unpack_buffer] (0x0100): [RID#12751] ccname: [KCM:] old_ccname: [KCM:] keytab: [/etc/krb5.keytab] * (2024-09-26 12:41:35): [krb5_child[3011892]] [switch_creds] (0x0200): [RID#12751] Switch user to [866900186][2070]. * (2024-09-26 12:41:35): [krb5_child[3011892]] [switch_creds] (0x0200): [RID#12751] Switch user to [0][0]. * (2024-09-26 12:41:35): [krb5_child[3011892]] [k5c_check_old_ccache] (0x4000): [RID#12751] Ccache_file is [KCM:] and is active and TGT is valid. * (2024-09-26 12:41:35): [krb5_child[3011892]] [k5c_setup_fast] (0x0100): [RID#12751] Fast principal is set to [host/server1.id.int@ID.INT] * (2024-09-26 12:41:35): [krb5_child[3011892]] [find_principal_in_keytab] (0x4000): [RID#12751] Trying to find principal host/server1.id.int@ID.INTmailto:host/server1.id.int@ID.INT in keytab. * (2024-09-26 12:41:35): [krb5_child[3011892]] [match_principal] (0x1000): [RID#12751] Principal matched to the sample (host/server1.id.int@ID.INTmailto:host/server1.id.int@ID.INT). * (2024-09-26 12:41:35): [krb5_child[3011892]] [check_fast_ccache] (0x0200): [RID#12751] FAST TGT is still valid. * (2024-09-26 12:41:35): [krb5_child[3011892]] [become_user] (0x0200): [RID#12751] Trying to become user [866900186][2070]. * (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x2000): [RID#12751] Running as [866900186][2070]. * (2024-09-26 12:41:35): [krb5_child[3011892]] [set_lifetime_options] (0x0100): [RID#12751] No specific renewable lifetime requested. * (2024-09-26 12:41:35): [krb5_child[3011892]] [set_lifetime_options] (0x0100): [RID#12751] No specific lifetime requested. * (2024-09-26 12:41:35): [krb5_child[3011892]] [set_canonicalize_option] (0x0100): [RID#12751] Canonicalization is set to [true] * (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x0400): [RID#12751] Will perform auth * (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x0400): [RID#12751] Will perform online auth * (2024-09-26 12:41:35): [krb5_child[3011892]] [tgt_req_child] (0x1000): [RID#12751] Attempting to get a TGT * (2024-09-26 12:41:35): [krb5_child[3011892]] [get_and_save_tgt] (0x0400): [RID#12751] Attempting kinit for realm [ID.INT] * (2024-09-26 12:41:35): [krb5_child[3011892]] [get_and_save_tgt] (0x0020): [RID#12751] 2270: [-1765328366][Client's credentials have been revoked] ********************** BACKTRACE DUMP ENDS HERE *********************************
Any help would be appreciated.
Dungan, Scott A. via FreeIPA-users wrote:
We see random user permission denied issues on RHEL8 client, that resolves itself after about 10 minutes. In this case, the user is authenticating using the remote desktop software NoMachine (nx).
The default password policy allows 6 failed logins, each happening within 60 seconds of the previous. This locks out the account for 10 minutes.
$ ipa pwpolicy-show ... Max failures: 6 Failure reset interval: 60 Lockout duration: 600
Probably the best place to start is to find the logs for these failed login attempts and see if you can determine where they originate and whether they are malicious or not.
You can also modify the default password policy or create a group password policy with this user as a member that tweaks these values.
rob
journalctl:
Sep 26 12:41:35 server1.id.int nxexec[3011890]: pam_sss(nx:auth): authentication failure; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith
Sep 26 12:41:35 server1.id.int nxexec[3011890]: pam_sss(nx:auth): received for user rsmith: 6 (Permission denied)
Sep 26 12:41:47 server1.id.int krb5_child[3011927]: Client's credentials have been revoked
Sep 26 12:41:47 server1.id.int krb5_child[3011927]: Client's credentials have been revoked
Sep 26 12:41:47 server1.id.int nxexec[3011925]: pam_sss(nx:auth): authentication failure; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith
Sep 26 12:41:47 server1.id.int nxexec[3011925]: pam_sss(nx:auth): received for user rsmith: 6 (Permission denied)
Sep 26 12:42:11 server1.id.int krb5_child[3011965]: Client's credentials have been revoked
Sep 26 12:42:11 server1.id.int krb5_child[3011965]: Client's credentials have been revoked
Sep 26 12:42:11 server1.id.int nxexec[3011963]: pam_sss(nx:auth): authentication failure; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith
Sep 26 12:42:11 server1.id.int nxexec[3011963]: pam_sss(nx:auth): received for user rsmith: 6 (Permission denied)
Sep 26 12:43:35 server1.id.int nxexec[3012022]: pam_sss(nx:auth): authentication success; logname= uid=969 euid=0 tty= ruser= rhost=192.168.55.202 user=rsmith
Sep 26 12:45:15 server1.id.int systemd-logind[4695]: New session 526 of user rsmith.
Sep 26 12:45:15 server1.id.int systemd[1]: Started Session 526 of user rsmith.
Sep 26 12:45:15 server1.id.int nxexec[3012073]: pam_unix(nx:session): session opened for user rsmith by (uid=969)
krb5_child.log:
(2024-09-26 12:41:24): [krb5_child[3011820]] [map_krb5_error] (0x0020): [RID#12745] 2399: [-1765328366][Client's credentials have been revoked]
(2024-09-26 12:41:35): [krb5_child[3011892]] [get_and_save_tgt] (0x0020): [RID#12751] 2270: [-1765328366][Client's credentials have been revoked] ********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE: * (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x0400): [RID#12751] krb5_child started. * (2024-09-26 12:41:35): [krb5_child[3011892]] [unpack_buffer] (0x1000): [RID#12751] total buffer size: [124] * (2024-09-26 12:41:35): [krb5_child[3011892]] [unpack_buffer] (0x0100): [RID#12751] cmd [241 (auth)] uid [866900186] gid [2070] validate [true] enterprise principal [false] offline [false] UPN [rsmith@ID.INT]
* (2024-09-26 12:41:35): [krb5_child[3011892]] [unpack_buffer] (0x0100): [RID#12751] ccname: [KCM:] old_ccname: [KCM:] keytab: [/etc/krb5.keytab]
* (2024-09-26 12:41:35): [krb5_child[3011892]] [switch_creds] (0x0200): [RID#12751] Switch user to [866900186][2070].
* (2024-09-26 12:41:35): [krb5_child[3011892]] [switch_creds] (0x0200): [RID#12751] Switch user to [0][0].
* (2024-09-26 12:41:35): [krb5_child[3011892]] [k5c_check_old_ccache] (0x4000): [RID#12751] Ccache_file is [KCM:] and is active and TGT is valid.
* (2024-09-26 12:41:35): [krb5_child[3011892]] [k5c_setup_fast] (0x0100): [RID#12751] Fast principal is set to [host/server1.id.int@ID.INT]
* (2024-09-26 12:41:35): [krb5_child[3011892]] [find_principal_in_keytab] (0x4000): [RID#12751] Trying to find principal host/server1.id.int@ID.INT mailto:host/server1.id.int@ID.INT in keytab.
* (2024-09-26 12:41:35): [krb5_child[3011892]] [match_principal] (0x1000): [RID#12751] Principal matched to the sample (host/server1.id.int@ID.INT mailto:host/server1.id.int@ID.INT).
* (2024-09-26 12:41:35): [krb5_child[3011892]] [check_fast_ccache] (0x0200): [RID#12751] FAST TGT is still valid.
* (2024-09-26 12:41:35): [krb5_child[3011892]] [become_user] (0x0200): [RID#12751] Trying to become user [866900186][2070].
* (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x2000): [RID#12751] Running as [866900186][2070].
* (2024-09-26 12:41:35): [krb5_child[3011892]] [set_lifetime_options] (0x0100): [RID#12751] No specific renewable lifetime requested.
* (2024-09-26 12:41:35): [krb5_child[3011892]] [set_lifetime_options] (0x0100): [RID#12751] No specific lifetime requested.
* (2024-09-26 12:41:35): [krb5_child[3011892]] [set_canonicalize_option] (0x0100): [RID#12751] Canonicalization is set to [true]
* (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x0400): [RID#12751] Will perform auth
* (2024-09-26 12:41:35): [krb5_child[3011892]] [main] (0x0400): [RID#12751] Will perform online auth
* (2024-09-26 12:41:35): [krb5_child[3011892]] [tgt_req_child] (0x1000): [RID#12751] Attempting to get a TGT
* (2024-09-26 12:41:35): [krb5_child[3011892]] [get_and_save_tgt] (0x0400): [RID#12751] Attempting kinit for realm [ID.INT]
* (2024-09-26 12:41:35): [krb5_child[3011892]] [get_and_save_tgt] (0x0020): [RID#12751] 2270: [-1765328366][Client's credentials have been revoked]
********************** BACKTRACE DUMP ENDS HERE
Any help would be appreciated.
freeipa-users@lists.fedorahosted.org
-
Dungan, Scott A. -
Rob Crittenden