Mark Johanson via FreeIPA-users wrote: > Hello, > > Having an issue with our CentOS 7 boxes joining FreeIPA. When I run the > ipa-client-install command It does its thing up to a point. At which point > the server slows to a dead crawl: > > Discovery was successful! > Client hostname: newclient.test.com > Realm: EXAMPLE.COM > DNS Domain: example.com > IPA Server: freeipa2.example.com > BaseDN: dc=example,dc=com > > Skipping synchronizing time with NTP server. > Successfully retrieved CA cert > Subject: CN=Certificate Authority,O=EXAMPLE.COM > Issuer: CN=Certificate Authority,O=EXAMPLE.COM > Valid From: 2020-12-04 02:53:05 > Valid Until: 2040-12-04 02:53:05 > > Enrolled in IPA realm EXAMPLE.COM > Created /etc/ipa/default.conf > New SSSD config will be created > Configured sudoers in /etc/nsswitch.conf > Configured /etc/sssd/sssd.conf > Configured /etc/krb5.conf for IPA realm EXAMPLE.COM > trying https://freeipa2.example.com/ipa/json > [try 1]: Forwarding 'schema' to json server > 'https://freeipa2.example.com/ipa/json' > trying https://freeipa2.example.com/ipa/session/json > [try 1]: Forwarding 'ping' to json server > 'https://freeipa2.example.com/ipa/session/json' > [try 1]: Forwarding 'ca_is_enabled' to json server > 'https://freeipa2.example.com/ipa/session/json' > Systemwide CA database updated. > Adding SSH public key from /etc/ssh/ssh_host_ed25519_key.pub > Adding SSH public key from /etc/ssh/ssh_host_rsa_key.pub > Adding SSH public key from /etc/ssh/ssh_host_ecdsa_key.pub > [try 1]: Forwarding 'host_mod' to json server > 'https://freeipa2.example.com/ipa/session/json' > Could not update DNS SSHFP records. > SSSD enabled > Configured /etc/openldap/ldap.conf > > At this point we are now just hanging. > > In trying to debug the issue, I start the client install and with sssctl I > increase the debug to 10 and when it reaches the point of hanging, I found > the following in the logs: > > sssd_example.com.log: > > (2022-10-19 10:18:37): [be[example.com]] [request_watch_destructor] (0x0400): > Deleting request watch > (2022-10-19 10:18:37): [be[example.com]] [set_server_common_status] (0x0100): > Marking server 'freeipa1.example.com' as 'name resolved' > (2022-10-19 10:18:37): [be[example.com]] [be_resolve_server_process] > (0x0200): Found address for server freeipa1.example.com: [192.168.1.1] TTL 193 > (2022-10-19 10:18:37): [be[example.com]] [ipa_resolve_callback] (0x0400): > Constructed uri 'ldap://freeipa1.example.com' > (2022-10-19 10:18:37): [be[example.com]] [krb5_add_krb5info_offline_callback] > (0x4000): Removal callback already available for service [IPA]. > (2022-10-19 10:18:37): [be[example.com]] [unique_filename_destructor] > (0x2000): Unlinking [/var/lib/sss/pubconf/.krb5info_dummy_70orma] > (2022-10-19 10:18:37): [be[example.com]] [unlink_dbg] (0x2000): File already > removed: [/var/lib/sss/pubconf/.krb5info_dummy_70orma] > (2022-10-19 10:18:37): [be[example.com]] [sdap_kinit_kdc_resolved] (0x1000): > KDC resolved, attempting to get TGT... > (2022-10-19 10:18:37): [be[example.com]] [create_tgt_req_send_buffer] > (0x0400): buffer size: 60 > (2022-10-19 10:18:37): [be[example.com]] [child_handler_setup] (0x2000): > Setting up signal handler up for pid [16003] > (2022-10-19 10:18:37): [be[example.com]] [child_handler_setup] (0x2000): > Signal handler set up for pid [16003] > (2022-10-19 10:18:37): [be[example.com]] [set_tgt_child_timeout] (0x0400): > Setting 6 seconds timeout for TGT child > (2022-10-19 10:18:37): [be[example.com]] [write_pipe_handler] (0x0400): All > data has been sent! > (2022-10-19 10:18:43): [be[example.com]] [get_tgt_timeout_handler] (0x4000): > timeout for sending SIGTERM to TGT child [16003] reached. > (2022-10-19 10:18:43): [be[example.com]] [get_tgt_timeout_handler] (0x0400): > Setting 2 seconds timeout for sending SIGKILL to TGT child > (2022-10-19 10:18:43): [be[example.com]] [read_pipe_handler] (0x0400): EOF > received, client finished > (2022-10-19 10:18:43): [be[example.com]] [child_sig_handler] (0x1000): > Waiting for child [16003]. > (2022-10-19 10:18:43): [be[example.com]] [child_sig_handler] (0x0020): child > [16003] failed with status [7]. > (2022-10-19 10:18:43): [be[example.com]] [child_callback] (0x0020): LDAP > child was terminated due to timeout > (2022-10-19 10:18:43): [be[example.com]] [sdap_kinit_done] (0x0080): > Communication with KDC timed out, trying the next one > (2022-10-19 10:18:43): [be[example.com]] [_be_fo_set_port_status] (0x8000): > Setting status: PORT_NOT_WORKING. Called from: > src/providers/ldap/sdap_async_connection.c: sdap_kinit_done: 1242 > (2022-10-19 10:18:43): [be[example.com]] [fo_set_port_status] (0x0100): > Marking port 389 of server 'freeipa1.example.com' as 'not working' > (2022-10-19 10:18:43): [be[example.com]] [fo_set_port_status] (0x0400): > Marking port 389 of duplicate server 'freeipa1.example.com' as 'not working' > (2022-10-19 10:18:43): [be[example.com]] [sdap_kinit_next_kdc] (0x1000): > Resolving next KDC for service IPA > (2022-10-19 10:18:43): [be[example.com]] [fo_resolve_service_send] (0x0100): > Trying to resolve service 'IPA' > (2022-10-19 10:18:43): [be[example.com]] [get_server_status] (0x1000): Status > of server 'freeipa2.example.com' is 'name not resolved' > (2022-10-19 10:18:43): [be[example.com]] [get_port_status] (0x1000): Port > status of port 389 for server 'freeipa2.example.com' is 'neutral' > (2022-10-19 10:18:43): [be[example.com]] > [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 > seconds > (2022-10-19 10:18:43): [be[example.com]] [resolve_srv_send] (0x0200): The > status of SRV lookup is resolved > (2022-10-19 10:18:43): [be[example.com]] [get_server_status] (0x1000): Status > of server 'freeipa2.example.com' is 'name not resolved' > (2022-10-19 10:18:43): [be[example.com]] [resolv_is_address] (0x4000): > [freeipa2.example.com] does not look like an IP address > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_step] > (0x2000): Querying files > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_files_send] > (0x0100): Trying to resolve A record of 'freeipa2.example.com' in files > (2022-10-19 10:18:43): [be[example.com]] [set_server_common_status] (0x0100): > Marking server 'freeipa2.example.com' as 'resolving name' > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_step] > (0x2000): Querying files > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_files_send] > (0x0100): Trying to resolve AAAA record of 'freeipa2.example.com' in files > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_next] > (0x0200): No more address families to retry > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_step] > (0x2000): Querying DNS > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_dns_query] > (0x0100): Trying to resolve A record of 'freeipa2.example.com' in DNS > (2022-10-19 10:18:43): [be[example.com]] [schedule_request_timeout] (0x2000): > Scheduling a timeout of 6 seconds > (2022-10-19 10:18:43): [be[example.com]] [schedule_timeout_watcher] (0x2000): > Scheduling DNS timeout watcher > (2022-10-19 10:18:43): [be[example.com]] [unschedule_timeout_watcher] > (0x4000): Unscheduling DNS timeout watcher > (2022-10-19 10:18:43): [be[example.com]] [resolv_gethostbyname_dns_parse] > (0x1000): Parsing an A reply > (2022-10-19 10:18:43): [be[example.com]] [request_watch_destructor] (0x0400): > Deleting request watch > (2022-10-19 10:18:43): [be[example.com]] [set_server_common_status] (0x0100): > Marking server 'freeipa2.example.com' as 'name resolved' > (2022-10-19 10:18:43): [be[example.com]] [be_resolve_server_process] > (0x0200): Found address for server freeipa2.example.com: [192.168.1.2] TTL 266 > (2022-10-19 10:18:43): [be[example.com]] [ipa_resolve_callback] (0x0400): > Constructed uri 'ldap://freeipa2.example.com' > (2022-10-19 10:18:43): [be[example.com]] [krb5_add_krb5info_offline_callback] > (0x4000): Removal callback already available for service [IPA]. > (2022-10-19 10:18:43): [be[example.com]] [unique_filename_destructor] > (0x2000): Unlinking [/var/lib/sss/pubconf/.krb5info_dummy_B0Adsl] > (2022-10-19 10:18:43): [be[example.com]] [unlink_dbg] (0x2000): File already > removed: [/var/lib/sss/pubconf/.krb5info_dummy_B0Adsl] > (2022-10-19 10:18:43): [be[example.com]] [sdap_kinit_kdc_resolved] (0x1000): > KDC resolved, attempting to get TGT... > (2022-10-19 10:18:43): [be[example.com]] [create_tgt_req_send_buffer] > (0x0400): buffer size: 60 > (2022-10-19 10:18:43): [be[example.com]] [child_handler_setup] (0x2000): > Setting up signal handler up for pid [16020] > (2022-10-19 10:18:43): [be[example.com]] [child_handler_setup] (0x2000): > Signal handler set up for pid [16020] > (2022-10-19 10:18:43): [be[example.com]] [set_tgt_child_timeout] (0x0400): > Setting 6 seconds timeout for TGT child > (2022-10-19 10:18:43): [be[example.com]] [write_pipe_handler] (0x0400): All > data has been sent! > (2022-10-19 10:18:49): [be[example.com]] [get_tgt_timeout_handler] (0x4000): > timeout for sending SIGTERM to TGT child [16020] reached. > (2022-10-19 10:18:49): [be[example.com]] [get_tgt_timeout_handler] (0x0400): > Setting 2 seconds timeout for sending SIGKILL to TGT child > (2022-10-19 10:18:49): [be[example.com]] [read_pipe_handler] (0x0400): EOF > received, client finished > (2022-10-19 10:18:49): [be[example.com]] [child_sig_handler] (0x1000): > Waiting for child [16020]. > (2022-10-19 10:18:49): [be[example.com]] [child_sig_handler] (0x0020): child > [16020] failed with status [7]. > (2022-10-19 10:18:49): [be[example.com]] [child_callback] (0x0020): LDAP > child was terminated due to timeout > (2022-10-19 10:18:49): [be[example.com]] [sdap_kinit_done] (0x0080): > Communication with KDC timed out, trying the next one > (2022-10-19 10:18:49): [be[example.com]] [_be_fo_set_port_status] (0x8000): > Setting status: PORT_NOT_WORKING. Called from: > src/providers/ldap/sdap_async_connection.c: sdap_kinit_done: 1242 > (2022-10-19 10:18:49): [be[example.com]] [fo_set_port_status] (0x0100): > Marking port 389 of server 'freeipa2.example.com' as 'not working' > (2022-10-19 10:18:49): [be[example.com]] [fo_set_port_status] (0x0400): > Marking port 389 of duplicate server 'freeipa2.example.com' as 'not working' > (2022-10-19 10:18:49): [be[example.com]] [sdap_kinit_next_kdc] (0x1000): > Resolving next KDC for service IPA > > At which point this just scrolls over and over as it works through all of the > IPA servers and then starts all over again. > > I thought it might be firewall on either the client box or the IPA nodes but > I don't get the general error about needing ports open from the > ipa-client-install and from the client I can telnet to all the ports: > > root@newclient [0.04 ] ~ #telnet freeipa1.example.com 389 > Trying 192.168.1.1... > Connected to freeipa1.example.com. > Escape character is '^]'. > > The odd thing is our Almalinux 8 boxes do not have this issue with the same > exact firewall wall setup as the CentOS 7 boxes. > > I've been trying to figure this out for a few days now and could use some > assistance if someone might be able to point me. > > Thanks, > > > > > > Discovery was successful! > Client hostname: newclient.test.com > Realm: EXAMPLE.COM > DNS Domain: example.com > IPA Server: freeipa2.example.com > BaseDN: dc=example,dc=com > > Skipping synchronizing time with NTP server. > Successfully retrieved CA cert > Subject: CN=Certificate Authority,O=EXAMPLE.COM > Issuer: CN=Certificate Authority,O=EXAMPLE.COM > Valid From: 2020-12-04 02:53:05 > Valid Until: 2040-12-04 02:53:05 > > Enrolled in IPA realm EXAMPLE.COM > Created /etc/ipa/default.conf > New SSSD config will be created > Configured sudoers in /etc/nsswitch.conf > Configured /etc/sssd/sssd.conf > Configured /etc/krb5.conf for IPA realm EXAMPLE.COM > trying https://freeipa2.example.com/ipa/json > [try 1]: Forwarding 'schema' to json server > 'https://freeipa2.example.com/ipa/json' > trying https://freeipa2.example.com/ipa/session/json > [try 1]: Forwarding 'ping' to json server > 'https://freeipa2.example.com/ipa/session/json' > [try 1]: Forwarding 'ca_is_enabled' to json server > 'https://freeipa2.example.com/ipa/session/json' > Systemwide CA database updated. > Adding SSH public key from /etc/ssh/ssh_host_ed25519_key.pub > Adding SSH public key from /etc/ssh/ssh_host_rsa_key.pub > Adding SSH public key from /etc/ssh/ssh_host_ecdsa_key.pub > [try 1]: Forwarding 'host_mod' to json server > 'https://freeipa2.example.com/ipa/session/json' > Could not update DNS SSHFP records. > SSSD enabled > Configured /etc/openldap/ldap.conf
It is timing out with SSSD trying to get a Kerberos ticket for itself. (2022-10-19 10:18:43): [be[example.com]] [sdap_kinit_done] (0x0080): Communication with KDC timed out, trying the next one What method of enrollment are you using, a one-time password or a Kerberos principal? Can you share the full /var/log/ipaclient-install.log? rob _______________________________________________ FreeIPA-users mailing list -- [email protected] To unsubscribe send an email to [email protected] Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/[email protected] Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
