On Пан, 12 лют 2024, Heidi Hough via FreeIPA-users wrote:
I appreciate the feedback. I added the ldap_search_timeout to both the server
and client sssd.conf files. I experimented with different values with no
additional success. Please find sanitized client and server sssd logs from my
login attempt with ldap_search_timeout = 30.
Client
https://privatebin.net/?8b3b376c2cf445ac#DwWqNUD96mcHqBYoNi7u97n9ZZ6ZNYeVDTrut6W91aK6
Server
https://privatebin.net/?f8a35b7c92fae546#DT3sHCD9kY7h3UZrRSBX8VbBkmccRCVkgguaX3NG6bDG
Hi,
it looks like you have restarted the server during the time when a
client request was issued. As a result, not only the server logs contain
no request information, it was not really served and thus failed:
from client side:
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]]
[dp_get_account_info_send] (0x0200): Got request for
[0x1][BE_REQ_USER][name=ad-he...@ad.contoso.com]
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [dp_attach_req]
(0x0400): [RID#2] DP Request [Account #2]: REQ_TRACE: New request. Flags
[0x0001].
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [dp_attach_req]
(0x0400): [RID#2] Number of active DP request: 1
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sss_domain_get_state]
(0x1000): [RID#2] Domain ipa.subdomain.contoso.com is Active
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sss_domain_get_state]
(0x1000): [RID#2] Domain ad.contoso.com is Active
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sss_domain_get_state]
(0x1000): [RID#2] Domain ipa.subdomain.contoso.com is Active
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sss_domain_get_state]
(0x1000): [RID#2] Domain ad.contoso.com is Active
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_print_server]
(0x2000): [RID#2] Searching 172.16.50.102:389
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_get_generic_ext_step]
(0x0400): [RID#2] calling ldap_search_ext with
[(&(objectClass=ipaUserOverride)(uid=ad-heidi))][cn=Default Trust
View,cn=views,cn=accounts,dc=ipa,dc
=subdomain,dc=contoso,dc=com].
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]]
[sdap_get_generic_ext_step] (0x2000): [RID#2] ldap_search_ext called, msgid = 14
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_op_add] (0x2000):
[RID#2] New operation 14 timeout 30
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_process_result]
(0x2000): Trace: sh[0x55c25d103380], connected[1], ops[0x55c25d17e390],
ldap[0x55c25d1006b0]
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]]
[sdap_get_generic_op_finished] (0x0400): [RID#2] Search result: Success(0), no
errmsg set
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_op_destructor]
(0x2000): [RID#2] Operation 14 finished
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sss_domain_get_state]
(0x1000): [RID#2] Domain ipa.subdomain.contoso.com is Active
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sss_domain_get_state]
(0x1000): [RID#2] Domain ad.contoso.com is Active
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]]
[ipa_s2n_get_acct_info_send] (0x0400): [RID#2] Sending request_type:
[REQ_FULL_WITH_MEMBERS] for trust user [ad-heidi] to IPA server
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [ipa_s2n_exop_send]
(0x0400): [RID#2] Executing extended operation
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [ipa_s2n_exop_send]
(0x2000): [RID#2] ldap_extended_operation sent, msgid = 15
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_op_add] (0x2000):
[RID#2] New operation 15 timeout 30
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_process_result]
(0x2000): Trace: sh[0x55c25d103380], connected[1], ops[0x55c25d17e390],
ldap[0x55c25d1006b0]
(2024-02-12 8:48:40): [be[ipa.subdomain.contoso.com]] [sdap_process_result]
(0x2000): Trace: end of ldap_result list
(2024-02-12 8:49:03): [be[ipa.subdomain.contoso.com]] [sdap_process_result]
(0x2000): Trace: sh[0x55c25d103380], connected[1], ops[0x55c25d17e390],
ldap[0x55c25d1006b0]
(2024-02-12 8:49:03): [be[ipa.subdomain.contoso.com]] [ipa_s2n_exop_done]
(0x0040): [RID#2] ldap_extended_operation result: Time limit exceeded(3),
(null).
The request is sent at 8:48:40. Assuming the time is the same, the
server side did not start at that point yet:
(2024-02-12 8:48:24): [be[ipa.subdomain.consoto.com]] [be_ptask_execute]
(0x0400): Task [Cleanup [id] of ad.contoso.com]: executing task, timeout 30
seconds
(2024-02-12 8:48:24): [be[ipa.subdomain.consoto.com]] [sysdb_cache_search_users]
(0x2000): Search users with filter:
(&(objectCategory=user)(&(!(dataExpireTimestamp=0))(dataExpireTimestamp<=1707756504)(!(lastLogin=*))))
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [server_setup]
(0x3f7c0): Starting with debug level = 0x3ff0
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [server_setup] (0x0400):
CONFDB: /var/lib/sss/db/config.ldb
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [dp_get_options]
(0x0400): Option lookup_family_order has value ipv4_first
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [dp_get_options]
(0x0400): Option dns_resolver_timeout has value 6
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [dp_get_options]
(0x0400): Option dns_resolver_op_timeout has value 3
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [dp_get_options]
(0x0400): Option dns_resolver_server_timeout has value 1000
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [dp_get_options]
(0x0400): Option dns_resolver_use_search_list is TRUE
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [dp_get_options]
(0x0400): Option dns_discovery_domain has no value
(2024-02-12 8:48:44): [be[ipa.subdomain.consoto.com]] [be_res_get_opts]
(0x0100): Lookup order: ipv4_first
So I suspect the request got simply lost.
SSSD on the client sends LDAP search with a specific control to LDAP
server. This request is taken care of by a plugin in LDAP server code
which issues a local request to SSSD using its API. It should be visible
in the sss_nss.log but there is no such activity at 8:48:40:
(2024-02-12 8:48:13): [nss] [server_setup] (0x3f7c0): Starting with debug
level = 0x0070
(2024-02-12 8:48:44): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): CR
#2: Could not get account info [1432158213]: Terminated
(2024-02-12 8:48:45): [nss] [cache_req_common_process_dp_reply] (0x3f7c0):
[CID#1] CR #4: Could not get account info [1432158212]: SSSD is offline
(2024-02-12 8:48:45): [nss] [cache_req_common_process_dp_reply] (0x3f7c0):
[CID#1] CR #5: Could not get account info [1432158212]: SSSD is offline
(2024-02-12 8:49:15): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): CR
#11: Could not get account info [1432158213]: Terminated
(2024-02-12 8:49:22): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): CR
#13: Could not get account info [1432158213]: Terminated
(2024-02-12 8:49:47): [nss] [sbus_dbus_connect_address] (0x0020): Unable to
register to
unix:path=/var/lib/sss/pipes/private/sbus-dp_ipa.subdomain.contoso.com
[org.freedesktop.DBus.Error.NoReply]: Did not receive a reply. Possible
causes include: the remote application did not send a reply, the message bus
security policy blocked the reply, the reply timeout expired, or the network
connection was broken.
If you are restarting sssd on the server, I'd suggest to wait a bit
until it settles down with its configuration first. Then you can issue a
client request and collect logs.
Thanks
Heidi
--
_______________________________________________
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
--
/ 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
