Hi, On Thu, Oct 20, 2022 at 2:34 PM Mark Johanson via FreeIPA-users < [email protected]> 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' > The reference to port 389 may be misleading. Did you check that the KDC ports are also reachable (88 / 464)? flo (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 > _______________________________________________ > 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 >
_______________________________________________ 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
