On Чцв, 15 лют 2024, Heidi Hough via FreeIPA-users wrote:
You are correct, debugging was only specified in the [domain/...] section. I
have enabled for nss and gathered logs again. The client and server times are
indeed in sync.
I initiated my login attempt at approximately 10:16:30. At approximately
10:17:10 I was presented with a prompt to enter my password. After entering my
password I was again presented with a password prompt. After entering multiple
times with no success I waited and eventually the connection attempt timed out.
Server Logs for this attempt
https://privatebin.net/?74adb14729c459fc#EhqWm6x2LVgfnL7iAmLZDFh3TtXpwgsH9wjUfWQYrGyS
Client Logs for this attempt
https://privatebin.net/?1d3532466812bef2#C6ECF2RnRMEXVi7HGLd8iYvhoSmEw2uRs88neb2MG3RQ
It seems like a considerable amount of time is spent searching the AD
groups a user is a member of. For testing purposes, an AD account was
created that is not a member of any groups. This user was able to
successfully log in. What additional steps should be taken to account
for AD's where users are members of many groups? To add to the
complexity, many of these groups are nested.
If time to resolve all groups is above 10 seconds, then you might want
to increase timeouts. There are three elements in a lookup:
- SSSD on the client to IPA server's LDAP server
- IPA server's LDAP server to local SSSD on the IPA server
- SSSD on the IPA server to AD DCs
The middle one (LDAP server plugin to local SSSD) should have a timeout
that covers time spent in resolving the most complex query issued to AD
DCs. SSSD on the client should be able to handle at least that timeout
too.
I've reviewed this document (https://access.redhat.com/articles/2133801) and
spent time adjusting parameters with little success.
The sssd.conf on both client and server include the following in the
[domain/...] section:
subdomain_inherit = ignore_group_members
ignore_group_members = True
Should these be placed somewhere else instead? Are there other options
that should be set to account for large numbers of nested AD groups?
No, these should be OK. The only potential change you might want to do
is to bump a timeout used by the ipa-exdom-extop plugin when it talks to
the SSSD on the server side:
https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/9/html/tuning_performance_in_identity_management/assembly_tuning-sssd-performance-for-large-idm-ad-trust-deployments_tuning-performance-in-idm#proc_tuning-the-config-timeout-for-the-ipa-extdom-plugin-on-idm-servers_assembly_tuning-sssd-performance-for-large-idm-ad-trust-deployments
It is 10 seconds by default but in your case it looks like the whole set
of operations to reverse resolve all those groups takes around 20-26
seconds. Notice the diffs between 'Looking up ...' and 'Object found,
but needs to be refreshed', most are within the same second but few are
requiring up to 5 seconds. These are actions to do 'initgroups'
operation which is typically run by the client side when you log in, to
build a list of secondary groups for your login process. I guess a first
login would require a lot time due to this information being not yet
available but consequent ones would take much lower time.
$ grep 'CID#8' sssd_nss.log |grep -E '(Looking up|but needs)'
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #31:
Looking up heidi...@ad.contoso.com
(2024-02-14 10:16:30): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #31:
Looking up [heidi...@ad.contoso.com] in cache
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #31:
Object found, but needs to be refreshed.
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #32:
Looking up heidi...@ad.contoso.com
(2024-02-14 10:16:30): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #32:
Looking up [heidi...@ad.contoso.com] in cache
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #32:
Object found, but needs to be refreshed.
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #33:
Looking up heidi...@ad.contoso.com
(2024-02-14 10:16:30): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #33:
Looking up [heidi...@ad.contoso.com] in cache
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #33:
Object found, but needs to be refreshed.
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #34:
Looking up GID:603892...@ad.contoso.com
(2024-02-14 10:16:30): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #34:
Looking up [GID:603892...@ad.contoso.com] in cache
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #34:
Object found, but needs to be refreshed.
(2024-02-14 10:16:30): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #35:
Looking up GID:602655...@ad.contoso.com
(2024-02-14 10:16:30): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #35:
Looking up [GID:602655...@ad.contoso.com] in cache
(2024-02-14 10:16:31): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #35:
Object found, but needs to be refreshed.
(2024-02-14 10:16:31): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #36:
Looking up GID:604961...@ad.contoso.com
(2024-02-14 10:16:31): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #36:
Looking up [GID:604961...@ad.contoso.com] in cache
(2024-02-14 10:16:31): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #36:
Object found, but needs to be refreshed.
(2024-02-14 10:16:31): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #37:
Looking up GID:602655...@ad.contoso.com
(2024-02-14 10:16:31): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #37:
Looking up [GID:602655...@ad.contoso.com] in cache
(2024-02-14 10:16:31): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #37:
Object found, but needs to be refreshed.
(2024-02-14 10:16:31): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #38:
Looking up GID:604859...@ad.contoso.com
(2024-02-14 10:16:31): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #38:
Looking up [GID:604859...@ad.contoso.com] in cache
(2024-02-14 10:16:34): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #38:
Object found, but needs to be refreshed.
(2024-02-14 10:16:34): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #39:
Looking up GID:604965...@ad.contoso.com
(2024-02-14 10:16:34): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #39:
Looking up [GID:604965...@ad.contoso.com] in cache
(2024-02-14 10:16:39): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #39:
Object found, but needs to be refreshed.
(2024-02-14 10:16:39): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #40:
Looking up GID:605125...@ad.contoso.com
(2024-02-14 10:16:39): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #40:
Looking up [GID:605125...@ad.contoso.com] in cache
(2024-02-14 10:16:39): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #40:
Object found, but needs to be refreshed.
(2024-02-14 10:16:39): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #41:
Looking up GID:601449...@ad.contoso.com
(2024-02-14 10:16:39): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #41:
Looking up [GID:601449...@ad.contoso.com] in cache
(2024-02-14 10:16:39): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #41:
Object found, but needs to be refreshed.
(2024-02-14 10:16:39): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #42:
Looking up GID:604750...@ad.contoso.com
(2024-02-14 10:16:39): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #42:
Looking up [GID:604750...@ad.contoso.com] in cache
(2024-02-14 10:16:40): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #42:
Object found, but needs to be refreshed.
(2024-02-14 10:16:40): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #43:
Looking up GID:605323...@ad.contoso.com
(2024-02-14 10:16:40): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #43:
Looking up [GID:605323...@ad.contoso.com] in cache
(2024-02-14 10:16:42): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #43:
Object found, but needs to be refreshed.
(2024-02-14 10:16:42): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #44:
Looking up GID:605323...@ad.contoso.com
(2024-02-14 10:16:42): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #44:
Looking up [GID:605323...@ad.contoso.com] in cache
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #44:
Object found, but needs to be refreshed.
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #46:
Looking up GID:604874...@ad.contoso.com
(2024-02-14 10:16:44): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #46:
Looking up [GID:604874...@ad.contoso.com] in cache
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #46:
Object found, but needs to be refreshed.
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #47:
Looking up GID:604954...@ad.contoso.com
(2024-02-14 10:16:44): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #47:
Looking up [GID:604954...@ad.contoso.com] in cache
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #47:
Object found, but needs to be refreshed.
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #49:
Looking up GID:604962...@ad.contoso.com
(2024-02-14 10:16:44): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #49:
Looking up [GID:604962...@ad.contoso.com] in cache
(2024-02-14 10:16:44): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #49:
Object found, but needs to be refreshed.
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #51:
Looking up GID:605156...@ad.contoso.com
(2024-02-14 10:16:45): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #51:
Looking up [GID:605156...@ad.contoso.com] in cache
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #51:
Object found, but needs to be refreshed.
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #53:
Looking up GID:605150...@ad.contoso.com
(2024-02-14 10:16:45): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #53:
Looking up [GID:605150...@ad.contoso.com] in cache
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #53:
Object found, but needs to be refreshed.
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #55:
Looking up GID:604144...@ad.contoso.com
(2024-02-14 10:16:45): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #55:
Looking up [GID:604144...@ad.contoso.com] in cache
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #55:
Object found, but needs to be refreshed.
(2024-02-14 10:16:45): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #57:
Looking up GID:605251...@ad.contoso.com
(2024-02-14 10:16:45): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #57:
Looking up [GID:605251...@ad.contoso.com] in cache
(2024-02-14 10:16:46): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #57:
Object found, but needs to be refreshed.
(2024-02-14 10:16:46): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #59:
Looking up GID:605131...@ad.contoso.com
(2024-02-14 10:16:46): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #59:
Looking up [GID:605131...@ad.contoso.com] in cache
(2024-02-14 10:16:46): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #59:
Object found, but needs to be refreshed.
(2024-02-14 10:16:46): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #61:
Looking up GID:604758...@ad.contoso.com
(2024-02-14 10:16:46): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #61:
Looking up [GID:604758...@ad.contoso.com] in cache
(2024-02-14 10:16:46): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #61:
Object found, but needs to be refreshed.
(2024-02-14 10:16:46): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #63:
Looking up GID:602656...@ad.contoso.com
(2024-02-14 10:16:46): [nss] [cache_req_search_cache] (0x0400): [CID#8] CR #63:
Looking up [GID:602656...@ad.contoso.com] in cache
(2024-02-14 10:16:52): [nss] [cache_req_search_send] (0x0400): [CID#8] CR #63:
Object found, but needs to be refreshed.
--
/ Alexander Bokovoy
Sr. Principal Software Engineer
Security / Identity Management Engineering
Red Hat Limited, Finland
--
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
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/freeipa-users@lists.fedorahosted.org
Do not reply to spam, report it:
https://pagure.io/fedora-infrastructure/new_issue
