2012263 – pam responder does not call initgroups to refresh the user entry

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 2012263 - pam responder does not call initgroups to refresh the user entry

Summary: pam responder does not call initgroups to refresh the user entry

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 8
Classification:	Red Hat
Component:	sssd
Sub Component:
Version:	8.5
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Target Release:	---
Assignee:	Pavel Březina
QA Contact:	Steeve Goveas
Docs Contact:
URL:
Whiteboard:	sync-to-jira
Depends On:
Blocks:	2028828
TreeView+	depends on / blocked

Reported:	2021-10-08 17:07 UTC by Steeve Goveas
Modified:	2022-05-10 16:47 UTC (History)
CC List:	9 users (show)
Fixed In Version:	sssd-2.6.2-1.el8
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Clones:	2028828 (view as bug list)
Environment:
Last Closed:	2022-05-10 15:26:45 UTC
Type:	Bug
Target Upstream Version:
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Links
System	ID	Priority	Status	Summary	Last Updated
Red Hat Issue Tracker	RHELPLAN-101405	None	None	None	2021-11-01 20:41:23 UTC
Red Hat Issue Tracker	SSSD-4013	None	None	None	2021-10-12 13:47:00 UTC
Red Hat Product Errata	RHBA-2022:2070	None	None	None	2022-05-10 15:27:13 UTC

Description Steeve Goveas 2021-10-08 17:07:55 UTC

Description of problem:

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Granting user2 to ftp service
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
*** Current Time: Mon Sep 27 16:30:23 2021  Localwatchdog at: Tue Sep 28 16:28:23 2021 
drwx------. 2 svcuser10001 svcuser10001 62 Sep 27 16:29 /home/svcuser10001
:: [ 16:30:30 ] :: [  BEGIN   ] :: Initial login to create home directories :: actually running 'auth_success svcuser10002 Secret123'
spawn ssh -q -l svcuser10002 localhost echo 'login successful'
svcuser10002@localhost's password: 
login successful
:: [ 16:30:31 ] :: [   PASS   ] :: Initial login to create home directories (Expected 0, got 0)
drwx------. 2 svcuser10001 svcuser10001 62 Sep 27 16:29 /home/svcuser10001
drwx------. 2 svcuser10002 svcuser10002 62 Sep 27 16:30 /home/svcuser10002
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
:: [ 16:30:36 ] :: [  BEGIN   ] :: Running 'ftp_auth_success svcuser10002 Secret123'
Login failed.
:: [ 16:30:37 ] :: [   FAIL   ] :: ERROR: Authentication failed.  
:: [ 16:30:37 ] :: [   FAIL   ] :: Command 'ftp_auth_success svcuser10002 Secret123' (Expected 0, got 1)
:: [ 16:30:37 ] :: [   FAIL   ] :: File '/tmp/ftplog' should contain 'Login successful.' 
:: [ 16:30:37 ] :: [  BEGIN   ] :: Running 'cat /var/log/sssd/sssd_LDAP.log | grep sdap_attrs_add_ldap_attr'
:: [ 16:30:37 ] :: [   FAIL   ] :: Command 'cat /var/log/sssd/sssd_LDAP.log | grep sdap_attrs_add_ldap_attr' (Expected 0, got 1)
:: [ 16:30:37 ] :: [   FAIL   ] :: File '/var/log/sssd/sssd_LDAP.log' should contain 'Access granted for \[vsftpd\]' 
Trying ::1...
Connected to localhost (::1).
220 (vsFTPd 3.0.3)
331 Please specify the password.
530 Login incorrect.
221 Goodbye.
:: [ 16:30:42 ] :: [   PASS   ] :: File '/var/log/secure' should contain 'pam_sss(vsftpd:auth): authentication success' 
Sep 27 16:30:36 hostname2 vsftpd[19642]: pam_sss(vsftpd:auth): authentication success; logname= uid=0 euid=0 tty=ftp ruser=svcuser10002 rhost=localhost user=svcuser10002
Sep 27 16:30:36 hostname2 vsftpd[19642]: pam_sss(vsftpd:account): system info: [Authorized service attribute has no matching rule, access denied]
Sep 27 16:30:36 hostname2 vsftpd[19642]: pam_sss(vsftpd:account): Access denied for user svcuser10002: 6 (Permission denied)
Sep 27 16:30:41 hostname2 systemd[19586]: pam_unix(systemd-user:session): session closed for user svcuser10002
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Duration: 37s
::   Assertions: 2 good, 5 bad
::   RESULT: FAIL (Granting user2 to ftp service)


Version-Release number of selected component (if applicable):
sssd-2.5.2-2.el8.x86_64

Actual results:
ftp auth fails just after ssh auth is successful and authorized service is set to vsftpd

Expected results:
ftp auth should pass

Additional info:
setting "pam_initgroups_scheme = always" in pam section of sssd.conf gets the expected result

Comment 1 Sumit Bose 2021-10-11 15:18:37 UTC

Hi,

the issue happens because in newer releases systemd-logind set UserStopDelaySec to 10s be default. As a result the systemd user manager process keep running for 10s after the user has logged out. This collides with the 'no_session' used by SSSD, since now there is still a process running under the UID of the user an refresh of the user including the group memberships and other data is not done and the changed LDAP data is not read.

Using 'pam_initgroups_scheme = always' is a workaround, another workaround would be to set 'UserStopDelaySec=0' in  /etc/systemd/logind.conf or other suitable place.

The SSSD code which checks if there are still processes of the user running should be update to ignore the systemd user manager processes. One way would be to call readlink() on /proc/PID/exe and check if the destination is '/usr/lib/systemd/systemd' or '/usr/lib/systemd/systemd (deleted)' in case systemd was updated while the user session was still active. It might be possible to determine at least the directory ('/usr/lib/systemd') at configure or runtime with systemd_util_dir pkgconfig option or sd_path_lookup() and SD_PATH_SYSTEMD_UTIL. But it should be checked with systemd developers if it is expected that the 'systemd' binary will always be in this directory.

bye,
Sumit

Comment 2 Pavel Březina 2021-11-22 11:30:29 UTC

Steeve, can you please confirm that setting 'UserStopDelaySec=0' in  /etc/systemd/logind.conf solves the issue as Sumit suggested?

Comment 3 Alexey Tikhonov 2021-11-24 12:59:16 UTC

(In reply to Pavel Březina from comment #2)
> Steeve, can you please confirm that setting 'UserStopDelaySec=0' in 
> /etc/systemd/logind.conf solves the issue as Sumit suggested?

JFTR: I would use "works around", not "solves".

Comment 4 Steeve Goveas 2021-11-24 17:27:06 UTC

Confirmed both workarounds work

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Granting user2 to ftp service with pam_initgroups_schema = always
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
-e\n\n======== cat sssd.conf ============\n\n
[sssd]
config_file_version = 2
sbus_timeout = 30
services = nss, pam
domains = LDAP
debug_level = 0xFFF0
[nss]
filter_groups = root
filter_users = root
debug_level = 0xFFF0
[pam]
pam_initgroups_scheme = always
debug_level = 0xFFF0
[domain/LDAP]
id_provider = ldap
ldap_uri = ldaps://ci-vm-10-0-154-58.hosted.upshift.rdu2.redhat.com
ldap_search_base = dc=example,dc=com
ldap_tls_cacert = /etc/openldap/certs/cacert.asc
debug_level = 0xFFF0
access_provider = ldap
ldap_access_order = authorized_service
ldap_user_authorized_service = authorizedService
*** Current Time: Wed Nov 24 11:15:22 2021  Localwatchdog at: Thu Nov 25 11:13:22 2021
*** Current Time: Wed Nov 24 11:15:37 2021  Localwatchdog at: Thu Nov 25 11:13:37 2021
drwx------. 2 svcuser10001 svcuser10001 62 Nov 24 11:14 /home/svcuser10001
:: [ 11:15:46 ] :: [  BEGIN   ] :: Initial login to create home directories :: actually running 'auth_success svcuser10002 Secret123'
spawn ssh -q -l svcuser10002 localhost echo 'login successful'
svcuser10002@localhost's password: 
login successful
:: [ 11:15:47 ] :: [   PASS   ] :: Initial login to create home directories (Expected 0, got 0)
drwx------. 2 svcuser10001 svcuser10001 62 Nov 24 11:14 /home/svcuser10001
drwx------. 2 svcuser10002 svcuser10002 62 Nov 24 11:15 /home/svcuser10002
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
:: [ 11:15:52 ] :: [  BEGIN   ] :: Running 'loginctl'
SESSION UID USER SEAT TTY
      4   0 root         
1 sessions listed.
:: [ 11:15:52 ] :: [   PASS   ] :: Command 'loginctl' (Expected 0, got 0)
:: [ 11:15:52 ] :: [  BEGIN   ] :: Running 'ftp_auth_success svcuser10002 Secret123'
230 Login successful.
:: [ 11:15:52 ] :: [   PASS   ] :: Authentication successful, as expected 
:: [ 11:15:52 ] :: [   PASS   ] :: Command 'ftp_auth_success svcuser10002 Secret123' (Expected 0, got 0)
:: [ 11:15:52 ] :: [   PASS   ] :: File '/tmp/ftplog' should contain 'Login successful.' 
Trying ::1...
Connected to localhost (::1).
220 (vsFTPd 3.0.3)
331 Please specify the password.
230 Login successful.
221 Goodbye.
:: [ 11:15:57 ] :: [  BEGIN   ] :: Running 'grep sdap_attrs_add_ldap_attr /var/log/sssd/sssd_LDAP.log'
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] Adding original mod-Timestamp [20211124161548Z] to attributes of [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowLastChange is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowMin is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowMax is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowWarning is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowInactive is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowExpire is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowFlag is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] krbLastPwdChange is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] krbPasswordExpiration is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] pwdAttribute is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] Adding authorizedService [vsftpd] to attributes of [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] Adding authorizedService [systemd-user] to attributes of [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] adAccountExpires is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] adUserAccountControl is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] nsAccountLock is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] authorizedHost is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] authorizedRHost is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] ndsLoginDisabled is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] ndsLoginExpirationTime is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] ndsLoginAllowedTimeMap is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] sshPublicKey is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] authType is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] userCertificate is not available for [svcuser10002@ldap].
(2021-11-24 11:15:52): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] mail is not available for [svcuser10002@ldap].
:: [ 11:15:57 ] :: [   PASS   ] :: Command 'grep sdap_attrs_add_ldap_attr /var/log/sssd/sssd_LDAP.log' (Expected 0, got 0)
:: [ 11:15:57 ] :: [   PASS   ] :: File '/var/log/secure' should contain 'pam_sss(vsftpd:auth): authentication success' 
:: [ 11:15:57 ] :: [  BEGIN   ] :: Running 'cat /var/log/secure'
Nov 24 11:15:47 hostname2 sshd[30949]: pam_unix(sshd:session): session closed for user svcuser10002
Nov 24 11:15:52 hostname2 vsftpd[31031]: pam_sss(vsftpd:auth): authentication success; logname= uid=0 euid=0 tty=ftp ruser=svcuser10002 rhost=localhost user=svcuser10002
Nov 24 11:15:52 hostname2 vsftpd[31031]: pam_unix(vsftpd:session): session opened for user svcuser10002 by (uid=0)
Nov 24 11:15:52 hostname2 vsftpd[31031]: pam_unix(vsftpd:session): session closed for user svcuser10002
:: [ 11:15:57 ] :: [   PASS   ] :: Command 'cat /var/log/secure' (Expected 0, got 0)
:: [ 11:15:57 ] :: [   PASS   ] :: File '/var/log/sssd/sssd_LDAP.log' should contain 'Access granted for \[vsftpd\]' 
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Duration: 41s
::   Assertions: 9 good, 0 bad
::   RESULT: PASS (Granting user2 to ftp service with pam_initgroups_schema = always)



::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Granting user2 to ftp service with UserStopDelaySec=0
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
-e\n\n======== cat /etc/systemd/logind.conf ============\n\n
#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.
#
# Entries in this file show the compile time defaults.
# You can change settings by editing this file.
# Defaults can be restored by simply deleting this file.
#
# See logind.conf(5) for details.
[Login]
UserStopDelaySec = 0
#NAutoVTs=6
#ReserveVT=6
#KillUserProcesses=no
#KillOnlyUsers=
#KillExcludeUsers=root
#InhibitDelayMaxSec=5
#HandlePowerKey=poweroff
#HandleSuspendKey=suspend
#HandleHibernateKey=hibernate
#HandleLidSwitch=suspend
#HandleLidSwitchExternalPower=suspend
#HandleLidSwitchDocked=ignore
#PowerKeyIgnoreInhibited=no
#SuspendKeyIgnoreInhibited=no
#HibernateKeyIgnoreInhibited=no
#LidSwitchIgnoreInhibited=yes
#HoldoffTimeoutSec=30s
#IdleAction=ignore
#IdleActionSec=30min
#RuntimeDirectorySize=10%
#RemoveIPC=no
#InhibitorsMax=8192
#SessionsMax=8192
-e\n\n======== cat sssd.conf ============\n\n
[sssd]
config_file_version = 2
sbus_timeout = 30
services = nss, pam
domains = LDAP
debug_level = 0xFFF0
[nss]
filter_groups = root
filter_users = root
debug_level = 0xFFF0
[pam]
debug_level = 0xFFF0
[domain/LDAP]
id_provider = ldap
ldap_uri = ldaps://ci-vm-10-0-154-58.hosted.upshift.rdu2.redhat.com
ldap_search_base = dc=example,dc=com
ldap_tls_cacert = /etc/openldap/certs/cacert.asc
debug_level = 0xFFF0
access_provider = ldap
ldap_access_order = authorized_service
ldap_user_authorized_service = authorizedService
:: [ 11:16:03 ] :: [  BEGIN   ] :: Running 'loginctl show-session| grep UserStopDelay'
UserStopDelayUSec=10s
:: [ 11:16:03 ] :: [   PASS   ] :: Command 'loginctl show-session| grep UserStopDelay' (Expected 0, got 0)
:: [ 11:16:03 ] :: [  BEGIN   ] :: Running 'systemctl restart systemd-logind'
:: [ 11:16:03 ] :: [   PASS   ] :: Command 'systemctl restart systemd-logind' (Expected 0, got 0)
:: [ 11:16:03 ] :: [  BEGIN   ] :: Running 'loginctl show-session| grep UserStopDelay'
UserStopDelayUSec=0
:: [ 11:16:03 ] :: [   PASS   ] :: Command 'loginctl show-session| grep UserStopDelay' (Expected 0, got 0)
*** Current Time: Wed Nov 24 11:16:22 2021  Localwatchdog at: Thu Nov 25 11:13:22 2021
drwx------. 2 svcuser10001 svcuser10001 62 Nov 24 11:14 /home/svcuser10001
drwx------. 2 svcuser10002 svcuser10002 62 Nov 24 11:15 /home/svcuser10002
:: [ 11:16:28 ] :: [  BEGIN   ] :: Initial login to create home directories :: actually running 'auth_success svcuser10002 Secret123'
spawn ssh -q -l svcuser10002 localhost echo 'login successful'
svcuser10002@localhost's password: 
login successful
:: [ 11:16:29 ] :: [   PASS   ] :: Initial login to create home directories (Expected 0, got 0)
drwx------. 2 svcuser10001 svcuser10001 62 Nov 24 11:14 /home/svcuser10001
drwx------. 2 svcuser10002 svcuser10002 62 Nov 24 11:15 /home/svcuser10002
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
modifying entry "uid=svcuser10002,ou=users,dc=example,dc=com"
:: [ 11:16:34 ] :: [  BEGIN   ] :: Running 'loginctl'
SESSION UID USER SEAT TTY
      4   0 root         
1 sessions listed.
:: [ 11:16:34 ] :: [   PASS   ] :: Command 'loginctl' (Expected 0, got 0)
:: [ 11:16:34 ] :: [  BEGIN   ] :: Running 'ftp_auth_success svcuser10002 Secret123'
230 Login successful.
:: [ 11:16:34 ] :: [   PASS   ] :: Authentication successful, as expected 
:: [ 11:16:34 ] :: [   PASS   ] :: Command 'ftp_auth_success svcuser10002 Secret123' (Expected 0, got 0)
:: [ 11:16:34 ] :: [   PASS   ] :: File '/tmp/ftplog' should contain 'Login successful.' 
Trying ::1...
Connected to localhost (::1).
220 (vsFTPd 3.0.3)
331 Please specify the password.
230 Login successful.
221 Goodbye.
:: [ 11:16:34 ] :: [  BEGIN   ] :: Running 'grep sdap_attrs_add_ldap_attr /var/log/sssd/sssd_LDAP.log'
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] Adding original mod-Timestamp [20211124161630Z] to attributes of [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowLastChange is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowMin is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowMax is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowWarning is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowInactive is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowExpire is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] shadowFlag is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] krbLastPwdChange is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] krbPasswordExpiration is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] pwdAttribute is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] Adding authorizedService [vsftpd] to attributes of [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] Adding authorizedService [systemd-user] to attributes of [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] adAccountExpires is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] adUserAccountControl is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] nsAccountLock is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] authorizedHost is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] authorizedRHost is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] ndsLoginDisabled is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] ndsLoginExpirationTime is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] ndsLoginAllowedTimeMap is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] sshPublicKey is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] authType is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] userCertificate is not available for [svcuser10002@ldap].
(2021-11-24 11:16:34): [be[LDAP]] [sdap_attrs_add_ldap_attr] (0x2000): [RID#16] mail is not available for [svcuser10002@ldap].
:: [ 11:16:34 ] :: [   PASS   ] :: Command 'grep sdap_attrs_add_ldap_attr /var/log/sssd/sssd_LDAP.log' (Expected 0, got 0)
*** Current Time: Wed Nov 24 11:16:37 2021  Localwatchdog at: Thu Nov 25 11:13:37 2021
:: [ 11:16:39 ] :: [   PASS   ] :: File '/var/log/secure' should contain 'pam_sss(vsftpd:auth): authentication success' 
:: [ 11:16:39 ] :: [  BEGIN   ] :: Running 'cat /var/log/secure'
Nov 24 11:16:29 hostname2 sshd[31442]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=::1 user=svcuser10002
Nov 24 11:16:29 hostname2 sshd[31442]: Accepted password for svcuser10002 from ::1 port 52056 ssh2
Nov 24 11:16:29 hostname2 systemd[31446]: pam_unix(systemd-user:session): session opened for user svcuser10002 by (uid=0)
Nov 24 11:16:29 hostname2 sshd[31442]: pam_unix(sshd:session): session opened for user svcuser10002 by (uid=0)
Nov 24 11:16:29 hostname2 sshd[31454]: Received disconnect from ::1 port 52056:11: disconnected by user
Nov 24 11:16:29 hostname2 sshd[31454]: Disconnected from user svcuser10002 ::1 port 52056
Nov 24 11:16:29 hostname2 sshd[31442]: pam_unix(sshd:session): session closed for user svcuser10002
Nov 24 11:16:29 hostname2 systemd[31448]: pam_unix(systemd-user:session): session closed for user svcuser10002
Nov 24 11:16:34 hostname2 vsftpd[31532]: pam_sss(vsftpd:auth): authentication success; logname= uid=0 euid=0 tty=ftp ruser=svcuser10002 rhost=localhost user=svcuser10002
Nov 24 11:16:34 hostname2 systemd[31537]: pam_unix(systemd-user:session): session opened for user svcuser10002 by (uid=0)
Nov 24 11:16:34 hostname2 vsftpd[31532]: pam_unix(vsftpd:session): session opened for user svcuser10002 by (uid=0)
Nov 24 11:16:34 hostname2 vsftpd[31532]: pam_unix(vsftpd:session): session closed for user svcuser10002
Nov 24 11:16:34 hostname2 systemd[31538]: pam_unix(systemd-user:session): session closed for user svcuser10002
:: [ 11:16:39 ] :: [   PASS   ] :: Command 'cat /var/log/secure' (Expected 0, got 0)
:: [ 11:16:39 ] :: [   PASS   ] :: File '/var/log/sssd/sssd_LDAP.log' should contain 'Access granted for \[vsftpd\]' 
:: [ 11:16:39 ] :: [  BEGIN   ] :: Running 'systemctl daemon-reload'
:: [ 11:16:40 ] :: [   PASS   ] :: Command 'systemctl daemon-reload' (Expected 0, got 0)
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Duration: 43s
::   Assertions: 15 good, 0 bad

Comment 5 Pavel Březina 2021-12-03 12:53:19 UTC

Upstream ticket:
https://github.com/SSSD/sssd/issues/5900

Comment 6 Pavel Březina 2021-12-03 12:54:15 UTC

Upstream PR:
https://github.com/SSSD/sssd/pull/5901

Comment 12 Alexey Tikhonov 2021-12-07 12:21:41 UTC

Pushed PR: https://github.com/SSSD/sssd/pull/5901

* `master`
    * a56b8d1aaf030fea196b65545dfe207ea10bdf50 - utils: ignore systemd and sd-pam process in get_active_uid_linux()

Comment 19 errata-xmlrpc 2022-05-10 15:26:45 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (sssd bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2022:2070

Note You need to log in before you can comment on or make changes to this bug.