Bug 1685472

Summary:	UPN negative cache does not use values from 'filter_users' config option
Product:	Red Hat Enterprise Linux 7	Reporter:	Thorsten Scherf <tscherf>
Component:	sssd	Assignee:	SSSD Maintainers <sssd-maint>
Status:	CLOSED ERRATA	QA Contact:	ipa-qe <ipa-qe>
Severity:	medium	Docs Contact:
Priority:	medium
Version:	7.6	CC:	amore, grajaiya, jhrozek, ksiddiqu, lslebodn, mzidek, pbrezina, sbose, sgoveas, sorlov, tscherf
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	sssd-1.16.4-1.el7	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2019-08-06 13:02:47 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Thorsten Scherf 2019-03-05 10:07:32 UTC

Description of problem:
The UPN negative cache does not use values from 'filter_users' config option and as a result a backend lookup for trigger also for those users.

Version-Release number of selected component (if applicable):
sssd-1.16.0-19.el7

How reproducible:
Always

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:
Related to https://bugzilla.redhat.com/1679173

Comment 2 Sumit Bose 2019-03-05 11:00:49 UTC

Upstream ticket:
https://pagure.io/SSSD/sssd/issue/3978

Comment 4 Jakub Hrozek 2019-03-19 09:26:38 UTC

master:
 * 640edac
 * 6b93ee6
 * 2f5aca3
sssd-1-16:
 * faede6d
 * 720907d
 * 6bb46a6

Comment 7 Jakub Hrozek 2019-06-12 09:01:48 UTC

I reproduced this pretty easily after I reverted the patches, just by following similar steps as you. The unqualified name, I  think might be the issue. The potential catch might be that sssd needs to realise that it's no longer offline after ipactl start.

What I did was: add foo to filter_users and then test with getent passwd foo. This also aligns with comment 1 where they had a qualified name.

I would suggest to change the sequence like this:
 - ipactl stop
 - sssd start
 - sssctl domain-list should not show the AD domain
 - keep calling sssctl domain-list until you do see the AD domain
 - then run id foo

HTH

Comment 9 anuja 2019-06-21 09:54:27 UTC

As per comment #8
Steps performed :
 - Setup trust
 - Change domain resolution order to prefer the AD domain
 - Added aduser in sssd.conf in filter_users
 - ipactl stop
 - rm -f sssd logs and cache
 - sssd start
 - ipactl start
 - sssctl domain-list should not show the AD domain
 - keep calling sssctl domain-list until you do see the AD domain
 - then run id user
 - check that there are no calls to [cache_req_search_dp] for user in sssd_nss.log
======================================================================================================================================================
older version :
======================================================================================================================================================
[root@oldenv1 ~]# rpm -qa sssd
sssd-1.16.2-13.el7.x86_64
[root@oldenv1 ~]# 
[root@oldenv1 ~]# grep -B 3 "filter_users" /etc/sssd/sssd.conf
[nss]
memcache_timeout = 600
homedir_substring = /home
filter_users = aduser1

[root@oldenv1 ~]# ipa config-show | grep resolution
  Domain resolution order: ipaad2k16cin.test:apq3h.test
[root@oldenv1 ~]# 
[root@oldenv1 ~]# ipactl stop
Stopping ipa-dnskeysyncd Service
Stopping ipa-otpd Service
Stopping winbind Service
Stopping smb Service
Stopping pki-tomcatd Service
Stopping ntpd Service
Stopping ipa-custodia Service
Stopping httpd Service
Stopping named Service
Stopping kadmin Service
Stopping krb5kdc Service
Stopping Directory Service
ipa: INFO: The ipactl command was successful
[root@oldenv1 ~]# service sssd stop; rm -rf /var/lib/sss/{db,mc}/*; service sssd start
Redirecting to /bin/systemctl stop sssd.service
Redirecting to /bin/systemctl start sssd.service
[root@oldenv1 ~]# sssd start
SSSD is already running
[root@oldenv1 ~]# ipactl start
Starting Directory Service
Starting krb5kdc Service
Starting kadmin Service
Starting named Service
Starting httpd Service
Starting ipa-custodia Service
Starting ntpd Service
Starting pki-tomcatd Service
Starting smb Service
Starting winbind Service
Starting ipa-otpd Service
Starting ipa-dnskeysyncd Service
ipa: INFO: The ipactl command was successful
[root@oldenv1 ~]# sssctl domain-list
apq3h.test
[root@oldenv1 ~]# sssctl domain-list
apq3h.test
[root@oldenv1 ~]# sleep 60 ; sssctl domain-list
apq3h.test
ipaad2k16cin.test
ipasubad2k16cin.ipaad2k16cin.test
[root@oldenv1 ~]# 
[root@oldenv1 ~]# id aduser1
uid=879001109(aduser1) gid=879001109(aduser1) groups=879001109(aduser1),879001115(adunigroup1),879001114(adgroup2),879000513(domain users),879001113(adgroup1)
[root@oldenv1 ~]# date
Thu Jun 20 08:46:32 EDT 2019

[root@oldenv1 ~]# grep -F "Looking up [aduser1] in data provider" /var/log/sssd/sssd_nss.log 
(Thu Jun 20 08:46:28 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #21: Looking up [aduser1] in data provider
(Thu Jun 20 08:46:28 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #23: Looking up [aduser1] in data provider
[root@oldenv1 ~]# 


======================================================================================================================================================
latest version :
======================================================================================================================================================
[root@latest771 ~]# rpm -qa sssd
sssd-1.16.4-21.el7.x86_64
[root@latest771 ~]# grep -B 3 "filter_users" /etc/sssd/sssd.conf
[nss]
memcache_timeout = 600
homedir_substring = /home
filter_users = aduser1

[root@latest771 ~]# ipa config-show | grep resolution
  Domain resolution order: ipaad2k16cin.test:agkfl.test

[root@latest771 ~]# ipactl stop
Stopping ipa-dnskeysyncd Service
Stopping ipa-otpd Service
Stopping winbind Service
Stopping smb Service
Stopping pki-tomcatd Service
Stopping ntpd Service
Stopping ipa-custodia Service
Stopping httpd Service
Stopping named Service
Stopping kadmin Service
Stopping krb5kdc Service
Stopping Directory Service
ipa: INFO: The ipactl command was successful
[root@latest771 ~]# service sssd stop; rm -rf /var/lib/sss/{db,mc}/*; service sssd start
Redirecting to /bin/systemctl stop sssd.service
Redirecting to /bin/systemctl start sssd.service
[root@latest771 ~]# sssd start
SSSD is already running
[root@latest771 ~]# ipactl start
Starting Directory Service
Starting krb5kdc Service
Starting kadmin Service
Starting named Service
Starting httpd Service
Starting ipa-custodia Service
Starting ntpd Service
Starting pki-tomcatd Service
Starting smb Service
Starting winbind Service
Starting ipa-otpd Service
Starting ipa-dnskeysyncd Service
ipa: INFO: The ipactl command was successful
[root@latest771 ~]# sssctl domain-listagkfl.test
[root@latest771 ~]# sleep 60 
[root@latest771 ~]# sssctl domain-list
agkfl.test
ipaad2k16cin.test
ipasubad2k16cin.ipaad2k16cin.test
[root@latest771 ~]#  id aduser1
uid=879001109(aduser1) gid=879001109(aduser1) groups=879001109(aduser1),879001115(adunigroup1),879001114(adgroup2),879000513(domain users),879001113(adgroup1)
[root@latest771 ~]# date
Thu Jun 20 09:22:42 EDT 2019
[root@latest771 ~]# grep -F "Looking up [aduser1] in data provider" /var/log/sssd/sssd_nss.log
(Thu Jun 20 09:14:10 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #23: Looking up [aduser1] in data provider
(Thu Jun 20 09:14:10 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #25: Looking up [aduser1] in data provider
(Thu Jun 20 09:19:32 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #21: Looking up [aduser1] in data provider
(Thu Jun 20 09:19:33 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #23: Looking up [aduser1] in data provider
(Thu Jun 20 09:22:35 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #21: Looking up [aduser1] in data provider
(Thu Jun 20 09:22:35 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #23: Looking up [aduser1] in data provider
[root@latest771 ~]# 

Based on this moving into assigned state.

Comment 10 Sumit Bose 2019-06-25 12:05:58 UTC

Hi,

the test failed because the current patches do not handle known domains correctly. Can you try to verify e.g. with

    filter_user = some_user

(yes, literally 'some_user') that 

    id some_user

does not lead to any "Looking up [some_user] in data provider" messages in sssd_nss.log? And yes, it is expected that id will return 'No such user' here.

If that's work my suggestion would be to move this ticket to verified and open a new ticket to fix the issue with the known domains as well.

bye,
Sumit

Comment 11 Jakub Hrozek 2019-06-25 20:43:06 UTC

The additional patches were pushed as:

* master: e7e212b
* sssd-1-16:
  * 934341e
  * 05b37ac

Comment 12 anuja 2019-06-26 07:42:05 UTC

As per comment #10 Moving back to ON_QA

Comment 13 anuja 2019-06-26 07:47:04 UTC

======================================================================================================================================================
Older Version :
sssd-1.16.2-13.el7.x86_64
======================================================================================================================================================
[root@old1 ~]# rpm -qa sssd
sssd-1.16.2-13.el7.x86_64
[root@old1 ~]# grep -B 3 "filter_users" /etc/sssd/sssd.conf
[nss]
memcache_timeout = 600
homedir_substring = /home
filter_users = some_user
[root@old1 ~]# ipa config-show | grep resolution
  Domain resolution order: ipaad2k16cin.test:a44wf.test
[root@old1 ~]# ipactl stop
Stopping ipa-dnskeysyncd Service
Stopping ipa-otpd Service
Stopping winbind Service
Stopping smb Service
Stopping pki-tomcatd Service
Stopping ntpd Service
Stopping ipa-custodia Service
Stopping httpd Service
Stopping named Service
Stopping kadmin Service
Stopping krb5kdc Service
Stopping Directory Service
ipa: INFO: The ipactl command was successful
[root@old1 ~]# service sssd stop; rm -rf /var/lib/sss/{db,mc}/*; service sssd start
Redirecting to /bin/systemctl stop sssd.service
Redirecting to /bin/systemctl start sssd.service
[root@old1 ~]# sssd start
SSSD is already running
[root@old1 ~]# ipactl start
Starting Directory Service
Starting krb5kdc Service
Starting kadmin Service
Starting named Service
Starting httpd Service
Starting ipa-custodia Service
Starting ntpd Service
Starting pki-tomcatd Service
Starting smb Service
Starting winbind Service
Starting ipa-otpd Service
Starting ipa-dnskeysyncd Service
ipa: INFO: The ipactl command was successful
[root@old1 ~]# sssctl domain-list
a44wf.test
[root@old1 ~]# sleep 60 ; sssctl domain-list | grep -w "ipaad2k16cin.test"
ipaad2k16cin.test
ipasubad2k16cin.ipaad2k16cin.test
[root@old1 ~]# id some_user
id: some_user: no such user
[root@old1 ~]# grep -F "Looking up [some_user] in data provider" /var/log/sssd/sssd_nss.log
(Wed Jun 26 03:21:23 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #22: Looking up [some_user] in data provider
(Wed Jun 26 03:21:23 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #22: Looking up [some_user] in data provider
(Wed Jun 26 03:21:23 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #22: Looking up [some_user] in data provider
[root@old1 ~]# date
Wed Jun 26 03:22:26 EDT 2019

======================================================================================================================================================
latest version:
sssd-1.16.4-21.el7.x86_64
======================================================================================================================================================

[root@latest1 ~]# rpm -qa sssd
sssd-1.16.4-21.el7.x86_64
[root@latest1 ~]# ipa config-show | grep resolution
  Domain resolution order: ipaad2k16cin.test:akpep.test
[root@latest1 ~]# 

[root@latest1 ~]# grep -B 3 "filter_users" /etc/sssd/sssd.conf
[nss]
memcache_timeout = 600
homedir_substring = /home
filter_users = some_user
[root@latest1 ~]# ipactl stop
Stopping ipa-dnskeysyncd Service
Stopping ipa-otpd Service
Stopping pki-tomcatd Service
Stopping ntpd Service
Stopping ipa-custodia Service
Stopping httpd Service
Stopping named Service
Stopping kadmin Service
Stopping krb5kdc Service
Stopping Directory Service
ipa: INFO: The ipactl command was successful
[root@latest1 ~]# service sssd stop; rm -rf /var/lib/sss/{db,mc}/*; service sssd start
Redirecting to /bin/systemctl stop sssd.service
Redirecting to /bin/systemctl start sssd.service
[root@latest1 ~]# sssd start
SSSD is already running
[root@latest1 ~]# ipactl start
Starting Directory Service
Starting krb5kdc Service
Starting kadmin Service
Starting named Service
Starting httpd Service
Starting ipa-custodia Service
Starting ntpd Service
Starting pki-tomcatd Service
Starting smb Service
Starting winbind Service
Starting ipa-otpd Service
Starting ipa-dnskeysyncd Service
ipa: INFO: The ipactl command was successful
[root@latest1 ~]# sssctl domain-list | grep -w "ipaad2k16cin.test"
[root@latest1 ~]# sleep 60 ; sssctl domain-list | grep -w "ipaad2k16cin.test"
ipaad2k16cin.test
ipasubad2k16cin.ipaad2k16cin.test
[root@latest1 ~]# id some_user
id: some_user: no such user
[root@latest1 ~]# grep -F "Looking up [some_user] in data provider" /var/log/sssd/sssd_nss.log
[root@latest1 ~]# date
Wed Jun 26 03:36:50 EDT 2019
[root@latest1 ~]# grep -F "in data provider" /var/log/sssd/sssd_nss.log
...............
(Wed Jun 26 03:25:24 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #11: Looking up [apache] in data provider
(Wed Jun 26 03:25:26 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #12: Looking up [pkiuser] in data provider
(Wed Jun 26 03:25:28 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #13: Looking up [ntp] in data provider
(Wed Jun 26 03:25:28 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #14: Looking up [pkiuser] in data provider
(Wed Jun 26 03:25:33 2019) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #15: Looking up [ods] in data provider
[root@latest1 ~]# date
Wed Jun 26 03:37:15 EDT 2019
[root@latest1 ~]# grep -F "Looking up [some_user] in data provider" /var/log/sssd/sssd_nss.log
[root@latest1 ~]# echo $?
1
[root@latest1 ~]# 
======================================================================================================================================================

As per comment #10
In latest version there is no call log like "Looking up [some_user] in data provider" messages in sssd_nss.log
Based on This moving bz to verified.
And creating new bz to fix the issue with the known domains as well.

Comment 17 errata-xmlrpc 2019-08-06 13:02:47 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, 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/RHSA-2019:2177

Comment 18 James Hartsock 2019-08-08 19:22:11 UTC

Bugzilla not allowing solution link, so doing as comment:
https://bugzilla.redhat.com/show_bug.cgi?id=1724088