I have a one-way trust configured to AD. It has been working for a long time but has stopped and I can't track down what has happened. `getent passwd user` works on users in IPA, but fails (nothing returned) on AD users.
**** Contents of sssd.conf on client: [domain/ipa.domain.edu]
cache_credentials = True krb5_store_password_if_offline = True ipa_domain = ipa.domain.edu id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = test.ipa.domain.edu chpass_provider = ipa ipa_server = _srv_,ipa.ipa.grinnell.edu ipa_server_mode = true ldap_tls_cacert = /etc/ipa/ca.crt krb5_validate = False debug_level=8
[sssd] services = nss, sudo, pam, ssh domains = ipa.domain.edu
[nss] homedir_substring = /home **** `ipa trustdomain-find` returns the trusted AD domain
I haven't found anything I can make sense of in the logs, but this might be a clue to someone else: **** From the sssd_ipa.domain.edu.log (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.edu is Active (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [ipa_srv_ad_acct_lookup_step] (0x0400): Looking up AD account (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain ipa.domain.edu is Active (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [be_mark_dom_offline] (0x1000): Marking subdomain domain.edu offline (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [be_mark_subdom_offline] (0x1000): Marking subdomain domain.edu as inactive (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [ipa_srv_ad_acct_lookup_done] (0x0040): ipa_get_*_acct request failed: [22]: Invalid argument. (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [ipa_subdomain_account_done] (0x0040): ipa_get_*_acct request failed: [22]: Invalid argument. (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [dp_req_done] (0x0400): DP Request [Account #20]: Request handler finished [0]: Success (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [_dp_req_recv] (0x0400): DP Request [Account #20]: Receiving request data. (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #20]: Finished. Success. (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [dp_req_reply_std] (0x1000): DP Request [Account #20]: Returning [Internal Error]: 3,22,Invalid argument (Thu Feb 11 12:07:19 2021) [sssd[be[ipa.domain.edu]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::domain.edu:name=connerms@domain.edu] from reply table ****
This additional bit from the logs indicates a failure to retireve a keytab: **** (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [main] (0x0400): Backend provider (ipa.domain.edu) started! (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_send] (0x1000): Trust direction of subdom domain.edu from forest domain.edu is: one-way inbound: local domain trusts the remote domain (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_1way] (0x0400): Will re-fetch keytab for domain.edu (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [ipa_getkeytab_send] (0x0400): Retrieving keytab for IPA$@DOMAIN.EDU from test.ipa.domain.edu into /var/lib/sss/keytabs/domain.edu.keytabDHvyo4 using ccache /var/lib/sss/db/ccache_ipa.domain.edu (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [80814] (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Signal handler set up for pid [80814] (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a5db00 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a5db00 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_remove_timeout] (0x2000): 0x556b59a5e9c0 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a5db00 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): Dispatching. (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_server_init_new_connection] (0x0200): Entering. (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x556b59a85950. (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x556b59a85950 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_add_watch] (0x2000): 0x556b59a8f920/0x556b59a80e30 (18), -/W (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a7e380 (18), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x556b59a8ec30] (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.AccessControl with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a85950 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a7e380 (18), R/- (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a80e30 (18), -/W (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a7e380 (18), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a80e30 (18), -/W (disabled) Unable to initialize STARTTLS session Failed to bind to server! Failed to get keytab ***
On Thu, Feb 11, 2021 at 10:20:45PM -0000, Mike Conner via FreeIPA-users wrote:
This additional bit from the logs indicates a failure to retireve a keytab:
(Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [main] (0x0400): Backend provider (ipa.domain.edu) started! (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_send] (0x1000): Trust direction of subdom domain.edu from forest domain.edu is: one-way inbound: local domain trusts the remote domain (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_1way] (0x0400): Will re-fetch keytab for domain.edu (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [ipa_getkeytab_send] (0x0400): Retrieving keytab for IPA$@DOMAIN.EDU from test.ipa.domain.edu into /var/lib/sss/keytabs/domain.edu.keytabDHvyo4 using ccache /var/lib/sss/db/ccache_ipa.domain.edu (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [80814] (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Signal handler set up for pid [80814] (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a5db00 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a5db00 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d700 (14), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a20780/0x556b59a5d6b0 (14), -/W (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_remove_timeout] (0x2000): 0x556b59a5e9c0 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a5db00 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): Dispatching. (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [id_callback] (0x0100): Got id ack and version (1) from Monitor (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_server_init_new_connection] (0x0200): Entering. (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_server_init_new_connection] (0x0200): Adding connection 0x556b59a85950. (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_init_connection] (0x0400): Adding connection 0x556b59a85950 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_add_watch] (0x2000): 0x556b59a8f920/0x556b59a80e30 (18), -/W (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a7e380 (18), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_server_init_new_connection] (0x0200): Got a connection (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [dp_client_init] (0x0100): Set-up Backend ID timeout [0x556b59a8ec30] (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Client with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_conn_register_path] (0x0400): Registering object path /org/freedesktop/sssd/dataprovider with D-Bus connection (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Properties with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.DBus.Introspectable with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.dataprovider with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Backend with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.Failover with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_opath_hash_add_iface] (0x0400): Registering interface org.freedesktop.sssd.DataProvider.AccessControl with path /org/freedesktop/sssd/dataprovider (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x556b59a85950 (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a7e380 (18), R/- (disabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a80e30 (18), -/W (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a7e380 (18), R/- (enabled) (Thu Feb 11 15:45:13 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x556b59a8f920/0x556b59a80e30 (18), -/W (disabled) Unable to initialize STARTTLS session
Hi,
SSSD is calling ipa-getkeytab here, does it work if you call ipa-getkeytab manually? Please make sure you use the '--retrieve' option to not override existing keys.
The STARTTLS might indicate issues with certificates. Have you check if maybe a related certificate is expired?
bye, Sumit
Failed to bind to server! Failed to get keytab
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@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.fedorahoste... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
I'm afraid I don't know how to construct the right ipa-getkeytab command to test. Do I run ipa-getkeytab on the client or on the ipa server? For the IPA$@DOMAIN.EDU principal?
I thought about STARTTLS pointing to a certificate issue. The certs on the ipa server are not expired:
getcert list | grep expires expires: 2022-06-18 21:28:39 UTC expires: 2022-05-24 03:14:46 UTC expires: 2022-05-24 03:15:16 UTC expires: 2022-05-24 03:14:56 UTC expires: 2038-07-11 18:11:01 UTC expires: 2022-05-24 03:14:38 UTC expires: 2022-08-01 03:40:17 UTC expires: 2022-06-15 03:14:35 UTC expires: 2022-06-15 03:14:50 UTC
Could it be an issue with an expired certificate on the AD end? Thank you!
The certificate for the AD secure ldap server is also current (ad.domain.edu:636).
Mike Conner via FreeIPA-users wrote:
The certificate for the AD secure ldap server is also current (ad.domain.edu:636).
It would only be binding to IPA for ipa-getkeytab. I don't know how sssd invokes it.
But you should be able to see a failed TLS connection in the 389-ds logs which could help point the way.
rob
The following is a portion of the sssd log on the client reflecting the same inability to retrieve keytab: *** (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_send] (0x1000): Trust direction of subdom domain.edu from forest domain.edu is: one-way inbound: local domain trusts the remote domain (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_1way] (0x0400): Will re-fetch keytab for domain.edu (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [ipa_getkeytab_send] (0x0400): Retrieving keytab for IPA$@domain.EDU from test.ipa.domain.edu into /var/lib/sss/keytabs/domain.edu.keytabENwf67 using ccache /var/lib/sss/db/ccache_IPA.DOMAIN.EDU (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [88300] (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Signal handler set up for pid [88300] (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x5578611b8b00 (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x5578611b8b00 (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x55786117b780/0x5578611b8700 (14), R/- (disabled) (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x55786117b780/0x5578611b86b0 (14), -/W (enabled) ***
At the same time, the errors log on the IPA server (/var/log/dirsrv/slapd_IPA-DOMAIN-EDU/errors) does not log any errors (TLS or otherwise): *** [12/Feb/2021:10:08:10.990268019 -0600] - INFO - slapd_daemon - slapd started. Listening on All Interfaces port 389 for LDAP requests [12/Feb/2021:10:08:10.992126928 -0600] - INFO - slapd_daemon - Listening on All Interfaces port 636 for LDAPS requests [12/Feb/2021:10:08:10.993036367 -0600] - INFO - slapd_daemon - Listening on /var/run/slapd-IPA-DOMAIN-EDU.socket for LDAPI requests [12/Feb/2021:10:08:11.058722880 -0600] - ERR - schema-compat-plugin - schema-compat-plugin tree scan will start in about 5 seconds! [12/Feb/2021:10:08:16.148838179 -0600] - ERR - schema-compat-plugin - warning: no entries set up under cn=computers, cn=compat,dc=ipa,dc=domain,dc=edu [12/Feb/2021:10:08:16.150531968 -0600] - ERR - schema-compat-plugin - Finished plugin initialization. ***
Thanks!
This may be useful information: Clients are still able to lookup and authenticate AD users as long as they have an in-tact cache. If I empty the sssd cache, that client will no longer be able to perform AD lookups or authentications.
Mike Conner via FreeIPA-users wrote:
The following is a portion of the sssd log on the client reflecting the same inability to retrieve keytab:
(Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_send] (0x1000): Trust direction of subdom domain.edu from forest domain.edu is: one-way inbound: local domain trusts the remote domain (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [ipa_server_trusted_dom_setup_1way] (0x0400): Will re-fetch keytab for domain.edu (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [ipa_getkeytab_send] (0x0400): Retrieving keytab for IPA$@domain.EDU from test.ipa.domain.edu into /var/lib/sss/keytabs/domain.edu.keytabENwf67 using ccache /var/lib/sss/db/ccache_IPA.DOMAIN.EDU (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [88300] (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [child_handler_setup] (0x2000): Signal handler set up for pid [88300] (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x5578611b8b00 (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x5578611b8b00 (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x55786117b780/0x5578611b8700 (14), R/- (disabled) (Fri Feb 12 10:11:54 2021) [sssd[be[ipa.domain.edu]]] [sbus_toggle_watch] (0x4000): 0x55786117b780/0x5578611b86b0 (14), -/W (enabled)
At the same time, the errors log on the IPA server (/var/log/dirsrv/slapd_IPA-DOMAIN-EDU/errors) does not log any errors (TLS or otherwise):
[12/Feb/2021:10:08:10.990268019 -0600] - INFO - slapd_daemon - slapd started. Listening on All Interfaces port 389 for LDAP requests [12/Feb/2021:10:08:10.992126928 -0600] - INFO - slapd_daemon - Listening on All Interfaces port 636 for LDAPS requests [12/Feb/2021:10:08:10.993036367 -0600] - INFO - slapd_daemon - Listening on /var/run/slapd-IPA-DOMAIN-EDU.socket for LDAPI requests [12/Feb/2021:10:08:11.058722880 -0600] - ERR - schema-compat-plugin - schema-compat-plugin tree scan will start in about 5 seconds! [12/Feb/2021:10:08:16.148838179 -0600] - ERR - schema-compat-plugin - warning: no entries set up under cn=computers, cn=compat,dc=ipa,dc=domain,dc=edu [12/Feb/2021:10:08:16.150531968 -0600] - ERR - schema-compat-plugin - Finished plugin initialization.
LDAP connections are not logged in errors. You need to look in access.
rob
On Fri, Feb 12, 2021 at 02:10:09PM -0000, Mike Conner via FreeIPA-users wrote:
I'm afraid I don't know how to construct the right ipa-getkeytab command to test. Do I run ipa-getkeytab on the client or on the ipa server? For the IPA$@DOMAIN.EDU principal?
Hi,
SSSD calls
KRB5CCNAME=/var/lib/sss/db/ccache_ipa.domain.edu /usr/sbin/ipa-getkeytab -r -s test.ipa.domain.edu -p 'IPA$@DOMAIN.EDU' -k /var/lib/sss/keytabs/domain.edu.keytab-test
I added '-test' to the keytab name to not overwrite the ones created by SSSD. The Kerberos credentail cache /var/lib/sss/db/ccache_ipa.domain.edu has the Kerberos TGT of the host account which should have the proper permissions to request a keytab.
HTH
bye, Sumit
I thought about STARTTLS pointing to a certificate issue. The certs on the ipa server are not expired:
getcert list | grep expires expires: 2022-06-18 21:28:39 UTC expires: 2022-05-24 03:14:46 UTC expires: 2022-05-24 03:15:16 UTC expires: 2022-05-24 03:14:56 UTC expires: 2038-07-11 18:11:01 UTC expires: 2022-05-24 03:14:38 UTC expires: 2022-08-01 03:40:17 UTC expires: 2022-06-15 03:14:35 UTC expires: 2022-06-15 03:14:50 UTC
Could it be an issue with an expired certificate on the AD end? Thank you! _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@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.fedorahoste... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
Thank you. I've run the following command on the broken client. In this instance 'ipa.ipa.domain.edu' is the IPA server. 'IPA$@DOMAIN.EDU' was used simply because it's what I saw in the logs.
KRB5CCNAME=/var/lib/sss/db/ccache_IPA.DOMAIN.EDU /usr/sbin/ipa-getkeytab -r -s ipa.ipa.domain.edu -p 'IPA$@DOMAIN.EDU' -k /var/lib/sss/keytabs/domain.edu.keytab-test
The result is: `Failed to load translations Failed to parse result: Insufficient access rights
Failed to get keytab`
On pe, 12 helmi 2021, Mike Conner via FreeIPA-users wrote:
Thank you. I've run the following command on the broken client. In this instance 'ipa.ipa.domain.edu' is the IPA server. 'IPA$@DOMAIN.EDU' was used simply because it's what I saw in the logs.
KRB5CCNAME=/var/lib/sss/db/ccache_IPA.DOMAIN.EDU /usr/sbin/ipa-getkeytab -r -s ipa.ipa.domain.edu -p 'IPA$@DOMAIN.EDU' -k /var/lib/sss/keytabs/domain.edu.keytab-test
The result is: `Failed to load translations Failed to parse result: Insufficient access rights
Failed to get keytab`
This is expected behavior because you are running the command on a wrong host. 'IPA$DOMAIN.EDU' is a trusted domain object that is highly privileged as it represents whole IPA domain in view of a trusted Active Directory forest. Only IPA replicas with 'trust agent' or 'trust controller' roles have access to it. There is explicit ACIs set to allow such access only to host/... principals of those IPA replicas.
The command Sumit asked you to run should be ran on IPA master, not the client. E.g., on ipa.ipa.domain.edu.
Thank you for the clarification. I ran in on the IPA server and the keytab was successfully retrieved.
`Keytab successfully retrieved and stored in: /var/lib/sss/keytabs/domain.edu.keytab-test`
-Mike
More logs. This is from another broken client during an attempt to login as an AD user: **** (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [S-1-5-21-71189414-1642862984-1097818727-22197] to IPA server (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 16 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_op_add] (0x2000): New operation 16 timeout 6 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: sh[0x55eb482586a0], connected[1], ops[0x55eb482c6f10], ldap[0x55eb48274a50] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: sh[0x55eb482586a0], connected[1], ops[0x55eb482c6f10], ldap[0x55eb48274a50] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_EXTENDED] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: Operations error(1), Failed to split fully qualified name. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation failed, server logs might contain more details. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_op_destructor] (0x2000): Operation 16 finished (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_id_op_done] (0x4000): releasing operation connection (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_subdomain_account_done] (0x0040): ipa_get_*_acct request failed: [1432158229]: Network I/O Error. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_done] (0x0400): DP Request [Account #1]: Request handler finished [0]: Success (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [_dp_req_recv] (0x0400): DP Request [Account #1]: Receiving request data. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1]: Finished. Success. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_reply_std] (0x1000): DP Request [Account #1]: Returning [Internal Error]: 3,1432158229,Network I/O Error (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:V:domain.edu:name=connerms@domain.edu] from reply table (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_destructor] (0x0400): DP Request [Account #1]: Request removed. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: sh[0x55eb482586a0], connected[1], ops[(nil)], ldap[0x55eb48274a50] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x55eb482d0940 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): Dispatching. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider ****
The `Returning [Internal Error]: 3,1432158229,Network I/O Error` part sticks out.
On Fri, Feb 12, 2021 at 10:43:18PM -0000, Mike Conner via FreeIPA-users wrote:
More logs. This is from another broken client during an attempt to login as an AD user:
(Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sss_domain_get_state] (0x1000): Domain domain.edu is Active (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_get_acct_info_send] (0x0400): Sending request_type: [REQ_FULL_WITH_MEMBERS] for trust user [S-1-5-21-71189414-1642862984-1097818727-22197] to IPA server (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_send] (0x0400): Executing extended operation (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_send] (0x2000): ldap_extended_operation sent, msgid = 16 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_op_add] (0x2000): New operation 16 timeout 6 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: sh[0x55eb482586a0], connected[1], ops[0x55eb482c6f10], ldap[0x55eb48274a50] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: sh[0x55eb482586a0], connected[1], ops[0x55eb482c6f10], ldap[0x55eb48274a50] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_EXTENDED] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation result: Operations error(1), Failed to split fully qualified name. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_exop_done] (0x0040): ldap_extended_operation failed, server logs might contain more details.
Hi,
the client sends a lookup request for the SID S-1-5-21-71189414-1642862984-1097818727-22197 to the server but on the server side a user or a group which are processed during this request do not have an '@' character in the name. Did you modify sssd.conf on the server to return only short names? If that's not the case do you know if the AD object with SID S-1-5-21-71189414-1642862984-1097818727-22197 has some '@' characters in the name? And which version of IPA are you using on the IPA servers?
bye, Sumit
(Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_op_destructor] (0x2000): Operation 16 finished (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_s2n_get_user_done] (0x0040): s2n exop request failed. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_id_op_done] (0x4000): releasing operation connection (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [ipa_subdomain_account_done] (0x0040): ipa_get_*_acct request failed: [1432158229]: Network I/O Error. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_done] (0x0400): DP Request [Account #1]: Request handler finished [0]: Success (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [_dp_req_recv] (0x0400): DP Request [Account #1]: Receiving request data. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #1]: Finished. Success. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_reply_std] (0x1000): DP Request [Account #1]: Returning [Internal Error]: 3,1432158229,Network I/O Error (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1:V:domain.edu:name=connerms@domain.edu] from reply table (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_destructor] (0x0400): DP Request [Account #1]: Request removed. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [dp_req_destructor] (0x0400): Number of active DP request: 0 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: sh[0x55eb482586a0], connected[1], ops[(nil)], ldap[0x55eb48274a50] (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): dbus conn: 0x55eb482d0940 (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sbus_dispatch] (0x4000): Dispatching. (Fri Feb 12 16:35:20 2021) [sssd[be[ipa.domain.edu]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path /org/freedesktop/sssd/dataprovider
The `Returning [Internal Error]: 3,1432158229,Network I/O Error` part sticks out. _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@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.fedorahoste... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
Yes. I had modified sssd.conf on the server in pursuit of the solution to proposed change and that is what caused this issue. I reverted the config and authentication/lookups are now working as expected. I'd forgotten that I made that change and since clients with in-tact caches were still working the impact wasn't evident until I configured a new client and enough time had passed that I didn't make the connection. Lesson learned. Revisiting the logs, I see it was the "Failed to split fully qualified name." that led you to this conclusion.
I'm tremendously grateful for your help!
freeipa-users@lists.fedorahosted.org
-
Alexander Bokovoy -
Mike Conner -
Rob Crittenden -
Sumit Bose