Hi,
The troubleshooting guide in the docs said to email the list if the System Error (4) shows up, so I figured I bring this issue up. I'm running sssd version 1.16.0 on Debian testing and recently encountered a new behavior. We set up sssd with active directory based authentication on an already established system. For various reasons there are still local passwd users, some of whom also have ad accounts. What used to happen is that the pam/nsswitch stack was set up so that those users would end up with their passwd id. If they had an ad account they could log in with either their shadow password or their ad password. Right after we upgraded from 1.16.0-1 to 1.16.0-2 any local user generated a System Error (4) in the logs and and local users with ad accounts could no longer use their ad passwords (although they could still use their local passwords). There isn't a lot of information in the logs.
auth.log:
Jan 23 19:02:27 spoon su[28320]: pam_unix(su:auth): authentication failure; logname=goehle uid=1000 euid=0 tty=/dev/pts/0 ruser=goehle rhost= user=picard Jan 23 19:02:27 spoon su[28320]: pam_sss(su:auth): authentication failure; logname=goehle uid=1000 euid=0 tty=/dev/pts/0 ruser=goehle rhost= user=picard Jan 23 19:02:27 spoon su[28320]: pam_sss(su:auth): received for user picard: 4 (System error)
sssd_pam.log (full version below):
(Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: su (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: goehle (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 28320 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dp_process_reply] (0x0010): Reply error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 31
There aren't any other log entries with this time stamp. In particular there aren't any entries in the domain log, the pam_nss log or the krb5_child log. I am able to authenticate manually with kinit, however. I would really appreciate it if someone could point me to the right logs, or even just tell me that mixing local and sss users in this way is not supported.
Thanks for your time.
Geoff Goehle.
(Tue Jan 23 19:02:27 2018) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected! (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3]. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3]. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_domain_get_state] (0x1000): Domain wcu.edu is Active (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'picard' matched without domain, user is picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: su (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: goehle (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 28320 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_set_plugin] (0x2000): CR #12: Setting "Initgroups by name" plugin (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_send] (0x0400): CR #12: New request 'Initgroups by name' (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_process_input] (0x0400): CR #12: Parsing input name [picard] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_domain_get_state] (0x1000): Domain wcu.edu is Active (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'picard' matched without domain, user is picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_set_name] (0x0400): CR #12: Setting name [picard] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_select_domains] (0x0400): CR #12: Performing a multi-domain search (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_domains] (0x0400): CR #12: Search will bypass the cache and check the data provider (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_validate_domain_type] (0x2000): Request type POSIX-only for domain implicit_files type POSIX is valid (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_set_domain] (0x0400): CR #12: Using domain [implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_prepare_domain_data] (0x0400): CR #12: Preparing input data for domain [implicit_files] rules (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_send] (0x0400): CR #12: Looking up picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: Checking negative cache for [picard@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/implicit_files/picard@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_ncache] (0x0400): CR #12: [picard@implicit_files] is not present in negative cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_dp] (0x0400): CR #12: Looking up [picard@implicit_files] in data provider (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_account_files_params] (0x2000): Domain files is not consistent, issuing update (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x55bc077c6930:3:files_initgr_request@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [implicit_files][0x3][BE_REQ_INITGROUPS][name=files_initgr_request:-] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x55bc077c6930:3:files_initgr_request@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_cache] (0x0400): CR #12: Looking up [picard@implicit_files] in cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_ncache_filter] (0x0400) : CR #12: This request type does not support filtering result by negative cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_search_done] (0x0400): CR #12: Returning updated object [picard@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_create_and_add_result] (0x0400): CR #12: Found 3 entries in domain implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x55bc077c6930:3:files_initgr_request@implicit_files] (Tue Jan 23 19:02:27 2018) [sssd[pam]] [cache_req_done] (0x0400): CR #12: Finished: Success (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [picard] added to PAM initgroup cache (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): domain: implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): user: picard@implicit_files (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): service: su (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): ruser: goehle (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): priv: 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 28320 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_print_data] (0x0100): logon name: picard (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x55bc08045290 (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_dp_process_reply] (0x0010): Reply error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [4]: System error. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [filter_responses] (0x0100): [pam_response_filter] not available, not fatal. (Tue Jan 23 19:02:27 2018) [sssd[pam]] [pam_reply] (0x0200): blen: 31
On Tue, Jan 23, 2018 at 07:44:04PM -0500, goehle@gmail.com wrote:
Hi,
The troubleshooting guide in the docs said to email the list if the System Error (4) shows up, so I figured I bring this issue up. I'm running sssd version 1.16.0 on Debian testing and recently encountered a new behavior. We set up sssd with active directory based authentication on an already established system. For various reasons there are still local passwd users, some of whom also have ad accounts. What used to happen is that the pam/nsswitch stack was set up so that those users would end up with their passwd id. If they had an ad account they could log in with either their shadow password or their ad password. Right after we upgraded from 1.16.0-1 to 1.16.0-2 any local user generated a System Error (4) in the logs and and local users with ad accounts could no longer use their ad passwords (although they could still use their local passwords). There isn't a lot of information in the logs.
Can you also paste your full configuration and the sssd domain log(s) ?
Does sssd on Debian use the implicit files provider (ps would show a sssd_be process running with --name implicit_files)
Thanks for the response. I was on #sssd and someone said that duplicate usernames like we have is a no go, so I was planning on just removing local accounts and deal with the fallout. However, I'm happy to look for a different fix. Geoff. - We are using the implicit files provider - The sssd.conf file is [domain/place.edu]id_provider = adaccess_provider = ad ldap_idmap_range_min = 200000ldap_idmap_range_max = 2000200000ldap_idmap_range_size = 800000ldap_pwd_policy = none sudo_provider = none debug_level = 8 [sssd]services = nss, pamconfig_file_version = 2domains = place.edu [nss]override_shell=/bin/bashoverride_homedir=/home/%ufilter_users = <stuff>filter_groups = <stuff> [pam] - The domain log file is. (There is a failed login attempt in this range of entries, but it doesn't show up anywhere.) (Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [child_sig_handler] (0x1000): Waiting for child [19947].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [child_sig_handler] (0x0020): child [19947] failed with status [2].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [nsupdate_child_handler] (0x0040): Dynamic DNS child failed with status [512](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158239]: Dynamic DNS update failed(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Entering.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x55a3326eac70.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x55a3326eac70(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_add_watch] (0x2000): 0x55a3326d8260/0x55a3326ede90 (19), -/W (disabled)(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x55a3326e7070](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Entering.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x55a3326e8800.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x55a3326e8800(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_add_watch] (0x2000): 0x55a3326d8de0/0x55a3326d9630 (20), -/W (disabled)(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x55a3326f3510](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326f3510](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [PAM](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #0]: New request. Flags [0000].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #0]: Request handler finished [0]: Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #0]: Receiving request data.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #0]: Finished. Success.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #0]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #0]: Request removed.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326e7070](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [NSS](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #1]: New request. Flags [0000].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #0]: Request handler finished [0]: Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #0]: Receiving request data.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #0]: Finished. Success.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #0]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #0]: Request removed.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326e7070](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [NSS](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #1]: New request. Flags [0000].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #1]: Request handler finished [0]: Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #1]: Receiving request data.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #1]: Finished. Success.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #1]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #1]: Request removed.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Entering.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x55a3326fa950.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x55a3326fa950(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_add_watch] (0x2000): 0x55a3326d00c0/0x55a3326fa5b0 (21), -/W (disabled)(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x55a3326e7070](Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326e7070](Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [SUDO](Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #2]: New request. Flags [0000].(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #2]: Request handler finished [0]: Success(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #2]: Receiving request data.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #2]: Finished. Success.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #2]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #2]: Request removed.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
On Wed, 2018-01-24 at 14:37 +0100, Jakub Hrozek wrote:
On Tue, Jan 23, 2018 at 07:44:04PM -0500, goehle@gmail.com wrote:
Hi,
The troubleshooting guide in the docs said to email the list if the System Error (4) shows up, so I figured I bring this issue up. I'm running sssd version 1.16.0 on Debian testing and recently encountered a new behavior. We set up sssd with active directory based authentication on an already established system. For various reasons there are still local passwd users, some of whom also have ad accounts. What used to happen is that the pam/nsswitch stack was set up so that those users would end up with their passwd id. If they had an ad account they could log in with either their shadow password or their ad password. Right after we upgraded from 1.16.0-1 to 1.16.0-2 any local user generated a System Error (4) in the logs and and local users with ad accounts could no longer use their ad passwords (although they could still use their local passwords). There isn't a lot of information in the logs.
Can you also paste your full configuration and the sssd domain log(s) ?
Does sssd on Debian use the implicit files provider (ps would show a sssd_be process running with --name implicit_files) _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
I'm sorry, but the line wraps in your mail are missing, at least that's how the mail got rendered for me..so I'm having trougle reading the logs..
Nonetheless, does it help if you add enable_files_domain = false into the [sssd] section?
On Wed, Jan 24, 2018 at 08:58:11AM -0500, Geoff Goehle wrote:
Thanks for the response. I was on #sssd and someone said that duplicate usernames like we have is a no go, so I was planning on just removing local accounts and deal with the fallout. However, I'm happy to look for a different fix. Geoff.
- We are using the implicit files provider
- The sssd.conf file is
[domain/place.edu]id_provider = adaccess_provider = ad ldap_idmap_range_min = 200000ldap_idmap_range_max = 2000200000ldap_idmap_range_size = 800000ldap_pwd_policy = none sudo_provider = none debug_level = 8 [sssd]services = nss, pamconfig_file_version = 2domains = place.edu [nss]override_shell=/bin/bashoverride_homedir=/home/%ufilter_users = <stuff>filter_groups = <stuff> [pam]
- The domain log file is. (There is a failed login attempt in this range of entries, but it doesn't show up anywhere.)
(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [child_sig_handler] (0x1000): Waiting for child [19947].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [child_sig_handler] (0x0020): child [19947] failed with status [2].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [nsupdate_child_handler] (0x0040): Dynamic DNS child failed with status [512](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158239]: Dynamic DNS update failed(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Entering.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x55a3326eac70.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x55a3326eac70(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_add_watch] (0x2000): 0x55a3326d8260/0x55a3326ede90 (19), -/W (disabled)(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x55a3326e7070](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Entering.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x55a3326e8800.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x55a3326e8800(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_add_watch] (0x2000): 0x55a3326d8de0/0x55a3326d9630 (20), -/W (disabled)(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x55a3326f3510](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326f3510](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [PAM](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #0]: New request. Flags [0000].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #0]: Request handler finished [0]: Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #0]: Receiving request data.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #0]: Finished. Success.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #0]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #0]: Request removed.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326e7070](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [NSS](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #1]: New request. Flags [0000].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #0]: Request handler finished [0]: Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #0]: Receiving request data.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #0]: Finished. Success.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #0]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #0]: Request removed.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326e7070](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [NSS](Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #1]: New request. Flags [0000].(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #1]: Request handler finished [0]: Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #1]: Receiving request data.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #1]: Finished. Success.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #1]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #1]: Request removed.(Wed Jan 24 08:53:43 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Entering.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x55a3326fa950.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x55a3326fa950(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_add_watch] (0x2000): 0x55a3326d00c0/0x55a3326fa5b0 (21), -/W (disabled)(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x55a3326e7070](Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.DataProvider.Client.Register on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Cancel DP ID timeout [0x55a3326e7070](Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_client_register] (0x0100): Added Frontend client [SUDO](Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getDomains on path /org/freedesktop/sssd/dataprovider(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): DP Request [Subdomains #2]: New request. Flags [0000].(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_attach_req] (0x0400): Number of active DP request: 1(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [ad_subdomains_handler_send] (0x0400): Subdomains were recently refreshed, nothing to do(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_done] (0x0400): DP Request [Subdomains #2]: Request handler finished [0]: Success(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [_dp_req_recv] (0x0400): DP Request [Subdomains #2]: Receiving request data.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Subdomains #2]: Finished. Success.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_reply_std] (0x1000): DP Request [Subdomains #2]: Returning [Success]: 0,0,Success(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_table_value_destructor] (0x0400): Removing [8:8:0000:<ALL>] from reply table(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): DP Request [Subdomains #2]: Request removed.(Wed Jan 24 08:53:44 2018) [sssd[be[place.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
On Wed, 2018-01-24 at 14:37 +0100, Jakub Hrozek wrote:
On Tue, Jan 23, 2018 at 07:44:04PM -0500, goehle@gmail.com wrote:
Hi,
The troubleshooting guide in the docs said to email the list if the System Error (4) shows up, so I figured I bring this issue up. I'm running sssd version 1.16.0 on Debian testing and recently encountered a new behavior. We set up sssd with active directory based authentication on an already established system. For various reasons there are still local passwd users, some of whom also have ad accounts. What used to happen is that the pam/nsswitch stack was set up so that those users would end up with their passwd id. If they had an ad account they could log in with either their shadow password or their ad password. Right after we upgraded from 1.16.0-1 to 1.16.0-2 any local user generated a System Error (4) in the logs and and local users with ad accounts could no longer use their ad passwords (although they could still use their local passwords). There isn't a lot of information in the logs.
Can you also paste your full configuration and the sssd domain log(s) ?
Does sssd on Debian use the implicit files provider (ps would show a sssd_be process running with --name implicit_files) _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page. Thanks so much for the help. Geoff. On Wed, 2018-01-24 at 15:46 +0100, Jakub Hrozek wrote:
I'm sorry, but the line wraps in your mail are missing, at least that's how the mail got rendered for me..so I'm having trougle reading the logs..
Nonetheless, does it help if you add enable_files_domain = false into the [sssd] section?
On Wed, Jan 24, 2018 at 08:58:11AM -0500, Geoff Goehle wrote:
Thanks for the response. I was on #sssd and someone said that duplicate usernames like we have is a no go, so I was planning on just removing local accounts and deal with the fallout. However, I'm happy to look for a different fix. Geoff.
- We are using the implicit files provider
- The sssd.conf file is
[domain/place.edu]id_provider = adaccess_provider = ad ldap_idmap_range_min = 200000ldap_idmap_range_max = 2000200000ldap_idmap_range_size = 800000ldap_pwd_policy = none sudo_provider = none debug_level = 8 [sssd]services = nss, pamconfig_file_version = 2domains = place.edu [nss]override_shell=/bin/bashoverride_homedir=/home/%ufilter_users = <stuff>filter_groups = <stuff> [pam]
On Wed, Jan 24, 2018 at 10:10:11AM -0500, Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page.
SSSD has a feature which mirrors the local /etc/passwd and /etc/group files for faster lookups of local users without having to enable nscd which is tricky to operate together with sssd, especially if you run sssd for a remote domain, too: https://fedoraproject.org/wiki/Changes/SSSDCacheForLocalUsers But I'm surprised that Debian would enable this feature without changing the nsswitch.conf order like Fedora did. They probably should disable the files domain by default..
The files domain is currently identity-only and no authentication is performed. That, together with the duplicate users and the files domain running by default has been causing the failures for you..
Op Woensdag, 24-01-2018 om 16:45 schreef Jakub Hrozek:
On Wed, Jan 24, 2018 at 10:10:11AM -0500, Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page.
SSSD has a feature which mirrors the local /etc/passwd and /etc/group files for faster lookups of local users without having to enable nscd which is tricky to operate together with sssd, especially if you run sssd for a remote domain, too: https://fedoraproject.org/wiki/Changes/SSSDCacheForLocalUsers But I'm surprised that Debian would enable this feature without changing the nsswitch.conf order like Fedora did. They probably should disable the files domain by default..
The files domain is currently identity-only and no authentication is performed. That, together with the duplicate users and the files domain running by default has been causing the failures for you..
On a side-note: I just tested this enable_files_domain and it seems using it results in the next domain still being queried for local users (verified by sifting through the ldap server logs). Using an explicit domain with id_provider=files apparently works differently (that domain answers and the next one is not queried), which is not very transparent. Is this expected?
Franky
On Wed, Jan 24, 2018 at 05:25:26PM +0100, Franky Van Liedekerke wrote:
Op Woensdag, 24-01-2018 om 16:45 schreef Jakub Hrozek:
On Wed, Jan 24, 2018 at 10:10:11AM -0500, Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page.
SSSD has a feature which mirrors the local /etc/passwd and /etc/group files for faster lookups of local users without having to enable nscd which is tricky to operate together with sssd, especially if you run sssd for a remote domain, too: https://fedoraproject.org/wiki/Changes/SSSDCacheForLocalUsers But I'm surprised that Debian would enable this feature without changing the nsswitch.conf order like Fedora did. They probably should disable the files domain by default..
The files domain is currently identity-only and no authentication is performed. That, together with the duplicate users and the files domain running by default has been causing the failures for you..
On a side-note: I just tested this enable_files_domain and it seems using it results in the next domain still being queried for local users (verified by sifting through the ldap server logs). Using an explicit domain with id_provider=files apparently works differently (that domain answers and the next one is not queried), which is not very transparent. Is this expected?
What was the order of the explicit domains? Note the implicit domain is always prepended before any other domain..
Op Woensdag, 24-01-2018 om 17:44 schreef Jakub Hrozek:
On Wed, Jan 24, 2018 at 05:25:26PM +0100, Franky Van Liedekerke wrote:
Op Woensdag, 24-01-2018 om 16:45 schreef Jakub Hrozek:
On Wed, Jan 24, 2018 at 10:10:11AM -0500, Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page.
SSSD has a feature which mirrors the local /etc/passwd and /etc/group files for faster lookups of local users without having to enable nscd which is tricky to operate together with sssd, especially if you run sssd for a remote domain, too: https://fedoraproject.org/wiki/Changes/SSSDCacheForLocalUsers But I'm surprised that Debian would enable this feature without changing the nsswitch.conf order like Fedora did. They probably should disable the files domain by default..
The files domain is currently identity-only and no authentication is performed. That, together with the duplicate users and the files domain running by default has been causing the failures for you..
On a side-note: I just tested this enable_files_domain and it seems using it results in the next domain still being queried for local users (verified by sifting through the ldap server logs). Using an explicit domain with id_provider=files apparently works differently (that domain answers and the next one is not queried), which is not very transparent. Is this expected?
What was the order of the explicit domains? Note the implicit domain is always prepended before any other domain..
The order in case of an explicit domain is first the files-based one, then ldap. So the order is (or should be) identical in both cases.
Franky
On Wed, Jan 24, 2018 at 06:06:38PM +0100, Franky Van Liedekerke wrote:
Op Woensdag, 24-01-2018 om 17:44 schreef Jakub Hrozek:
On Wed, Jan 24, 2018 at 05:25:26PM +0100, Franky Van Liedekerke wrote:
Op Woensdag, 24-01-2018 om 16:45 schreef Jakub Hrozek:
On Wed, Jan 24, 2018 at 10:10:11AM -0500, Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page.
SSSD has a feature which mirrors the local /etc/passwd and /etc/group files for faster lookups of local users without having to enable nscd which is tricky to operate together with sssd, especially if you run sssd for a remote domain, too: https://fedoraproject.org/wiki/Changes/SSSDCacheForLocalUsers But I'm surprised that Debian would enable this feature without changing the nsswitch.conf order like Fedora did. They probably should disable the files domain by default..
The files domain is currently identity-only and no authentication is performed. That, together with the duplicate users and the files domain running by default has been causing the failures for you..
On a side-note: I just tested this enable_files_domain and it seems using it results in the next domain still being queried for local users (verified by sifting through the ldap server logs). Using an explicit domain with id_provider=files apparently works differently (that domain answers and the next one is not queried), which is not very transparent. Is this expected?
What was the order of the explicit domains? Note the implicit domain is always prepended before any other domain..
The order in case of an explicit domain is first the files-based one, then ldap. So the order is (or should be) identical in both cases.
Then I don't know without logs, sorry.
On (24/01/18 10:10), Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page. Thanks so much for the help.
Implicit files domain is still enabled in debian (even in unstable) https://anonscm.debian.org/cgit/pkg-sssd/sssd.git/tree/debian/rules#n39
I had a discussion with Timo few days/weeks ago that it does not make a huge sense for debian. Because default order of modules in nsswitch.conf does not have sss as 1st one.
It would be good to revert commit https://anonscm.debian.org/cgit/pkg-sssd/sssd.git/commit/?id=039d86778617826...
Adding Timo to CC
LS
On Wed, Jan 24, 2018 at 06:35:48PM +0100, Lukas Slebodnik wrote:
On (24/01/18 10:10), Geoff Goehle wrote:
Sorry about the line breaks. Adding "enable_files_domain = false" to the [sssd] section fixed the issue. Just out of curiosity, could I ask what that does? Its not in the man page. Thanks so much for the help.
Implicit files domain is still enabled in debian (even in unstable) https://anonscm.debian.org/cgit/pkg-sssd/sssd.git/tree/debian/rules#n39
I had a discussion with Timo few days/weeks ago that it does not make a huge sense for debian. Because default order of modules in nsswitch.conf does not have sss as 1st one.
It would be good to revert commit https://anonscm.debian.org/cgit/pkg-sssd/sssd.git/commit/?id=039d86778617826...
Adding Timo to CC
There is also already https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=888207
sssd-users@lists.fedorahosted.org