Red Hat Bugzilla – Bug 1515759
ipa-server-install with different IP fails on /usr/sbin/pkispawn -s CA
Last modified: 2018-10-23 11:43:40 EDT
Issue reproducible. In order to reproduce, you need to add the machine IP address to /etc/hosts (the existing one, not the fake one). In this case, pki-spawn fails with: 2017-11-23 09:37:48 pkispawn : INFO ....... executing 'systemctl daemon-reload' 2017-11-23 09:37:48 pkispawn : INFO ....... executing 'systemctl start pki-tomcatd@pki-tomcat.service' 2017-11-23 09:37:49 pkispawn : DEBUG ........... pki_protocol https hostname vm-110.abc.idm.lab.eng.brq.redhat.com port 8443 subsystem ca 2017-11-23 09:39:56 pkispawn : DEBUG ........... No connection - server may still be down 2017-11-23 09:39:56 pkispawn : DEBUG ........... No connection - exception thrown: ('Connection aborted.', error(110, 'Connection timed out')) 2017-11-23 09:39:57 pkispawn : ERROR ....... server failed to restart 2017-11-23 09:39:57 pkispawn : DEBUG ....... Error Type: Exception 2017-11-23 09:39:57 pkispawn : DEBUG ....... Error Message: server failed to restart 2017-11-23 09:39:57 pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 533, in main scriptlet.spawn(deployer) File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 374, in spawn raise Exception("server failed to restart") The code shows that pki spawn is checking if the server is running (https://github.com/dogtagpki/pki/blob/DOGTAG_10_4_BRANCH/base/server/python/pki/server/deployment/pkihelper.py#L1020) by connecting to the url https://`hostname`:8443/ca/admin/ca/getStatus. Note that there is only one connection try. Wireshark demonstrates that the fake IP address is used. I noticed that if the timeout waiting for the server to come up is raised to 200s for instance, pki spawn finishes successfully (https://github.com/dogtagpki/pki/blob/DOGTAG_10_4_BRANCH/base/server/python/pki/server/deployment/scriptlets/configuration.py#L369). So there are probably 2 timeouts that interact here: - the timeout set in deployer.instance.wait_for_startup(60), which allows to perform multiple times a get on https://hostname:8443/ca/admin/ca/getStatus (until timeout is exhausted) - the timeout used to establish the connection when get(url) is called, probably defined at the system level. When first timeout < second timeout, the get(url) can be performed only once and fails. If first timeout > 2nd timeout, the get(url) can be performed a second time and the second time succeeds. Fraser, I know you added the ability to configure the first timeout in the master branch, so could you have a look at this issue?
Thanks for the analysis, Flo. This is an obscure issue. I'd argue that rather than fiddling with timeouts, the problem of it attempting to a nonexistant IP address should be resolved. This begs the question - why would someone put an --ip-address that does not exist on the machine? What is the use case? Maybe there should be a sanity check for this option instead?
The use case is described in these upstream tickets: https://pagure.io/freeipa/issue/2715 https://pagure.io/freeipa/issue/4317
Thanks Flo, I'll look into this.
Fix needs to be done in Dogtag; changed component to pki-core and reference upstream ticket (https://pagure.io/dogtagpki/issue/2939). Gerrit reviews - master: https://review.gerrithub.io/#/c/399972/ - DOGTAG_10_5_BRANCH: https://review.gerrithub.io/#/c/399973/
Upstream patch pushed: - master: 1671d9c3b3b2bdd48fd74c3229c2869e5cfac80c - DOGTAG_10_5_BRANCH: abe1b5b0850115008a29ad54d82a25971293f932
edewata wrote: The patch apparently causes installation with HSM to fail since the timeout is too short. It probably should be implemented as a configurable parameter. It has been reverted in the following commits: master: https://github.com/dogtagpki/pki/commit/5d80aee3f64d57da2c92e89c15fd8fd2aae5f2eb 10.5 branch: https://github.com/dogtagpki/pki/commit/c576b6519a136db2553ab840952bce565f58547d
Endi, any idea what would be an appropriate default value that would be sufficient for HSM environments?
Fraser, I'm not sure. That would depend on the environment. In general I'd rather avoid introducing a new default value if there is one already available from the system. So I think the timeout parameter should be unset by default, but a user-defined timeout can be specified in pki.conf for specific scenarios like this.
New gerrit review, implementing a configurable timeout. https://review.gerrithub.io/#/c/401523/
ftweedal wrote: Pushed to master (132ddb4fcadcaa6eb8cbfc0e1f2a37b8b5654119)
Version: ipa-server-4.6.4-8.el7.x86_64 pki-server-10.5.9-6.el7.noarch Tested the bug on the basis of below observations: 1. Noticed that when ip address which is unavailable on system is used for ipa-server installation, the installation fails. Console: [root@vm-idm-011 ~]# rpm -q ipa-server ipa-server-4.6.4-8.el7.x86_64 [root@vm-idm-011 ~]# ip addr on system is 10.x.x.x, no other ip address available. [root@vm-idm-011 ~]# ipa-server-install --setup-dns --forwarder=10.x.x.x --ip-address=12.13.14.15 -r TESTRELM.TEST -p Secret123 -a Secret123 -U --allow-zone-overlap The log file for this installation can be found in /var/log/ipaserver-install.log ============================================================================== This program will set up the IPA Server. This includes: * Configure a stand-alone CA (dogtag) for certificate management * Configure the Network Time Daemon (ntpd) * Create and configure an instance of Directory Server * Create and configure a Kerberos Key Distribution Center (KDC) * Configure Apache (httpd) * Configure DNS (bind) * Configure the KDC to enable PKINIT WARNING: conflicting time&date synchronization service 'chronyd' will be disabled in favor of ntpd Warning: skipping DNS resolution of host vm-idm-011.testrelm.test The domain name has been determined based on the host name. Checking DNS domain testrelm.test., please wait ... WARNING: No network interface matches the IP address 12.13.14.15 Checking DNS forwarders, please wait ... The IPA Master Server will be configured with: Hostname: vm-idm-011.testrelm.test IP address(es): 12.13.14.15 Domain name: testrelm.test Realm name: TESTRELM.TEST BIND DNS server will be configured to serve IPA domain with: Forwarders: 10.x.x.x Forward policy: first Reverse zone(s): No reverse zone Adding [12.13.14.15 vm-idm-011.testrelm.test] to your /etc/hosts file Configuring NTP daemon (ntpd) [1/4]: stopping ntpd [2/4]: writing configuration [3/4]: configuring ntpd to start on boot [4/4]: starting ntpd Done configuring NTP daemon (ntpd). Configuring directory server (dirsrv). Estimated time: 30 seconds [1/44]: creating directory server instance [2/44]: enabling ldapi [3/44]: configure autobind for root [4/44]: stopping directory server [5/44]: updating configuration in dse.ldif [6/44]: starting directory server [7/44]: adding default schema [8/44]: enabling memberof plugin [9/44]: enabling winsync plugin [10/44]: configuring replication version plugin [11/44]: enabling IPA enrollment plugin [12/44]: configuring uniqueness plugin [13/44]: configuring uuid plugin [14/44]: configuring modrdn plugin [15/44]: configuring DNS plugin [16/44]: enabling entryUSN plugin [17/44]: configuring lockout plugin [18/44]: configuring topology plugin [19/44]: creating indices [20/44]: enabling referential integrity plugin [21/44]: configuring certmap.conf [22/44]: configure new location for managed entries [23/44]: configure dirsrv ccache [24/44]: enabling SASL mapping fallback [25/44]: restarting directory server [26/44]: adding sasl mappings to the directory [27/44]: adding default layout [28/44]: adding delegation layout [29/44]: creating container for managed entries [30/44]: configuring user private groups [31/44]: configuring netgroups from hostgroups [32/44]: creating default Sudo bind user [33/44]: creating default Auto Member layout [34/44]: adding range check plugin [35/44]: creating default HBAC rule allow_all [36/44]: adding entries for topology management [37/44]: initializing group membership [38/44]: adding master entry [39/44]: initializing domain level [40/44]: configuring Posix uid/gid generation [41/44]: adding replication acis [42/44]: activating sidgen plugin [43/44]: activating extdom plugin [44/44]: configuring directory to start on boot Done configuring directory server (dirsrv). Configuring Kerberos KDC (krb5kdc) [1/10]: adding kerberos container to the directory [2/10]: configuring KDC [3/10]: initialize kerberos container [4/10]: adding default ACIs [5/10]: creating a keytab for the directory [6/10]: creating a keytab for the machine [7/10]: adding the password extension to the directory [8/10]: creating anonymous principal [9/10]: starting the KDC [10/10]: configuring KDC to start on boot Done configuring Kerberos KDC (krb5kdc). Configuring kadmin [1/2]: starting kadmin [2/2]: configuring kadmin to start on boot Done configuring kadmin. Configuring ipa-custodia [1/5]: Making sure custodia container exists [2/5]: Generating ipa-custodia config file [3/5]: Generating ipa-custodia keys [4/5]: starting ipa-custodia [5/5]: configuring ipa-custodia to start on boot Done configuring ipa-custodia. Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes [1/28]: configuring certificate server instance ipaserver.install.dogtaginstance: CRITICAL Failed to configure CA instance: Command '/usr/sbin/pkispawn -s CA -f /tmp/tmpC2n2pM' returned non-zero exit status 1 ipaserver.install.dogtaginstance: CRITICAL See the installation logs and the following files/directories for more information: ipaserver.install.dogtaginstance: CRITICAL /var/log/pki/pki-tomcat [error] RuntimeError: CA configuration failed. ipapython.admintool: ERROR CA configuration failed. ipapython.admintool: ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information [root@vm-idm-011 ~]# [root@vm-idm-011 ~]# cat /etc/hosts 127.0.0.1 localhost localhost.localdomain localhost4 localhost4.localdomain4 ::1 localhost localhost.localdomain localhost6 localhost6.localdomain6 10.x.x.x vm-idm-011.testrelm.test vm-idm-011 12.13.14.15 vm-idm-011.testrelm.test vm-idm-011 # /var/log/ipaserver-install.log 2018-09-06T09:03:55Z DEBUG [1/28]: configuring certificate server instance 2018-09-06T09:03:55Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state' 2018-09-06T09:03:55Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state' 2018-09-06T09:03:55Z DEBUG Contents of pkispawn configuration file (/tmp/tmpC2n2pM): [CA] pki_security_domain_name = IPA pki_enable_proxy = True pki_restart_configured_instance = False pki_backup_keys = True pki_backup_password = XXXXXXXX pki_profiles_in_ldap = True pki_default_ocsp_uri = http://ipa-ca.testrelm.test/ca/ocsp pki_status_request_timeout = 15 pki_client_pkcs12_password = XXXXXXXX pki_admin_name = admin pki_admin_uid = admin pki_admin_email = root@localhost pki_admin_password = XXXXXXXX pki_admin_nickname = ipa-ca-agent pki_admin_subject_dn = cn=ipa-ca-agent,O=TESTRELM.TEST pki_client_admin_cert_p12 = /root/ca-agent.p12 pki_ds_ldap_port = 389 pki_ds_password = XXXXXXXX pki_ds_base_dn = o=ipaca pki_ds_database = ipaca pki_subsystem_subject_dn = cn=CA Subsystem,O=TESTRELM.TEST pki_ocsp_signing_subject_dn = cn=OCSP Subsystem,O=TESTRELM.TEST pki_ssl_server_subject_dn = cn=vm-idm-011.testrelm.test,O=TESTRELM.TEST pki_audit_signing_subject_dn = cn=CA Audit,O=TESTRELM.TEST pki_ca_signing_subject_dn = CN=Certificate Authority,O=TESTRELM.TEST pki_subsystem_nickname = subsystemCert cert-pki-ca pki_ocsp_signing_nickname = ocspSigningCert cert-pki-ca pki_ssl_server_nickname = Server-Cert cert-pki-ca pki_audit_signing_nickname = auditSigningCert cert-pki-ca pki_ca_signing_nickname = caSigningCert cert-pki-ca pki_ca_signing_key_algorithm = SHA256withRSA pki_pin = XXXXXXXX 2018-09-06T09:03:55Z DEBUG Starting external process 2018-09-06T09:03:55Z DEBUG args=/usr/sbin/pkispawn -s CA -f /tmp/tmpC2n2pM 2018-09-06T09:06:05Z DEBUG Process finished, return code=1 2018-09-06T09:06:05Z DEBUG stdout=Log file: /var/log/pki/pki-ca-spawn.20180906143355.log Loading deployment configuration from /tmp/tmpC2n2pM. WARNING: The 'pki_ssl_server_nickname' in [CA] has been deprecated. Use 'pki_sslserver_nickname' instead. WARNING: The 'pki_ssl_server_subject_dn' in [CA] has been deprecated. Use 'pki_sslserver_subject_dn' instead. Installing CA into /var/lib/pki/pki-tomcat. Storing deployment configuration into /etc/sysconfig/pki/tomcat/pki-tomcat/ca/deployment.cfg. Installation failed: server failed to restart 2018-09-06T09:06:05Z DEBUG stderr=pkispawn : ERROR ....... server failed to restart 2018-09-06T09:06:05Z CRITICAL Failed to configure CA instance: Command '/usr/sbin/pkispawn -s CA -f /tmp/tmpC2n2pM' returned non-zero exit status 1 2018-09-06T09:06:05Z CRITICAL See the installation logs and the following files/directories for more information: 2018-09-06T09:06:05Z CRITICAL /var/log/pki/pki-tomcat 2018-09-06T09:06:05Z DEBUG Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 570, in start_creation run_step(full_msg, method) File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 560, in run_step method() File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 660, in __spawn_instance pki_pin) File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 166, in spawn_instance self.handle_setup_error(e) File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 406, in handle_setup_error raise RuntimeError("%s configuration failed." % self.subsystem) RuntimeError: CA configuration failed. 2018-09-06T09:06:05Z DEBUG [error] RuntimeError: CA configuration failed. 2018-09-06T09:06:05Z DEBUG File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 178, in execute return_value = self.run() File "/usr/lib/python2.7/site-packages/ipapython/install/cli.py", line 319, in run return cfgr.run() File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in run return self.execute() File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 389, in execute for rval in self._executor(): File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 434, in __runner exc_handler(exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 463, in _handle_execute_exception self._handle_exception(exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 453, in _handle_exception six.reraise(*exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 424, in __runner step() File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 421, in <lambda> step = lambda: next(self.__gen) File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from six.reraise(*exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from value = gen.send(prev_value) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 658, in _configure next(executor) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 434, in __runner exc_handler(exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 463, in _handle_execute_exception self._handle_exception(exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 521, in _handle_exception self.__parent._handle_exception(exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 453, in _handle_exception six.reraise(*exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 518, in _handle_exception super(ComponentBase, self)._handle_exception(exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 453, in _handle_exception six.reraise(*exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 424, in __runner step() File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 421, in <lambda> step = lambda: next(self.__gen) File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from six.reraise(*exc_info) File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from value = gen.send(prev_value) File "/usr/lib/python2.7/site-packages/ipapython/install/common.py", line 65, in _install for unused in self._installer(self.parent): File "/usr/lib/python2.7/site-packages/ipaserver/install/server/__init__.py", line 583, in main master_install(self) File "/usr/lib/python2.7/site-packages/ipaserver/install/server/install.py", line 250, in decorated func(installer) File "/usr/lib/python2.7/site-packages/ipaserver/install/server/install.py", line 812, in install ca.install_step_0(False, None, options, custodia=custodia) File "/usr/lib/python2.7/site-packages/ipaserver/install/ca.py", line 303, in install_step_0 use_ldaps=standalone) File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 475, in configure_instance self.start_creation(runtime=runtime) File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 570, in start_creation run_step(full_msg, method) File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 560, in run_step method() File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 660, in __spawn_instance pki_pin) File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 166, in spawn_instance self.handle_setup_error(e) File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 406, in handle_setup_error raise RuntimeError("%s configuration failed." % self.subsystem) 2018-09-06T09:06:05Z DEBUG The ipa-server-install command failed, exception: RuntimeError: CA configuration failed. 2018-09-06T09:06:05Z ERROR CA configuration failed. 2018-09-06T09:06:05Z ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information Thus on the basis of above observations, ipa-server installation still fails, thus marking the status of bug to 'ASSIGNED'
Failure noticed at installation step: Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes [1/28]: configuring certificate server instance ipaserver.install.dogtaginstance: CRITICAL Failed to configure CA instance: Command '/usr/sbin/pkispawn -s CA -f /tmp/tmpC2n2pM' returned non-zero exit status 1 ipaserver.install.dogtaginstance: CRITICAL See the installation logs and the following files/directories for more information: ipaserver.install.dogtaginstance: CRITICAL /var/log/pki/pki-tomcat [error] RuntimeError: CA configuration failed. ipapython.admintool: ERROR CA configuration failed. ipapython.admintool: ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information