Disabled Domain fills IPA client sssd logs - FreeIPA-users - Fedora Mailing-Lists

2024

2023

2022

2021

2020

2019

2018

2017

Disabled Domain fills IPA client sssd logs

New primary rid range overlaps...

Eliminating Basic Auth Prompt When...

Ronald Wimmer

Thursday, 16 February 2023 Thu, 16 Feb '23

5:14 a.m.

We do face the problem that we disabled a domain we do not need and that this particular domain fills up sssd logs on the client side. Especially sssd_nss.log. How could we possibly avoid this behavior? Cheers, Ronald

Reply

Show replies by thread

Sumit Bose

Thursday, 16 February Thu, 16 Feb

5:18 a.m.

Am Thu, Feb 16, 2023 at 12:14:02PM +0100 schrieb Ronald Wimmer via FreeIPA-users:

We do face the problem that we disabled a domain we do not need and that this particular domain fills up sssd logs on the client side. Especially sssd_nss.log. How could we possibly avoid this behavior?

Hi, are you using the default debug level or did you set debug_level explicitly in sssd.conf? Can you give some examples of the debug message? bye, Sumit

Cheers, Ronald _______________________________________________ FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave(a)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.fedoraho... Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue

Reply

Ronald Wimmer

Friday, 17 February Fri, 17 Feb

1:51 a.m.

On 16.02.23 12:18, Sumit Bose wrote:

Am Thu, Feb 16, 2023 at 12:14:02PM +0100 schrieb Ronald Wimmer via FreeIPA-users: > We do face the problem that we disabled a domain we do not need and that > this particular domain fills up sssd logs on the client side. Especially > sssd_nss.log. How could we possibly avoid this behavior? Hi, are you using the default debug level or did you set debug_level explicitly in sssd.conf? Can you give some examples of the debug message?

I raised the debug level. sssd_nss.log fills up with (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): Entering request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: 0x5610c6660820 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR #18: Data Provider Error: 3, 5, Failed to get reply from Data Provider (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR #18: Due to an error we will return cached data (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: Looking up [UID:1000@tk.MYDOMAIN.at] in cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: Object [UID:1000@tk.MYDOMAIN.at] was not found in cache (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR #18: Finished: Not found (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain buero.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain org.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain tk.MYDOMAIN.at is Disabled (2023-02-17 8:44:52): [nss] [nss_protocol_done] (0x4000): Sending reply: not found (2023-02-17 8:44:52): [nss] [sss_dp_req_destructor] (0x0400): Deleting request: [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [nss_getby_id] (0x0400): Input ID: 1000 (2023-02-17 8:44:52): [nss] [cache_req_set_plugin] (0x2000): CR #19: Setting "User by ID" plugin (2023-02-17 8:44:52): [nss] [cache_req_send] (0x0400): CR #19: New request 'User by ID' (2023-02-17 8:44:52): [nss] [cache_req_select_domains] (0x0400): CR #19: Performing a multi-domain search (2023-02-17 8:44:52): [nss] [cache_req_search_domains] (0x0400): CR #19: Search will check the cache and check the data provider (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain org.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@org.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/org.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@org.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain linux.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@linux.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/linux.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@linux.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain buero.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@buero.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/buero.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@buero.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain tk.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@tk.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/tk.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@tk.MYDOMAIN.at] is not present in negative cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Looking up [UID:1000@tk.MYDOMAIN.at] in cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Object [UID:1000@tk.MYDOMAIN.at] was not found in cache (2023-02-17 8:44:52): [nss] [cache_req_search_dp] (0x0400): CR #19: Looking up [UID:1000@tk.MYDOMAIN.at] in data provider (2023-02-17 8:44:52): [nss] [sss_dp_issue_request] (0x0400): Issuing request for [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): Entering request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: 0x5610c6660820 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR #19: Data Provider Error: 3, 5, Failed to get reply from Data Provider (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR #19: Due to an error we will return cached data (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Looking up [UID:1000@tk.MYDOMAIN.at] in cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Object [UID:1000@tk.MYDOMAIN.at] was not found in cache (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR #19: Finished: Not found (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain buero.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain org.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain tk.MYDOMAIN.at is Disabled (2023-02-17 8:44:52): [nss] [nss_protocol_done] (0x4000): Sending reply: not found (2023-02-17 8:44:52): [nss] [sss_dp_req_destructor] (0x0400): Deleting request: [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [nss_getby_id] (0x0400): Input ID: 1000 (2023-02-17 8:44:52): [nss] [cache_req_set_plugin] (0x2000): CR #20: Setting "User by ID" plugin (2023-02-17 8:44:52): [nss] [cache_req_send] (0x0400): CR #20: New request 'User by ID' (2023-02-17 8:44:52): [nss] [cache_req_select_domains] (0x0400): CR #20: Performing a multi-domain search (2023-02-17 8:44:52): [nss] [cache_req_search_domains] (0x0400): CR #20: Search will check the cache and check the data provider (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain org.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@org.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/org.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@org.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain linux.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@linux.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/linux.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@linux.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain buero.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@buero.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/buero.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@buero.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain tk.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@tk.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/tk.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@tk.MYDOMAIN.at] is not present in negative cache As it is very hard for me to read the logfile with that debug_level I hope this snippet is sufficient... Pls let me know if not. Cheers, Ronald

Reply

Sumit Bose

2:51 a.m.

Am Fri, Feb 17, 2023 at 08:51:03AM +0100 schrieb Ronald Wimmer:

On 16.02.23 12:18, Sumit Bose wrote: > Am Thu, Feb 16, 2023 at 12:14:02PM +0100 schrieb Ronald Wimmer via FreeIPA-users: > > We do face the problem that we disabled a domain we do not need and that > > this particular domain fills up sssd logs on the client side. Especially > > sssd_nss.log. How could we possibly avoid this behavior? > > Hi, > > are you using the default debug level or did you set debug_level > explicitly in sssd.conf? > > Can you give some examples of the debug message? I raised the debug level. sssd_nss.log fills up with (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): Entering request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: 0x5610c6660820 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR #18: Data Provider Error: 3, 5, Failed to get reply from Data Provider (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR #18: Due to an error we will return cached data (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: Looking up [UID:1000@tk.MYDOMAIN.at] in cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: Object [UID:1000@tk.MYDOMAIN.at] was not found in cache (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR #18: Finished: Not found (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain buero.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain org.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain tk.MYDOMAIN.at is Disabled (2023-02-17 8:44:52): [nss] [nss_protocol_done] (0x4000): Sending reply: not found (2023-02-17 8:44:52): [nss] [sss_dp_req_destructor] (0x0400): Deleting request: [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [nss_getby_id] (0x0400): Input ID: 1000 (2023-02-17 8:44:52): [nss] [cache_req_set_plugin] (0x2000): CR #19: Setting "User by ID" plugin (2023-02-17 8:44:52): [nss] [cache_req_send] (0x0400): CR #19: New request 'User by ID' (2023-02-17 8:44:52): [nss] [cache_req_select_domains] (0x0400): CR #19: Performing a multi-domain search (2023-02-17 8:44:52): [nss] [cache_req_search_domains] (0x0400): CR #19: Search will check the cache and check the data provider (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain org.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@org.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/org.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@org.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain linux.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@linux.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/linux.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@linux.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain buero.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@buero.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/buero.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@buero.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain tk.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using domain [tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: Looking up UID:1000@tk.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: Checking negative cache for [UID:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/tk.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: [UID:1000@tk.MYDOMAIN.at] is not present in negative cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Looking up [UID:1000@tk.MYDOMAIN.at] in cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Object [UID:1000@tk.MYDOMAIN.at] was not found in cache (2023-02-17 8:44:52): [nss] [cache_req_search_dp] (0x0400): CR #19: Looking up [UID:1000@tk.MYDOMAIN.at] in data provider (2023-02-17 8:44:52): [nss] [sss_dp_issue_request] (0x0400): Issuing request for [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): Entering request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): 0x5610c6661c90 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: 0x5610c6660820 (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR #19: Data Provider Error: 3, 5, Failed to get reply from Data Provider (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR #19: Due to an error we will return cached data (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Looking up [UID:1000@tk.MYDOMAIN.at] in cache (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: Object [UID:1000@tk.MYDOMAIN.at] was not found in cache (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR #19: Finished: Not found (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain buero.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain org.MYDOMAIN.at is Active (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain tk.MYDOMAIN.at is Disabled

Hi, thanks for the details. Pavel, do you think it would make sense to skip disabled domains in cache_req's multi-domain search? It looks like for single-domain search they are already skipped via cache_req_domain_get_domain_by_name(). bye, Sumit

(2023-02-17 8:44:52): [nss] [nss_protocol_done] (0x4000): Sending reply: not found (2023-02-17 8:44:52): [nss] [sss_dp_req_destructor] (0x0400): Deleting request: [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [nss_getby_id] (0x0400): Input ID: 1000 (2023-02-17 8:44:52): [nss] [cache_req_set_plugin] (0x2000): CR #20: Setting "User by ID" plugin (2023-02-17 8:44:52): [nss] [cache_req_send] (0x0400): CR #20: New request 'User by ID' (2023-02-17 8:44:52): [nss] [cache_req_select_domains] (0x0400): CR #20: Performing a multi-domain search (2023-02-17 8:44:52): [nss] [cache_req_search_domains] (0x0400): CR #20: Search will check the cache and check the data provider (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain org.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@org.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@org.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/org.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@org.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain linux.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@linux.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@linux.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/linux.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@linux.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain buero.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@buero.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@buero.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/buero.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@buero.MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@MYDOMAIN.at] does not exist (negative cache) (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain tk.MYDOMAIN.at type POSIX is valid (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #20: Using domain [tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #20: Looking up UID:1000@tk.MYDOMAIN.at (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: Checking negative cache for [UID:1000@tk.MYDOMAIN.at] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/tk.MYDOMAIN.at/1000] (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/UID/1000] (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #20: [UID:1000@tk.MYDOMAIN.at] is not present in negative cache As it is very hard for me to read the logfile with that debug_level I hope this snippet is sufficient... Pls let me know if not. Cheers, Ronald

Reply

Ronald Wimmer

Tuesday, 21 March Tue, 21 Mar

5:06 a.m.

On 17.02.23 09:51, Sumit Bose wrote:

Am Fri, Feb 17, 2023 at 08:51:03AM +0100 schrieb Ronald Wimmer: > > > On 16.02.23 12:18, Sumit Bose wrote: >> Am Thu, Feb 16, 2023 at 12:14:02PM +0100 schrieb Ronald Wimmer via FreeIPA-users: >>> We do face the problem that we disabled a domain we do not need and that >>> this particular domain fills up sssd logs on the client side. Especially >>> sssd_nss.log. How could we possibly avoid this behavior? >> >> Hi, >> >> are you using the default debug level or did you set debug_level >> explicitly in sssd.conf? >> >> Can you give some examples of the debug message? > > > I raised the debug level. sssd_nss.log fills up with > > (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating > request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] > (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 > (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): Entering > request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): 0x5610c6661c90 > (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: > 0x5610c6660820 > (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. > (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data Provider > returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] > (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR #18: > Data Provider Error: 3, 5, Failed to get reply from Data Provider > (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR #18: > Due to an error we will return cached data > (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: > Looking up [UID:1000@tk.MYDOMAIN.at] in cache > (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: > Object [UID:1000@tk.MYDOMAIN.at] was not found in cache > (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR #18: > Finished: Not found > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > buero.MYDOMAIN.at is Active > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > MYDOMAIN.at is Active > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > org.MYDOMAIN.at is Active > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > tk.MYDOMAIN.at is Disabled > (2023-02-17 8:44:52): [nss] [nss_protocol_done] (0x4000): Sending reply: > not found > (2023-02-17 8:44:52): [nss] [sss_dp_req_destructor] (0x0400): Deleting > request: [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [nss_getby_id] (0x0400): Input ID: 1000 > (2023-02-17 8:44:52): [nss] [cache_req_set_plugin] (0x2000): CR #19: > Setting "User by ID" plugin > (2023-02-17 8:44:52): [nss] [cache_req_send] (0x0400): CR #19: New request > 'User by ID' > (2023-02-17 8:44:52): [nss] [cache_req_select_domains] (0x0400): CR #19: > Performing a multi-domain search > (2023-02-17 8:44:52): [nss] [cache_req_search_domains] (0x0400): CR #19: > Search will check the cache and check the data provider > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] > (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): > Request type POSIX-only for domain org.MYDOMAIN.at type POSIX is valid > (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using > domain [org.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: > Looking up UID:1000@org.MYDOMAIN.at > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > Checking negative cache for [UID:1000@org.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/UID/org.MYDOMAIN.at/1000] > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > [UID:1000@org.MYDOMAIN.at] does not exist (negative cache) > (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): > Request type POSIX-only for domain linux.MYDOMAIN.at type POSIX is valid > (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using > domain [linux.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: > Looking up UID:1000@linux.MYDOMAIN.at > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > Checking negative cache for [UID:1000@linux.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/UID/linux.MYDOMAIN.at/1000] > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > [UID:1000@linux.MYDOMAIN.at] does not exist (negative cache) > (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): > Request type POSIX-only for domain buero.MYDOMAIN.at type POSIX is valid > (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using > domain [buero.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: > Looking up UID:1000@buero.MYDOMAIN.at > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > Checking negative cache for [UID:1000@buero.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/UID/buero.MYDOMAIN.at/1000] > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > [UID:1000@buero.MYDOMAIN.at] does not exist (negative cache) > (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): > Request type POSIX-only for domain MYDOMAIN.at type POSIX is valid > (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using > domain [MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: > Looking up UID:1000@MYDOMAIN.at > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > Checking negative cache for [UID:1000@MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/UID/MYDOMAIN.at/1000] > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > [UID:1000@MYDOMAIN.at] does not exist (negative cache) > (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): > Request type POSIX-only for domain tk.MYDOMAIN.at type POSIX is valid > (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: Using > domain [tk.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: > Looking up UID:1000@tk.MYDOMAIN.at > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > Checking negative cache for [UID:1000@tk.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/UID/tk.MYDOMAIN.at/1000] > (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking > negative cache for [NCE/UID/1000] > (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: > [UID:1000@tk.MYDOMAIN.at] is not present in negative cache > (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: > Looking up [UID:1000@tk.MYDOMAIN.at] in cache > (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: > Object [UID:1000@tk.MYDOMAIN.at] was not found in cache > (2023-02-17 8:44:52): [nss] [cache_req_search_dp] (0x0400): CR #19: Looking > up [UID:1000@tk.MYDOMAIN.at] in data provider > (2023-02-17 8:44:52): [nss] [sss_dp_issue_request] (0x0400): Issuing > request for [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating > request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] > (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 > (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): Entering > request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] > (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): 0x5610c6661c90 > (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: > 0x5610c6660820 > (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. > (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data Provider > returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] > (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR #19: > Data Provider Error: 3, 5, Failed to get reply from Data Provider > (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR #19: > Due to an error we will return cached data > (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: > Looking up [UID:1000@tk.MYDOMAIN.at] in cache > (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: > Object [UID:1000@tk.MYDOMAIN.at] was not found in cache > (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR #19: > Finished: Not found > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > buero.MYDOMAIN.at is Active > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > MYDOMAIN.at is Active > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > org.MYDOMAIN.at is Active > (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain > tk.MYDOMAIN.at is Disabled Hi, thanks for the details. Pavel, do you think it would make sense to skip disabled domains in cache_req's multi-domain search? It looks like for single-domain search they are already skipped via cache_req_domain_get_domain_by_name().

Is there something I could do at the moment? Even when logrotating hourly sssd_nss.log fills up so rapidly with (2023-03-21 10:53:39): [nss] [sss_dp_get_reply] (0x0010): The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] that it is difficult to cope with that. Cheers, Ronald

Reply

Ronald Wimmer

Monday, 22 May Mon, 22 May

2:59 a.m.

On 21.03.23 11:06, Ronald Wimmer via FreeIPA-users wrote:

On 17.02.23 09:51, Sumit Bose wrote: > Am Fri, Feb 17, 2023 at 08:51:03AM +0100 schrieb Ronald Wimmer: >> >> >> On 16.02.23 12:18, Sumit Bose wrote: >>> Am Thu, Feb 16, 2023 at 12:14:02PM +0100 schrieb Ronald Wimmer via >>> FreeIPA-users: >>>> We do face the problem that we disabled a domain we do not need and >>>> that >>>> this particular domain fills up sssd logs on the client side. >>>> Especially >>>> sssd_nss.log. How could we possibly avoid this behavior? >>> >>> Hi, >>> >>> are you using the default debug level or did you set debug_level >>> explicitly in sssd.conf? >>> >>> Can you give some examples of the debug message? >> >> >> I raised the debug level. sssd_nss.log fills up with >> >> (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating >> request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] >> (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 >> (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): >> Entering >> request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): >> 0x5610c6661c90 >> (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: >> 0x5610c6660820 >> (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. >> (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data >> Provider >> returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] >> (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR >> #18: >> Data Provider Error: 3, 5, Failed to get reply from Data Provider >> (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR >> #18: >> Due to an error we will return cached data >> (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: >> Looking up [UID:1000@tk.MYDOMAIN.at] in cache >> (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #18: >> Object [UID:1000@tk.MYDOMAIN.at] was not found in cache >> (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR >> #18: >> Finished: Not found >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> buero.MYDOMAIN.at is Active >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> MYDOMAIN.at is Active >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> org.MYDOMAIN.at is Active >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> tk.MYDOMAIN.at is Disabled >> (2023-02-17 8:44:52): [nss] [nss_protocol_done] (0x4000): Sending >> reply: >> not found >> (2023-02-17 8:44:52): [nss] [sss_dp_req_destructor] (0x0400): Deleting >> request: [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [nss_getby_id] (0x0400): Input ID: 1000 >> (2023-02-17 8:44:52): [nss] [cache_req_set_plugin] (0x2000): CR #19: >> Setting "User by ID" plugin >> (2023-02-17 8:44:52): [nss] [cache_req_send] (0x0400): CR #19: New >> request >> 'User by ID' >> (2023-02-17 8:44:52): [nss] [cache_req_select_domains] (0x0400): CR >> #19: >> Performing a multi-domain search >> (2023-02-17 8:44:52): [nss] [cache_req_search_domains] (0x0400): CR >> #19: >> Search will check the cache and check the data provider >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/DOM_LOCATE_TYPE/linux.MYDOMAIN.at/User by ID] >> (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): >> Request type POSIX-only for domain org.MYDOMAIN.at type POSIX is valid >> (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: >> Using >> domain [org.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: >> Looking up UID:1000@org.MYDOMAIN.at >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> Checking negative cache for [UID:1000@org.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/UID/org.MYDOMAIN.at/1000] >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> [UID:1000@org.MYDOMAIN.at] does not exist (negative cache) >> (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): >> Request type POSIX-only for domain linux.MYDOMAIN.at type POSIX is valid >> (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: >> Using >> domain [linux.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: >> Looking up UID:1000@linux.MYDOMAIN.at >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> Checking negative cache for [UID:1000@linux.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/UID/linux.MYDOMAIN.at/1000] >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> [UID:1000@linux.MYDOMAIN.at] does not exist (negative cache) >> (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): >> Request type POSIX-only for domain buero.MYDOMAIN.at type POSIX is valid >> (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: >> Using >> domain [buero.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: >> Looking up UID:1000@buero.MYDOMAIN.at >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> Checking negative cache for [UID:1000@buero.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/UID/buero.MYDOMAIN.at/1000] >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> [UID:1000@buero.MYDOMAIN.at] does not exist (negative cache) >> (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): >> Request type POSIX-only for domain MYDOMAIN.at type POSIX is valid >> (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: >> Using >> domain [MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: >> Looking up UID:1000@MYDOMAIN.at >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> Checking negative cache for [UID:1000@MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/UID/MYDOMAIN.at/1000] >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> [UID:1000@MYDOMAIN.at] does not exist (negative cache) >> (2023-02-17 8:44:52): [nss] [cache_req_validate_domain_type] (0x2000): >> Request type POSIX-only for domain tk.MYDOMAIN.at type POSIX is valid >> (2023-02-17 8:44:52): [nss] [cache_req_set_domain] (0x0400): CR #19: >> Using >> domain [tk.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [cache_req_search_send] (0x0400): CR #19: >> Looking up UID:1000@tk.MYDOMAIN.at >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> Checking negative cache for [UID:1000@tk.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/UID/tk.MYDOMAIN.at/1000] >> (2023-02-17 8:44:52): [nss] [sss_ncache_check_str] (0x2000): Checking >> negative cache for [NCE/UID/1000] >> (2023-02-17 8:44:52): [nss] [cache_req_search_ncache] (0x0400): CR #19: >> [UID:1000@tk.MYDOMAIN.at] is not present in negative cache >> (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: >> Looking up [UID:1000@tk.MYDOMAIN.at] in cache >> (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: >> Object [UID:1000@tk.MYDOMAIN.at] was not found in cache >> (2023-02-17 8:44:52): [nss] [cache_req_search_dp] (0x0400): CR #19: >> Looking >> up [UID:1000@tk.MYDOMAIN.at] in data provider >> (2023-02-17 8:44:52): [nss] [sss_dp_issue_request] (0x0400): Issuing >> request for [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sss_dp_get_account_msg] (0x0400): Creating >> request for [tk.MYDOMAIN.at][0x1][BE_REQ_USER][idnumber=1000:-] >> (2023-02-17 8:44:52): [nss] [sbus_add_timeout] (0x2000): 0x5610c6661c90 >> (2023-02-17 8:44:52): [nss] [sss_dp_internal_get_send] (0x0400): >> Entering >> request [0x5610c5282a80:1:1000@tk.MYDOMAIN.at] >> (2023-02-17 8:44:52): [nss] [sbus_remove_timeout] (0x2000): >> 0x5610c6661c90 >> (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): dbus conn: >> 0x5610c6660820 >> (2023-02-17 8:44:52): [nss] [sbus_dispatch] (0x4000): Dispatching. >> (2023-02-17 8:44:52): [nss] [sss_dp_get_reply] (0x0010): The Data >> Provider >> returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] >> (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0040): CR >> #19: >> Data Provider Error: 3, 5, Failed to get reply from Data Provider >> (2023-02-17 8:44:52): [nss] [cache_req_common_dp_recv] (0x0400): CR >> #19: >> Due to an error we will return cached data >> (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: >> Looking up [UID:1000@tk.MYDOMAIN.at] in cache >> (2023-02-17 8:44:52): [nss] [cache_req_search_cache] (0x0400): CR #19: >> Object [UID:1000@tk.MYDOMAIN.at] was not found in cache >> (2023-02-17 8:44:52): [nss] [cache_req_process_result] (0x0400): CR >> #19: >> Finished: Not found >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> buero.MYDOMAIN.at is Active >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> MYDOMAIN.at is Active >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> org.MYDOMAIN.at is Active >> (2023-02-17 8:44:52): [nss] [sss_domain_get_state] (0x1000): Domain >> tk.MYDOMAIN.at is Disabled > > Hi, > > thanks for the details. > > Pavel, do you think it would make sense to skip disabled domains in > cache_req's multi-domain search? It looks like for single-domain search > they are already skipped via cache_req_domain_get_domain_by_name(). Is there something I could do at the moment? Even when logrotating hourly sssd_nss.log fills up so rapidly with (2023-03-21 10:53:39): [nss] [sss_dp_get_reply] (0x0010): The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] that it is difficult to cope with that.

Any updates on this matter? Is there a way to prevent the disabled domain from beeing logged?

Reply

346

days inactive

441

days old

freeipa-users@lists.fedorahosted.org

Manage subscription

5 comments

2 participants

tags (0)

participants (2)

Ronald Wimmer
Sumit Bose