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