Alexey, Of course. Added below. -- lawrence
----- [root@acad-cnode006 ~]# sssctl logs-remove Truncating log files... ----- [root@acad-cnode006 ~]# sssctl debug-level sssd 0x0070 nss 0x0070 pam 0x0070 domain/adldap1.augusta.edu 0x0070 [root@acad-cnode006 ~]# sssctl debug-level 9 [root@acad-cnode006 ~]# sssctl debug-level sssd 0x2f7f0 nss 0x2f7f0 pam 0x2f7f0 domain/adldap1.augusta.edu 0x2f7f0 ----- [root@acad-cnode006 ~]# ll /home/lck total 12 drwxr-xr-x 3 28244723 28433522 4096 Jan 28 14:19 Documents drwxr-xr-x 8 28244723 28433522 4096 Feb 6 12:25 apps drwxr-xr-x 4 28244723 28433522 4096 Feb 12 15:36 scripts ----- [root@acad-cnode006 ~]# cat /var/log/sssd/sssd_nss.log (2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:29:55): [nss] [sbus_signal_handler] (0x2000): Received D-Bus signal org.freedesktop.DBus.NameOwnerChanged on /org/freedesktop/DBus (2025-02-15 19:29:55): [nss] [sbus_name_owner_changed] (0x4000): Name of owner :1.8 has changed from [] to [:1.8] (2025-02-15 19:29:55): [nss] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.NameOwnerChanged: Success (2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:29:55): [nss] [sbus_method_handler] (0x2000): Received D-Bus method org.freedesktop.DBus.Properties.Get on /sssd (2025-02-15 19:29:55): [nss] [sbus_senders_lookup] (0x2000): Looking for identity of sender [:1.8] (2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:29:55): [nss] [sbus_senders_lookup] (0x2000): Looking for identity of sender [:1.8] (2025-02-15 19:29:55): [nss] [sbus_senders_add] (0x2000): Inserting identity of sender [:1.8]: 0 (2025-02-15 19:29:55): [nss] [sbus_properties_get_send] (0x4000): Requesting property: sssd.service.debug_level of /sssd (2025-02-15 19:29:55): [nss] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.Properties.Get: Success (2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:29:55): [nss] [sbus_signal_handler] (0x2000): Received D-Bus signal org.freedesktop.DBus.NameOwnerChanged on /org/freedesktop/DBus (2025-02-15 19:29:55): [nss] [sbus_name_owner_changed] (0x4000): Name of owner :1.8 has changed from [:1.8] to [] (2025-02-15 19:29:55): [nss] [sbus_senders_delete] (0x2000): Removing identity of sender [:1.8] (2025-02-15 19:29:55): [nss] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.NameOwnerChanged: Success (2025-02-15 19:30:29): [nss] [get_client_cred] (0x4000): Client [0x55cf53509b00][22] creds: euid[0] egid[0] pid[84709] cmd_line['ls']. (2025-02-15 19:30:29): [nss] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x55cf53509b00][22] (2025-02-15 19:30:29): [nss] [accept_fd_handler] (0x0400): [CID#451] Client [cmd ls][uid 0][0x55cf53509b00][22] connected! (2025-02-15 19:30:29): [nss] [sss_cmd_get_version] (0x0200): [CID#451] Received client version [1]. (2025-02-15 19:30:29): [nss] [sss_cmd_get_version] (0x0200): [CID#451] Offered version [1]. (2025-02-15 19:30:29): [nss] [sss_nss_getby_id] (0x0400): [CID#451] Input ID: 28244723 (looking up 'POSIX data') (2025-02-15 19:30:29): [nss] [cache_req_set_plugin] (0x2000): [CID#451] CR #969: Setting "User by ID" plugin (2025-02-15 19:30:29): [nss] [cache_req_send] (0x0400): [CID#451] CR #969: REQ_TRACE: New request [CID #451] 'User by ID' (2025-02-15 19:30:29): [nss] [cache_req_select_domains] (0x0400): [CID#451] CR #969: Performing a multi-domain search (2025-02-15 19:30:29): [nss] [cache_req_search_domains] (0x0400): [CID#451] CR #969: Search will check the cache and check the data provider (2025-02-15 19:30:29): [nss] [cache_req_validate_domain_type] (0x2000): [CID#451] Request type POSIX-only for domain adldap1.augusta.edu type POSIX is valid (2025-02-15 19:30:29): [nss] [cache_req_set_domain] (0x0400): [CID#451] CR #969: Using domain [adldap1.augusta.edu] (2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR #969: Looking up UID:[email protected] (2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451] CR #969: Checking negative cache for [UID:[email protected]] (2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451] Checking negative cache for [NCE/UID/adldap1.augusta.edu/28244723] (2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451] Checking negative cache for [NCE/UID/28244723] (2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451] CR #969: [UID:[email protected]] is not present in negative cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #969: Looking up [UID:[email protected]] in cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #969: Object [UID:[email protected]] was not found in cache (2025-02-15 19:30:29): [nss] [cache_req_search_dp] (0x0400): [CID#451] CR #969: Looking up [UID:[email protected]] in data provider (2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451] Creating request for [adldap1.augusta.edu ][0x1][BE_REQ_USER][idnumber=28244723:-] (2025-02-15 19:30:29): [nss] [sss_nss_get_object_send] (0x0400): [CID#451] Client [0x55cf53509b00][22]: sent cache request #969 (2025-02-15 19:30:29): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): [CID#451] CR #969: Data Provider Error: 3, 0, Success (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x0400): [CID#451] CR #969: Due to an error we will return cached data (2025-02-15 19:30:29): [nss] [sss_domain_get_state] (0x1000): [CID#451] Domain adldap1.augusta.edu is Active (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #969: Looking up [UID:[email protected]] in cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #969: Object [UID:[email protected]] was not found in cache (2025-02-15 19:30:29): [nss] [cache_req_process_result] (0x0400): [CID#451] CR #969: Finished: Not found (2025-02-15 19:30:29): [nss] [sss_nss_protocol_done] (0x4000): [CID#451] Sending reply: not found (2025-02-15 19:30:29): [nss] [sss_nss_getby_id] (0x0400): [CID#451] Input ID: 28433522 (looking up 'POSIX data') (2025-02-15 19:30:29): [nss] [cache_req_set_plugin] (0x2000): [CID#451] CR #970: Setting "Group by ID" plugin (2025-02-15 19:30:29): [nss] [cache_req_send] (0x0400): [CID#451] CR #970: REQ_TRACE: New request [CID #451] 'Group by ID' (2025-02-15 19:30:29): [nss] [cache_req_select_domains] (0x0400): [CID#451] CR #970: Performing a multi-domain search (2025-02-15 19:30:29): [nss] [cache_req_search_domains] (0x0400): [CID#451] CR #970: Search will check the cache and check the data provider (2025-02-15 19:30:29): [nss] [cache_req_validate_domain_type] (0x2000): [CID#451] Request type POSIX-only for domain adldap1.augusta.edu type POSIX is valid (2025-02-15 19:30:29): [nss] [cache_req_set_domain] (0x0400): [CID#451] CR #970: Using domain [adldap1.augusta.edu] (2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR #970: Looking up GID:[email protected] (2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451] CR #970: Checking negative cache for [GID:[email protected]] (2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451] Checking negative cache for [NCE/GID/adldap1.augusta.edu/28433522] (2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451] Checking negative cache for [NCE/GID/28433522] (2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451] CR #970: [GID:[email protected]] is not present in negative cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #970: Looking up [GID:[email protected]] in cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #970: Object [GID:[email protected]] was not found in cache (2025-02-15 19:30:29): [nss] [cache_req_search_dp] (0x0400): [CID#451] CR #970: Looking up [GID:[email protected]] in data provider (2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451] Creating request for [adldap1.augusta.edu ][0x2][BE_REQ_GROUP][idnumber=28433522:-] (2025-02-15 19:30:29): [nss] [sss_nss_get_object_send] (0x0400): [CID#451] Client [0x55cf53509b00][22]: sent cache request #970 (2025-02-15 19:30:29): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): [CID#451] CR #970: Data Provider Error: 3, 0, Success (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x0400): [CID#451] CR #970: Due to an error we will return cached data (2025-02-15 19:30:29): [nss] [sss_domain_get_state] (0x1000): [CID#451] Domain adldap1.augusta.edu is Active (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #970: Looking up [GID:[email protected]] in cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #970: Object [GID:[email protected]] was not found in cache (2025-02-15 19:30:29): [nss] [cache_req_process_result] (0x0400): [CID#451] CR #970: Finished: Not found (2025-02-15 19:30:29): [nss] [sss_nss_protocol_done] (0x4000): [CID#451] Sending reply: not found (2025-02-15 19:30:29): [nss] [sss_nss_getby_id] (0x0400): [CID#451] Input ID: 28433522 (looking up 'POSIX data') (2025-02-15 19:30:29): [nss] [cache_req_set_plugin] (0x2000): [CID#451] CR #971: Setting "Group by ID" plugin (2025-02-15 19:30:29): [nss] [cache_req_send] (0x0400): [CID#451] CR #971: REQ_TRACE: New request [CID #451] 'Group by ID' (2025-02-15 19:30:29): [nss] [cache_req_select_domains] (0x0400): [CID#451] CR #971: Performing a multi-domain search (2025-02-15 19:30:29): [nss] [cache_req_search_domains] (0x0400): [CID#451] CR #971: Search will check the cache and check the data provider (2025-02-15 19:30:29): [nss] [cache_req_validate_domain_type] (0x2000): [CID#451] Request type POSIX-only for domain adldap1.augusta.edu type POSIX is valid (2025-02-15 19:30:29): [nss] [cache_req_set_domain] (0x0400): [CID#451] CR #971: Using domain [adldap1.augusta.edu] (2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR #971: Looking up GID:[email protected] (2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451] CR #971: Checking negative cache for [GID:[email protected]] (2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451] Checking negative cache for [NCE/GID/adldap1.augusta.edu/28433522] (2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451] Checking negative cache for [NCE/GID/28433522] (2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451] CR #971: [GID:[email protected]] is not present in negative cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #971: Looking up [GID:[email protected]] in cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #971: Object [GID:[email protected]] was not found in cache (2025-02-15 19:30:29): [nss] [cache_req_search_dp] (0x0400): [CID#451] CR #971: Looking up [GID:[email protected]] in data provider (2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451] Creating request for [adldap1.augusta.edu ][0x2][BE_REQ_GROUP][idnumber=28433522:-] (2025-02-15 19:30:29): [nss] [sss_nss_get_object_send] (0x0400): [CID#451] Client [0x55cf53509b00][22]: sent cache request #971 (2025-02-15 19:30:29): [nss] [sbus_dispatch] (0x4000): Dispatching. (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): [CID#451] CR #971: Data Provider Error: 3, 0, Success (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x0400): [CID#451] CR #971: Due to an error we will return cached data (2025-02-15 19:30:29): [nss] [sss_domain_get_state] (0x1000): [CID#451] Domain adldap1.augusta.edu is Active (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #971: Looking up [GID:[email protected]] in cache (2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451] CR #971: Object [GID:[email protected]] was not found in cache (2025-02-15 19:30:29): [nss] [cache_req_process_result] (0x0400): [CID#451] CR #971: Finished: Not found (2025-02-15 19:30:29): [nss] [sss_nss_protocol_done] (0x4000): [CID#451] Sending reply: not found (2025-02-15 19:30:29): [nss] [client_recv] (0x0200): [CID#451] Client disconnected! (2025-02-15 19:30:29): [nss] [client_close_fn] (0x2000): [CID#451] Terminated client [0x55cf53509b00][22] ---------- >From Alexey: Huh... apparently I parsed strace wrongly because sssd_nss.log says a correct UID is being looked up: ``` (2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR #969: Looking up UID:[email protected] (2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451] Creating request for [adldap1.augusta.edu ][0x1][BE_REQ_USER][idnumber=28244723:-] (2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0): [CID#451] CR #969: Data Provider Error: 3, 0, Success ``` Well, that's good, no mystery on the sss_client library side. Then the next thing we need to check 'sssd_$domain.log' with debug_level=9 that covers processing of this request, that results in "Data Provider Error" ---------- Alexey, Thank you again, included below: [root@acad-cnode006 ~]# sssctl debug-level 9 [root@acad-cnode006 ~]# sssctl debug-level sssd 0x2f7f0 nss 0x2f7f0 pam 0x2f7f0 domain/adldap1.augusta.edu 0x2f7f0 [root@acad-cnode006 ~]# sssctl logs-remove Truncating log files... [root@acad-cnode006 ~]# ll /home/lck ----- total 12 drwxr-xr-x 3 28244723 28433522 4096 Jan 28 14:19 Documents drwxr-xr-x 8 28244723 28433522 4096 Feb 6 12:25 apps drwxr-xr-x 4 28244723 28433522 4096 Feb 12 15:36 scripts ----- [root@acad-cnode006 ~]# cat /var/log/sssd/sssd_adldap1.augusta.edu.log (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x4000): inotify name: chrony.conf (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x0400): Not interested in chrony.conf (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x4000): inotify name: group (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x0400): Not interested in group (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x4000): inotify name: hosts (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x0400): Not interested in hosts (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_internal_cb] (0x2000): All inotify events processed (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x4000): inotify name: passwd (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x0400): Not interested in passwd (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_file_event] (0x0400): received notification for watched file /etc/resolv.conf (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [create_dispatcher] (0x0400): Running a timer with delay 1.0 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [dispatch_event] (0x0400): Dispatched an event with combined flags 0x400 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_file_event] (0x0400): Will reopen moved or deleted file /etc/resolv.conf (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x4000): inotify name: resolv.conf (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x0400): received notification for watched file [resolv.conf] under /etc (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [get_dispatcher] (0x2000): Reusing existing dispatcher (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [dispatch_event] (0x0400): Dispatched an event with combined flags 0x500 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x4000): inotify name: shadow (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event] (0x0400): Not interested in shadow (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_internal_cb] (0x2000): All inotify events processed (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [watch_ctx_destructor] (0x2000): Closing inotify fd 20 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_watch] (0x2000): Opened inotify fd 20 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_watch] (0x2000): Opened file watch 1 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_watch] (0x2000): Opened directory watch 2 (2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_rewatch] (0x0400): Recreated watch (2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [watched_file_inotify_cb] (0x1000): Received inotify notification for /etc/resolv.conf (2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [watch_update_resolv] (0x0400): Reloading /etc/resolv.conf. (2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [recreate_ares_channel] (0x0100): Initializing new c-ares channel (2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [recreate_ares_channel] (0x0100): Destroying the old c-ares channel (2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [check_if_online] (0x2000): Schedule check_if_online_delayed in 1s. (2025-02-17 13:32:16): [be[adldap1.augusta.edu]] [be_run_unconditional_online_cb] (0x4000): List of unconditional online callbacks is empty, nothing to do. (2025-02-17 13:32:16): [be[adldap1.augusta.edu]] [check_if_online_delayed] (0x2000): Backend is already online, nothing to do. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_method_handler] (0x2000): Received D-Bus method sssd.dataprovider.getAccountInfo on /sssd (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_senders_lookup] (0x2000): Looking for identity of sender [sssd.nss] (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_get_account_info_send] (0x0200): Got request for [0x1][BE_REQ_USER][idnumber=28244723] (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400): [RID#79] DP Request [Account #79]: REQ_TRACE: New request. [sssd.nss CID #496] Flags [0x0001]. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400): [RID#79] Number of active DP request: 1 (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sss_domain_get_state] (0x1000): [RID#79] Domain adldap1.augusta.edu is Active (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [users_get_send] (0x0080): [RID#79] [28244723] did not match any configured ID mapping domain (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_search_user_by_uid] (0x0400): [RID#79] No such entry (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_delete_user] (0x0400): [RID#79] Error: 2 (No such file or directory) (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x0400): [RID#79] DP Request [Account #79]: Request handler finished [0]: Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x20000): [RID#79] DP Request [Account #79]: Handling request took [0.142] milliseconds. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [_dp_req_recv] (0x0400): [RID#79] DP Request [Account #79]: Receiving request data. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor] (0x0400): [RID#79] DP Request [Account #79]: Request removed. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor] (0x0400): [RID#79] Number of active DP request: 0 (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_reply_std] (0x1000): [RID#79] DP Request [Account #79]: Returning [Internal Error]: 3,0,Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_issue_request_done] (0x0400): sssd.dataprovider.getAccountInfo: Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_method_handler] (0x2000): Received D-Bus method sssd.dataprovider.getAccountInfo on /sssd (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_senders_lookup] (0x2000): Looking for identity of sender [sssd.nss] (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_get_account_info_send] (0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=28433522] (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400): [RID#80] DP Request [Account #80]: REQ_TRACE: New request. [sssd.nss CID #496] Flags [0x0001]. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400): [RID#80] Number of active DP request: 1 (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sss_domain_get_state] (0x1000): [RID#80] Domain adldap1.augusta.edu is Active (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [groups_get_send] (0x0080): [RID#80] [28433522] did not match any configured ID mapping domain (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_search_group_by_id] (0x0400): [RID#80] No such entry (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_delete_group] (0x0400): [RID#80] Error: 2 (No such file or directory) (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x0400): [RID#80] DP Request [Account #80]: Request handler finished [0]: Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x20000): [RID#80] DP Request [Account #80]: Handling request took [0.142] milliseconds. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [_dp_req_recv] (0x0400): [RID#80] DP Request [Account #80]: Receiving request data. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor] (0x0400): [RID#80] DP Request [Account #80]: Request removed. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor] (0x0400): [RID#80] Number of active DP request: 0 (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_reply_std] (0x1000): [RID#80] DP Request [Account #80]: Returning [Internal Error]: 3,0,Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_issue_request_done] (0x0400): sssd.dataprovider.getAccountInfo: Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_method_handler] (0x2000): Received D-Bus method sssd.dataprovider.getAccountInfo on /sssd (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_senders_lookup] (0x2000): Looking for identity of sender [sssd.nss] (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_get_account_info_send] (0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=28433522] (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400): [RID#81] DP Request [Account #81]: REQ_TRACE: New request. [sssd.nss CID #496] Flags [0x0001]. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400): [RID#81] Number of active DP request: 1 (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sss_domain_get_state] (0x1000): [RID#81] Domain adldap1.augusta.edu is Active (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [groups_get_send] (0x0080): [RID#81] [28433522] did not match any configured ID mapping domain (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_search_group_by_id] (0x0400): [RID#81] No such entry (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_delete_group] (0x0400): [RID#81] Error: 2 (No such file or directory) (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x0400): [RID#81] DP Request [Account #81]: Request handler finished [0]: Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x20000): [RID#81] DP Request [Account #81]: Handling request took [0.158] milliseconds. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [_dp_req_recv] (0x0400): [RID#81] DP Request [Account #81]: Receiving request data. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor] (0x0400): [RID#81] DP Request [Account #81]: Request removed. (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor] (0x0400): [RID#81] Number of active DP request: 0 (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_reply_std] (0x1000): [RID#81] DP Request [Account #81]: Returning [Internal Error]: 3,0,Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_issue_request_done] (0x0400): sssd.dataprovider.getAccountInfo: Success (2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000): Dispatching.sssd 0x2f7f0 --------- >From Alexey: Ok, we are getting closer to the root cause: ``` (13:32:22): [dp_get_account_info_send] (0x0200): Got request for [0x1][BE_REQ_USER][idnumber=28244723] (13:32:22): [sss_domain_get_state] (0x1000): [RID#79] Domain adldap1.augusta.edu is Active (13:32:22): [users_get_send] (0x0080): [RID#79] [28244723] did not match any configured ID mapping domain ``` What are: 1) actual backend - AD? 2) id_provider user in sssd.conf? 3) value of 'ldap_id_mapping' sssd.conf::domain option? ---------- Alexey, Good morning! sanitized conf file included below: - Yes, back end is native AD - Included sanitized conf file details other settings (group names, certs, dn's, modified, password omitted) ----- [sssd] config_file_version = 2 services = nss,pam domains = adldap1.example.edu [nss] filter_users = root filter_groups = root [pam] [domain/adldap1.example.edu] id_provider = ldap enumerate = False cache_credentials = True case_sensitive = false ignore_group_members = True ldap_schema = ad ldap_uri = ldaps://root.example.edu ldap_backup_uri = ldaps://root2.example.edu ldap_user_search_base = dc=example,dc=edu ldap_referrals = False ldap_tls_cacert = /etc/openldap/certs/root.crt ldap_tls_reqcert = never ldap_use_tokengroups = True ldap_id_mapping = True ldap_idmap_range_size = 2000000 override_homedir = /home/%u default_shell = /bin/bash override_gid = 28433520 ldap_access_order = filter,expire ldap_account_expire_policy = ad ldap_access_filter = (|(memberOf=cn=prod_admins_group,ou=hpc,dc=example,dc=edu)(memberOf=cn=prod_users_group,ou=hpc,dc=example,dc=edu)) ldap_default_bind_dn = CN="Service, LDAP_Auth",OU=ServiceAccounts,DC=example,DC=edu ldap_default_authtok_type = password ---------- Alexey, Thank you for the effort thus far and the feedback, but I'd like to offer a few points. - As referenced, these systems are ephemeral, so joining them to AD to use the AD provider isn't sustainable. - We have other systems configured exactly the same way, across many different versions of the daemon and RHEL OS's, and have never seen this issue. - Correct, as soon as I do a lookup by name, any valid name, everything resolves as expected. Being able to use the LDAP ID provider and the AD schema, provided by an SSSD configuration directive, suggests we're not doing anything radical. What is different is these OS instances are Rocky 9.5 Linux containers deployed as stateless systems. So, given that my question becomes what is different? Is there something the daemon is missing in a stateless configuration? I know that's pretty open ended, I've done this quite a bit, but I don't have the developer insight or experience of where else to look next. I'll test with the recommendations given and perhaps the results may provide additional breadcrumbs. Stay tuned and thank you, -- Lawrence ---------- Alexey, I tried using both the `ldap_idmap_default_domain_sid` and `ldap_idmap_default_domain` directives, but the same result. -- lawrence On Mon, Feb 17, 2025 at 12:39 PM Alexey Tikhonov <[email protected]> wrote: > Hi. > > The reason is that 'id_provider = ldap' is used against AD. > > Normally 'subdomain_provider' reads required data and sets up id-mapping > at startup, but ldap provider doesn't have 'subdomain_provider', so when > first lookup is by-id it can't convert id to SID: > ``` > [users_get_send] (0x0080): [RID#79] [28244723] did not match any > configured ID mapping domain > ``` > and can't handle a request. > > You wrote: "until I manually run a "getent" or "id" on any user or group" > - I guess those lookups are by-name? > I guess this triggers a connection to AD, rootDSE is read and id-mapping > is set up. > > You can try to set `ldap_idmap_default_domain_sid` and > `ldap_idmap_default_domain` to the SID and name of your domain. Hopefully > this will create a static mapping at startup. > > But in general it's recommended to use 'id_provider = ad' against AD. > > > >
-- _______________________________________________ sssd-users mailing list -- [email protected] To unsubscribe send an email to [email protected] 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/[email protected] Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
