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!
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
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
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