I didn't get a response in #sssd, so I figured I'll try here at the mail list.
# rpm -q sssd ipa-server
sssd-1.16.0-19.el7_5.5.x86_64
ipa-server-4.5.4-10.el7_5.3.x86_64
I've been scratching my head trying to resolve this particular issue. I'm having
issues with AD users where when they login, they'll get the UID/GID assigned in the ID
views correctly, but only some of the time. Other times, they won't get the id view
assigned to them. This is all done in the default trust view. What makes this issue even
more interesting is that out of my 6 domain controllers, sometimes it'll be one server
out of the six that does it, sometimes it's two. But it's never the same ones, so
it's difficult to track the particular issue down. What's even more interesting is
this is not occurring with some users (like my own). I have yet to see it occur with my
account or even the rest of my team's accounts. One of the things I tried to do is
delete the ID views of the offending users and recreate them to no avail.
I put SSSD into debug mode on the IPA servers and tried to get some relevant logs and such
to try and figure this out. Below is my SSSD configuration, ldb info, and debug logs
(removing private information where possible). I'm trying to determine if this is
either a bug within SSSD or if this is a misconfiguration on my part.
$ ldbsearch -H cache_ipa.example.com.ldb name=user.name(a)ad.example.com originalADuidNumber
uidNumber originalADgidNumber gidNumber
asq: Unable to register control with rootdse!
# record 1
dn: name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb
originalADuidNumber: 55616902
originalADgidNumber: 55616902
uidNumber: 55616902
gidNumber: 55616902
$ ipa idoverrideuser-show "Default Trust View" user.name(a)ad.example.com
Anchor to override: user.name(a)ad.example.com
UID: 40001
GID: 40001
Home directory: /home/user.name
Login shell: /bin/bash
$ ldbsearch -H timestamps_ipa.example.com.ldb | less
dn: name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb
objectCategory: user
originalModifyTimestamp: 20180823172515.0Z
entryUSN: 92632390
initgrExpireTimestamp: 1535133621
lastUpdate: 1535128235
dataExpireTimestamp: 1535133635
distinguishedName: name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb
## DEBUG LOGS
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_set_entry_attr] (0x0200):
Entry [name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb] has set
[ts_cache] attrs.
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): commit ldb
transaction (nesting: 0)
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_get_ad_override_connect_done]
(0x4000): Searching for overrides in view [Default Trust View] with filter
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-922099545-2851689246-2917073205-16902))].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_print_server] (0x2000):
Searching 172.20.23.190:389
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-922099545-2851689246-2917073205-16902))][cn=Default
Trust View,cn=views,cn=accounts,dc=ipa,dc=chotel,dc=com].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 32
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_op_add] (0x2000): New
operation 32 timeout 6
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: sh[0x55f30a5d1080], connected[1], ops[(nil)], ldap[0x55f30a5d0f90]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: end of ldap_result list
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: sh[0x55f30a5d1940], connected[1], ops[0x55f30a645310], ldap[0x55f30a5ce320]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_ENTRY]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [ipaanchoruuid=:SID:S-1-5-21-922099545-2851689246-2917073205-16902,cn=Default
Trust View,cn=views,cn=accounts,dc=ipa,dc=chotel,dc=com].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [objectClass]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [loginShell]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [uidNumber]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [ipaAnchorUUID]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [gidNumber]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [homeDirectory]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_parse_range] (0x2000): No
sub-attributes for [ipaOriginalUid]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: sh[0x55f30a5d1940], connected[1], ops[0x55f30a645310], ldap[0x55f30a5ce320]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_op_destructor] (0x2000):
Operation 32 finished
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_get_ad_override_done]
(0x4000): Found override for object with filter
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-922099545-2851689246-2917073205-16902))].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_id_op_destroy] (0x4000):
releasing operation connection
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_apply_default_override]
(0x4000): Override [uidNumber] with [40001] for
[name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_apply_default_override]
(0x0080): Override attribute for [gidNumber] has more [2] than one value, using only the
first.
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_apply_default_override]
(0x4000): Override [gidNumber] with [40001] for
[name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_apply_default_override]
(0x4000): Override [homeDirectory] with [/home/user.name] for
[name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_apply_default_override]
(0x4000): Override [loginShell] with [/bin/bash] for
[name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55f30a6819a0
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55f30a681a60
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Running timer event
0x55f30a6819a0 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Destroying timer
event 0x55f30a681a60 "ltdb_timeout"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Ending timer event
0x55f30a6819a0 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [safe_original_attributes]
(0x4000): Original object does not have [sshPublicKey] set.
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55f30a683c50
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55f30a683d10
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Running timer event
0x55f30a683c50 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Destroying timer
event 0x55f30a683d10 "ltdb_timeout"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Ending timer event
0x55f30a683c50 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_ldb_msg_difference]
(0x2000): Replaced/extended attr [uidNumber] of entry
[name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): start ldb
transaction (nesting: 0)
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55f30a68d1c0
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55f30a68d280
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Running timer event
0x55f30a68d1c0 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Destroying timer
event 0x55f30a68d280 "ltdb_timeout"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Ending timer event
0x55f30a68d1c0 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): commit ldb
transaction (nesting: 0)
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sysdb_set_entry_attr] (0x0200):
Entry [name=user.name(a)ad.example.com,cn=users,cn=ad.example.com,cn=sysdb] has set [cache,
ts_cache] attrs.
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55f30a68d330
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55f30a688900
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Running timer event
0x55f30a68d330 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55f30a689320
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55f30a6893e0
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Destroying timer
event 0x55f30a688900 "ltdb_timeout"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Ending timer event
0x55f30a68d330 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Running timer event
0x55f30a689320 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x55f30a634920
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x55f30a6349e0
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Destroying timer
event 0x55f30a6893e0 "ltdb_timeout"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Ending timer event
0x55f30a689320 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Running timer event
0x55f30a634920 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Destroying timer
event 0x55f30a6349e0 "ltdb_timeout"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ldb] (0x4000): Ending timer event
0x55f30a634920 "ltdb_callback"
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_initgr_get_overrides_step]
(0x1000): Processing group 0/1
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_initgr_get_overrides_step]
(0x1000): Fetching group S-1-5-21-922099545-2851689246-2917073205-20676
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_id_op_connect_step] (0x4000):
reusing cached connection
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_get_ad_override_connect_done]
(0x4000): Searching for overrides in view [Default Trust View] with filter
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-922099545-2851689246-2917073205-20676))].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_print_server] (0x2000):
Searching 172.20.23.190:389
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-922099545-2851689246-2917073205-20676))][cn=Default
Trust View,cn=views,cn=accounts,dc=ipa,dc=chotel,dc=com].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 33
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_op_add] (0x2000): New
operation 33 timeout 6
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: sh[0x55f30a5d1940], connected[1], ops[0x55f30a63f270], ldap[0x55f30a5ce320]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: end of ldap_result list
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_result] (0x2000):
Trace: sh[0x55f30a5d1940], connected[1], ops[0x55f30a63f270], ldap[0x55f30a5ce320]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_process_message] (0x4000):
Message type: [LDAP_RES_SEARCH_RESULT]
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_get_generic_op_finished]
(0x0400): Search result: Success(0), no errmsg set
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_op_destructor] (0x2000):
Operation 33 finished
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_get_ad_override_done]
(0x4000): No override found with filter
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-922099545-2851689246-2917073205-20676))].
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [sdap_id_op_destroy] (0x4000):
releasing operation connection
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_initgr_get_overrides_step]
(0x1000): Processing group 1/1
(Fri Aug 24 16:30:12 2018) [sssd[be[ipa.example.com]]] [ipa_get_ad_memberships_send]
(0x0400): External group information still valid.
## /etc/sssd/sssd.conf
[
domain/ipa.example.com]
cache_credentials = True
krb5_store_password_if_offline = True
# krb5_realm =
IPA.EXAMPLE.COM
ipa_domain =
ipa.example.com
ipa_hostname =
entl01.ipa.example.com
# Server Specific Settings
ipa_server =
entl01.ipa.example.com
ipa_server_mode = True
subdomain_homedir = %o
fallback_homedir = /home/%u
default_shell = /bin/bash
id_provider = ipa
auth_provider = ipa
access_provider = ipa
chpass_provider = ipa
ldap_tls_cacert = /etc/ipa/ca.crt
[sssd]
services = nss, sudo, pam, ssh
domains =
ipa.example.com
[nss]
filter_users =
root,ldap,named,avahi,haldaemon,dbus,radiusd,news,nscd,tomcat,activemq,informix,oracle,xdba,grid,dbadmin,weblogic,operator,postgres,devolog
memcache_timeout = 600
homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp]