Description of problem:


There's a sudo rule defined for a group named "Domain Admins" (default group in AD). This rule doesn't work when the cache is new (either newly configured machine / removing cache files). After running id -nG (the n is significant), the problem goes away. This happens on SSSD 1.14.0-43.el7_3.18 (CentOS 7.3).

I have the following configuration:

[domain/cb.local]
access_provider = ad
ad_domain = cb.local
cache_credentials = True
default_shell = /bin/bash
id_provider = ad
krb5_realm = CB.LOCAL
krb5_store_password_if_offline = True
ldap_user_ssh_public_key = sshPublicKeys
override_homedir = /home/%u
realmd_tags = manages-system joined-with-adcli
use_fully_qualified_names = False
debug_level = 8

[ssh]

[sssd]
config_file_version = 2
domains = cb.local
services = nss, pam, ssh, sudo

[sudo]
debug_level = 8

On running sudo .., in the sudo logs I see the following query: (note the SIDs)

sssd_sudo.log
(Thu Jul 27 13:51:53 2017) [sssd[sudo]] [sudosrv_query_cache] (0x0200): Searching sysdb with [(&(objectClass=sudoRule)(dataExpireTimestamp<=1501156313)(|(name=defaults)(sudoUser=ALL)(sudoUser=bhaarsma@cb.local)(sudoUser=#83601104)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-572@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-518@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-513@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-1107@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-512@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-513@cb.local)(sudoUser=+*)))]
(Thu Jul 27 13:51:53 2017) [sssd[sudo]] [sudosrv_refresh_rules_send] (0x0400): No expired rules were found for [bhaarsma@cb.local@cb.local].
(Thu Jul 27 13:51:53 2017) [sssd[sudo]] [sudosrv_fetch_rules] (0x0400): Retrieving rules for [bhaarsma@cb.local@cb.local]
(Thu Jul 27 13:51:53 2017) [sssd[sudo]] [sudosrv_query_cache] (0x0200): Searching sysdb with [(&(objectClass=sudoRule)(|(sudoUser=ALL)(sudoUser=bhaarsma@cb.local)(sudoUser=#83601104)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-572@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-518@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-513@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-1107@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-512@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-513@cb.local)))]
(Thu Jul 27 13:51:53 2017) [sssd[sudo]] [sudosrv_cached_rules_by_user] (0x0400): Replacing sudoUser attribute with sudoUser: #83601104
(Thu Jul 27 13:51:53 2017) [sssd[sudo]] [sudosrv_query_cache] (0x0200): Searching sysdb with [(&(objectClass=sudoRule)(sudoUser=+*)(!(|(sudoUser=ALL)(sudoUser=bhaarsma@cb.local)(sudoUser=#83601104)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-572@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-518@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-513@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-1107@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-512@cb.local)(sudoUser=%S-1-5-21-2868460407-4237694160-164503905-513@cb.local))))]

Meanwhile in the sssd log:

sssd_cb.local.log
(Thu Jul 27 13:51:53 2017) [sssd[be[cb.local]]] [sdap_ad_save_group_membership_with_idmapping] (0x1000): Processing membership SID [S-1-5-21-2868460407-4237694160-164503905-512]
(Thu Jul 27 13:51:53 2017) [sssd[be[cb.local]]] [sdap_ad_save_group_membership_with_idmapping] (0x1000): SID [S-1-5-21-2868460407-4237694160-164503905-512] maps to GID [83600512]
(Thu Jul 27 13:51:53 2017) [sssd[be[cb.local]]] [sysdb_search_group_by_gid] (0x0400): No such entry

Now when I run id -nG, the following shows up in the logs:

sssd_cb.local.log
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_print_server] (0x2000): Searching 10.233.3.17:389
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(objectSID=S-1-5-21-2868460407-4237694160-164503905-512)(objectClass=group)(sAMAccountName=*))][DC=cb,DC=local].
(...)
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results.
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_has_deref_support] (0x0400): The server supports deref method ASQ
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_nested_group_hash_group] (0x2000): Marking group as non-posix and setting GID=0!
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_nested_group_process_send] (0x2000): About to process group [CN=Domain Admins,CN=Users,DC=cb,DC=local]
(...)
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_nested_group_process_send] (0x2000): Looking up 3/4 members of group [CN=Domain Admins,CN=Users,DC=cb,DC=local]
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_nested_group_process_send] (0x2000): Members of group [CN=Domain Admins,CN=Users,DC=cb,DC=local] will be processed individually
(...)
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_get_primary_name] (0x0400): Processing object Domain Admins
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_save_group] (0x0400): Processing group Domain Admins@cb.local
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_save_group] (0x1000): Mapping group [Domain Admins@cb.local] objectSID [S-1-5-21-2868460407-4237694160-164503905-512] to unix ID
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original DN [CN=Domain\20Admins,CN=Users,DC=cb,DC=local] to attributes of [Domain Admins@cb.local].
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20170708181452.0Z] to attributes of [Domain Admins@cb.local].
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_process_ghost_members] (0x0400): The group has 4 members
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_process_ghost_members] (0x0400): Group has 4 members
(...)
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_save_group] (0x0400): Storing info for group Domain Admins@cb.local
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_check_ts_cache] (0x2000): Cannot find TS cache entry for [name=Domain Admins@cb.local,cn=groups,cn=cb.local,cn=sysdb]: [2]: No such file or directory
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_check_and_update_ts_cache] (0x2000): No timestamps entry
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_search_by_name] (0x0400): No such entry
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_store_group] (0x1000): Group Domain Admins@cb.local does not exist.
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_add_group] (0x1000): Group with the same gid exists: [83600512].
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_add_group] (0x0400): Error: 17 (File exists)
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_store_new_group] (0x1000): sysdb_add_group failed: [EEXIST].
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_delete_entry] (0x0080): sysdb_delete_ts_entry failed: 0
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_store_new_group] (0x0400): A group with the same GID [83600512] was removed from the cache
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_search_group_by_gid] (0x0400): No such entry
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_get_primary_name] (0x0400): Processing object Domain Admins
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_save_grpmem] (0x0400): Processing group Domain Admins@cb.local
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_cache_search_users] (0x2000): Search users with filter: (&(objectclass=user)(gidNumber=83600512))
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sysdb_cache_search_users] (0x2000): No such entry
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_save_grpmem] (0x0400): Adding member users to group [Domain Admins@cb.local]
(...)
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_nested_done] (0x2000): No external members, done(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [dp_req_done] (0x0400): DP Request [Account #4]: Request handler finished [0]: Success
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [_dp_req_recv] (0x0400): DP Request [Account #4]: Receiving request data.
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #4]: Finished. Success.
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [dp_req_reply_std] (0x1000): DP Request [Account #4]: Returning [Success]: 0,0,Success
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:2:1::cb.local:idnumber=83600512] from reply table
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [dp_req_destructor] (0x0400): DP Request [Account #4]: Request removed.
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_process_result] (0x2000): Trace: sh[0x7f81f485d3c0], connected[1], ops[(nil)], ldap[0x7f81f488ab30]
(Thu Jul 27 13:52:04 2017) [sssd[be[cb.local]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list

And now when running sudo ..., it no longer queries for SIDs:

sssd_sudo.log
(Thu Jul 27 13:52:40 2017) [sssd[sudo]] [sudosrv_query_cache] (0x0200): Searching sysdb with [(&(objectClass=sudoRule)(|(sudoUser=ALL)(sudoUser=bhaarsma@cb.local)(sudoUser=#83601104)(sudoUser=%Domain\20Admins@cb.local)(sudoUser=%Schema\20Admins@cb.local)(sudoUser=%Domain\20Users@cb.local)(sudoUser=%Denied\20RODC\20Password\20Replication\20Group@cb.local)(sudoUser=%VPN\20Users@cb.local)(sudoUser=%Domain\20Users@cb.local)))]

The cache item for "Domain Admins" before running id -nG look like:

# record 12
dn: name=S-1-5-21-2868460407-4237694160-164503905-512@cb.local,cn=groups,cn=cb.local,cn=sysdb
createTimestamp: 1501157472
gidNumber: 83600512
name: S-1-5-21-2868460407-4237694160-164503905-512@cb.local
objectClass: group
lastUpdate: 1501157472
dataExpireTimestamp: 1501157471
isPosix: FALSE
objectSIDString: S-1-5-21-2868460407-4237694160-164503905-512
(member/memberuid... 1 member)
distinguishedName: name=S-1-5-21-2868460407-4237694160-164503905-512@cb.local,
 cn=groups,cn=cb.local,cn=sysdb

And afterwards:

# record 3
dn: name=Domain Admins@cb.local,cn=groups,cn=cb.local,cn=sysdb
createTimestamp: 1501157510
gidNumber: 83600512
name: Domain Admins@cb.local
objectClass: group
objectSIDString: S-1-5-21-2868460407-4237694160-164503905-512
uniqueID: d6553f26-553c-42ff-a1ef-85259cdf8f72
originalDN: CN=Domain Admins,CN=Users,DC=cb,DC=local
originalModifyTimestamp: 20170708181452.0Z
entryUSN: 13268
orig_member: (... 4 entries)
ghost: vpnadmin@cb.local
ghost: rspijker@cb.local
ghost: Administrator@cb.local
nameAlias: domain admins@cb.local
isPosix: TRUE
lastUpdate: 1501157510
dataExpireTimestamp: 1501162910
(member/memberuid... 1 member)
memberof: name=Denied RODC Password Replication Group@cb.local,cn=groups,cn=cb
 .local,cn=sysdb
distinguishedName: name=Domain Admins@cb.local,cn=groups,cn=cb.local,cn=sysdb



Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info: