CentOS 7.8
SSSD 1.16.4

Having a strange issue where the ldap_access_filter seems to be applied to some 
users and not others when they are both logging into the same application that 
is using the underlying OS PAM configuration. Below are the excerpts from the 
logs:

USERA log entires:
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object USERA
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user USERA@default
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [USERA@default].
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [USERA@default].
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Storing info for user USERA@default
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(memberuid=USERA)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:3::default:name=USERA@default] from reply table
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_access_send] (0x0400): 
Performing access check for user [USERA@default]
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_access_filter_send] 
(0x0400): Performing access filter check for user [USERA@default]
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=posixAccount)(objectClass=posixAccount)(accountActive=TRUE)(|(allowedService=unixAdmin)(allowedService=USERA)(allowedService=USERAAdmin)))][uid=USERA,ou=posixAccounts,ou=Apps,dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [dp_get_account_info_handler] 
(0x0200): Got request for [0x2][BE_REQ_GROUP][name=USERAadmin@default]
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(cn=USERAadmin)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object USERAadmin
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_save_group] (0x0400): 
Processing group USERAadmin@default
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [sdap_save_group] (0x0400): 
Storing info for group USERAadmin@default
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:2::default:name=USERAadmin@default] from reply 
table
(Fri May 15 12:35:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [dp_get_account_info_handler] 
(0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=USERA@default]
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object USERA
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user USERA@default
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [USERA@default].
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [USERA@default].
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Storing info for user USERA@default
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(memberuid=USERA)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:3::default:name=USERA@default] from reply table
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_access_send] (0x0400): 
Performing access check for user [USERA@default]
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_access_filter_send] 
(0x0400): Performing access filter check for user [USERA@default]
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=posixAccount)(objectClass=posixAccount)(accountActive=TRUE)(|(allowedService=unixAdmin)(allowedService=USERA)(allowedService=USERAAdmin)))][uid=USERA,ou=posixAccounts,ou=Apps,dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:40:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [dp_get_account_info_handler] 
(0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=USERA@default]
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object USERA
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user USERA@default
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [USERA@default].
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [USERA@default].
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Storing info for user USERA@default
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(memberuid=USERA)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:3::default:name=USERA@default] from reply table
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_access_send] (0x0400): 
Performing access check for user [USERA@default]
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_access_filter_send] 
(0x0400): Performing access filter check for user [USERA@default]
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=posixAccount)(objectClass=posixAccount)(accountActive=TRUE)(|(allowedService=unixAdmin)(allowedService=USERA)(allowedService=USERAAdmin)))][uid=USERA,ou=posixAccounts,ou=Apps,dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:45:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [dp_get_account_info_handler] 
(0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=USERA@default]
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object USERA
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user USERA@default
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [USERA@default].
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [USERA@default].
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Storing info for user USERA@default
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(memberuid=USERA)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:3::default:name=USERA@default] from reply table
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_access_send] (0x0400): 
Performing access check for user [USERA@default]
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_access_filter_send] 
(0x0400): Performing access filter check for user [USERA@default]
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=USERA)(objectclass=ObjectClassA)(objectClass=ObjectClassB)(AttributeA=TRUE)(|(AttributeB=ServiceC)(AttributeC=ServiceA)(AttributeC=ServiceB)))][uid=USERA,ou=OUA,ou=OUB,dc=DOMAIN,dc=SUFFIX].
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=USERA@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] 
attrs.
(Fri May 15 12:50:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default
(Fri May 15 12:50:02 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
USERA@default


USERB log entries:

(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object emu
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user emu@default
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [emu@default].
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [emu@default].
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Storing info for user emu@default
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=emu@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] attrs.
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(memberuid=emu)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=emu@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] attrs.
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:3::default:name=emu@default] from reply table
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
emu@default
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_access_send] (0x0400): 
Performing access check for user [emu@default]
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_access_filter_send] 
(0x0400): Performing access filter check for user [emu@default]
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=emu)(objectclass=posixAccount)(objectClass=posixAccount)(accountActive=TRUE)(|(allowedService=unixAdmin)(allowedService=EMU)(allowedService=EMUAdmin)))][uid=emu,ou=posixAccounts,ou=Apps,dc=DOMAIN,dc=SUFFIX].
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=emu@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] attrs.
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
emu@default
(Fri May 15 10:35:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
emu@default
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [dp_get_account_info_handler] 
(0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=emu@default]
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=emu)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object emu
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user emu@default
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [emu@default].
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [emu@default].
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Storing info for user emu@default
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=emu@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] attrs.
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(memberuid=emu)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=emu@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] attrs.
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [dp_table_value_destructor] 
(0x0400): Removing [0:1:0x0001:3::default:name=emu@default] from reply table
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
emu@default
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_access_send] (0x0400): 
Performing access check for user [emu@default]
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_access_filter_send] 
(0x0400): Performing access filter check for user [emu@default]
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=emu)(objectclass=posixAccount)(objectClass=posixAccount)(accountActive=TRUE)(|(allowedService=unixAdmin)(allowedService=EMU)(allowedService=EMUAdmin)))][uid=emu,ou=posixAccounts,ou=Apps,dc=DOMAIN,dc=SUFFIX].
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [sysdb_set_entry_attr] (0x0200): 
Entry [name=emu@default,cn=users,cn=default,cn=sysdb] has set [ts_cache] attrs.
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
emu@default
(Fri May 15 10:40:01 2020) [sssd[be[default]]] [pam_print_data] (0x0100): user: 
emu@default
(Fri May 15 10:40:10 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object emu
(Fri May 15 10:40:10 2020) [sssd[be[default]]] [sdap_save_group] (0x0400): 
Processing group emu@default
(Fri May 15 10:40:10 2020) [sssd[be[default]]] [sdap_save_group] (0x0400): 
Storing info for group emu@default
(Fri May 15 10:40:53 2020) [sssd[be[default]]] [dp_get_account_info_handler] 
(0x0200): Got request for [0x3][BE_REQ_INITGROUPS][name=emu@default]
(Fri May 15 10:40:53 2020) [sssd[be[default]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with 
[(&(uid=emu)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][dc=DOMAIN,dc=SUFFIX].
(Fri May 15 10:40:53 2020) [sssd[be[default]]] [sdap_get_primary_name] 
(0x0400): Processing object emu
(Fri May 15 10:40:53 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Processing user emu@default
(Fri May 15 10:40:53 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): 
Original memberOf is not available for [emu@default].
(Fri May 15 10:40:53 2020) [sssd[be[default]]] [sdap_save_user] (0x0400): User 
principal is not available for [emu@default].

As you can see from the 2 log excerpts USERB never has the ldap_access_filter 
check applied while it is done for USERA. Has anyone encounted this before?

Thank you,

Sajesh


_______________________________________________
sssd-users mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Fedora Code of Conduct: 
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: 
https://lists.fedorahosted.org/archives/list/[email protected]

Reply via email to