freeipa

#7980 Configuring certificate server (pki-tomcatd). Failed to configure CA instance on F30
Closed: insufficientinfo by rcritten. Opened by outman.

Closed: insufficientinfo
Reopen Issue

When I installed FreeIPA in a new Fedora 30 VM, it failed with this error message :

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/30]: configuring certificate server instance
Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpp98at9s2'] returned non-zero exit status 1: 'pkihelper     : ERROR    Server did not start after 60s\nconfiguration : ERROR    Server failed to restart\npkispawn      : ERROR    Exception: server failed to restart\n  File "/usr/lib/python3.7/site-packages/pki/server/pkispawn.py", line 547, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 670, in spawn\n    raise Exception("server failed to restart")\n\n')
See the installation logs and the following files/directories for more information:
  /var/log/pki/pki-tomcat
  [error] RuntimeError: CA configuration failed.
CA configuration failed.
The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

freeipa-server package :

[root@ipa ~]# rpm -q freeipa-server
freeipa-server-4.7.90.pre1-4.fc30.x86_64
[root@ipa ~]# uname -a
Linux ipa.zerone.os 5.1.8-300.fc30.x86_64 #1 SMP Sun Jun 9 17:09:32 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

All dnf install -y freeipa-server rpms info:

https://paste.fedoraproject.org/paste/xSe7skiXMKr3t4pGJzyCjg

Full /var/log/ipaserver-install.log was uploaded to fpaste :

https://paste.fedoraproject.org/paste/RLlvXEPg~XfYTVYDAg-lpw

DEBUG ERROR message in /var/log/ipaserver-install.log :

2019-06-17T08:49:28Z DEBUG Starting external process
2019-06-17T08:49:28Z DEBUG args=['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpp98at9s2']
2019-06-17T08:50:33Z DEBUG Process finished, return code=1
2019-06-17T08:50:33Z DEBUG stdout=Log file: /var/log/pki/pki-ca-spawn.20190617164929.log
Loading deployment configuration from /tmp/tmpp98at9s2.
WARNING: The 'pki_ssl_server_token' in [CA] has been deprecated. Use 'pki_sslserver_token' 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
2019-06-17T08:50:33Z DEBUG stderr=pkihelper     : ERROR    Server did not start after 60s
configuration : ERROR    Server failed to restart
pkispawn      : ERROR    Exception: server failed to restart
  File "/usr/lib/python3.7/site-packages/pki/server/pkispawn.py", line 547, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 670, in spawn
    raise Exception("server failed to restart")
2019-06-17T08:50:33Z CRITICAL Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpp98at9s2'] returned non-zero exit status 1: 'pkihelper     : ERROR    Server did not start after 60s\nconfiguration : ERROR    Server failed to restart\npkispawn      : ERROR    Exception: server failed to restart\n  File "/usr/lib/python3.7/site-packages/pki/server/pkispawn.py", line 547, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 670, in spawn\n    raise Exception("server failed to restart")\n\n')
2019-06-17T08:50:33Z CRITICAL See the installation logs and the following files/directories for more information:
2019-06-17T08:50:33Z CRITICAL   /var/log/pki/pki-tomcat
2019-06-17T08:50:34Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/ipaserver/install/dogtaginstance.py", line 178, in spawn_instance
    ipautil.run(args, nolog=nolog_list)
  File "/usr/lib/python3.7/site-packages/ipapython/ipautil.py", line 580, in run
    p.returncode, arg_string, output_log, error_log
ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpp98at9s2'] returned non-zero exit status 1: 'pkihelper     : ERROR    Server did not start after 60s\nconfiguration : ERROR    Server failed to restart\npkispawn      : ERROR    Exception: server failed to restart\n  File "/usr/lib/python3.7/site-packages/pki/server/pkispawn.py", line 547, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 670, in spawn\n    raise Exception("server failed to restart")\n\n')
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 595, in __spawn_instance
    nolog_list=nolog_list
  File "/usr/lib/python3.7/site-packages/ipaserver/install/dogtaginstance.py", line 180, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/dogtaginstance.py", line 437, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)
RuntimeError: CA configuration failed.
2019-06-17T08:50:34Z DEBUG   [error] RuntimeError: CA configuration failed.
2019-06-17T08:50:34Z DEBUG Removing /root/.dogtag/pki-tomcat/ca
2019-06-17T08:50:34Z DEBUG   File "/usr/lib/python3.7/site-packages/ipapython/admintool.py", line 179, in execute
    return_value = self.run()
  File "/usr/lib/python3.7/site-packages/ipapython/install/cli.py", line 347, in run
    return cfgr.run()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 360, in run
    return self.execute()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 386, in execute
    for rval in self._executor():
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 655, in _configure
    next(executor)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 518, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 515, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.7/site-packages/ipapython/install/common.py", line 65, in _install
    for unused in self._installer(self.parent):
  File "/usr/lib/python3.7/site-packages/ipaserver/install/server/__init__.py", line 557, in main
    master_install(self)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/server/install.py", line 254, in decorated
    func(installer)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/server/install.py", line 855, in install
    ca.install_step_0(False, None, options, custodia=custodia)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/ca.py", line 356, in install_step_0
    pki_config_override=options.pki_config_override,
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 480, in configure_instance
    self.start_creation(runtime=runtime)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 595, in __spawn_instance
    nolog_list=nolog_list
  File "/usr/lib/python3.7/site-packages/ipaserver/install/dogtaginstance.py", line 180, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/dogtaginstance.py", line 437, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)
2019-06-17T08:50:34Z DEBUG The ipa-server-install command failed, exception: RuntimeError: CA configuration failed.
2019-06-17T08:50:34Z ERROR CA configuration failed.
2019-06-17T08:50:34Z ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

The logs in /var/log/pki are more relevant for this error, /var/log/pki/pki-ca-spawn.20190617164929.log in particular.

Do you have at least 2GB RAM in this VM?

@rcritten After I increase VM's RAM, ipa-server-install failed at :

Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
  [1/30]: configuring certificate server instance
  [2/30]: Add ipa-pki-wait-running
  [3/30]: reindex attributes
  [4/30]: exporting Dogtag certificate store pin
  [5/30]: stopping certificate server instance to update CS.cfg
  [6/30]: backing up CS.cfg
  [7/30]: disabling nonces
  [8/30]: set up CRL publishing
  [9/30]: enable PKIX certificate path discovery and validation
  [10/30]: starting certificate server instance
  [11/30]: configure certmonger for renewals
  [12/30]: requesting RA certificate from CA
  [13/30]: setting audit signing renewal to 2 years
  [14/30]: restarting certificate server
  [error] CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'restart', 'pki-tomcatd@pki-tomcat.service'] returned non-zero exit status 1: 'Job for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\n')
CalledProcessError(Command ['/bin/systemctl', 'restart', 'pki-tomcatd@pki-tomcat.service'] returned non-zero exit status 1: 'Job for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\n')
The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

Current services and listening port :

# netstat -lntpu
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address      Foreign Address     State       PID/Program name
tcp        0      0 0.0.0.0:749        0.0.0.0:*           LISTEN      1673/kadmind
tcp        0      0 0.0.0.0:464        0.0.0.0:*           LISTEN      1673/kadmind
tcp        0      0 0.0.0.0:22         0.0.0.0:*           LISTEN      466/sshd
tcp        0      0 0.0.0.0:88         0.0.0.0:*           LISTEN      1648/krb5kdc
tcp6       0      0 :::636             :::*                LISTEN      1562/ns-slapd
tcp6       0      0 :::389             :::*                LISTEN      1562/ns-slapd
tcp6       0      0 :::749             :::*                LISTEN      1673/kadmind
tcp6       0      0 :::464             :::*                LISTEN      1673/kadmind
tcp6       0      0 :::22              :::*                LISTEN      466/sshd
tcp6       0      0 :::88              :::*                LISTEN      1648/krb5kdc
udp        0      0 127.0.0.1:323      0.0.0.0:*                       1329/chronyd
udp        0      0 0.0.0.0:464        0.0.0.0:*                       1673/kadmind
udp        0      0 0.0.0.0:68         0.0.0.0:*                       650/dhclient
udp        0      0 0.0.0.0:88         0.0.0.0:*                       1648/krb5kdc
udp6       0      0 ::1:323            :::*                            1329/chronyd
udp6       0      0 :::464             :::*                            1673/kadmind
udp6       0      0 :::88              :::*                            1648/krb5kdc

pki-tomcatd@pki-tomcat.service FAILED log message :

# systemctl status pki-tomcatd@pki-tomcat.service                                                                                                                                             
● pki-tomcatd@pki-tomcat.service - PKI Tomcat Server pki-tomcat
   Loaded: loaded (/usr/lib/systemd/system/pki-tomcatd@.service; enabled; vendor preset: disabled)
  Drop-In: /etc/systemd/system/pki-tomcatd@pki-tomcat.service.d
           └─ipa.conf
   Active: failed (Result: timeout) since Tue 2019-06-18 11:55:19 CST; 6min ago
  Process: 3004 ExecStartPre=/usr/sbin/pki-server migrate --instance pki-tomcat (code=exited, status=0/SUCCESS)
  Process: 3026 ExecStartPre=/usr/bin/pkidaemon start pki-tomcat (code=exited, status=0/SUCCESS)
  Process: 3152 ExecStart=/usr/libexec/tomcat/server start (code=exited, status=143)
  Process: 3153 ExecStartPost=/usr/libexec/ipa/ipa-pki-wait-running (code=killed, signal=TERM)
 Main PID: 3152 (code=exited, status=143)
Jun 18 11:55:07 ipa.zerone.os ipa-pki-wait-running[3153]: ipa-pki-wait-running: Connection failed: HTTPConnectionPool(host='ipa.zerone.os', port=8080): Read timed out. (read timeout=1.0)
Jun 18 11:55:09 ipa.zerone.os ipa-pki-wait-running[3153]: ipa-pki-wait-running: Connection failed: HTTPConnectionPool(host='ipa.zerone.os', port=8080): Read timed out. (read timeout=1.0)
Jun 18 11:55:11 ipa.zerone.os ipa-pki-wait-running[3153]: ipa-pki-wait-running: Connection failed: HTTPConnectionPool(host='ipa.zerone.os', port=8080): Read timed out. (read timeout=1.0)
Jun 18 11:55:13 ipa.zerone.os ipa-pki-wait-running[3153]: ipa-pki-wait-running: Connection failed: HTTPConnectionPool(host='ipa.zerone.os', port=8080): Read timed out. (read timeout=1.0)
Jun 18 11:55:15 ipa.zerone.os ipa-pki-wait-running[3153]: ipa-pki-wait-running: Connection failed: HTTPConnectionPool(host='ipa.zerone.os', port=8080): Read timed out. (read timeout=1.0)
Jun 18 11:55:17 ipa.zerone.os ipa-pki-wait-running[3153]: ipa-pki-wait-running: Connection failed: HTTPConnectionPool(host='ipa.zerone.os', port=8080): Read timed out. (read timeout=1.0)
Jun 18 11:55:17 ipa.zerone.os systemd[1]: pki-tomcatd@pki-tomcat.service: Start-post operation timed out. Stopping.
Jun 18 11:55:18 ipa.zerone.os systemd[1]: pki-tomcatd@pki-tomcat.service: Control process exited, code=killed, status=15/TERM
Jun 18 11:55:19 ipa.zerone.os systemd[1]: pki-tomcatd@pki-tomcat.service: Failed with result 'timeout'.
Jun 18 11:55:19 ipa.zerone.os systemd[1]: Failed to start PKI Tomcat Server pki-tomcat.

/var/log/ipaserver-install.log :

https://paste.fedoraproject.org/paste/mpcFrXn2ecU-sUfbwWgjEA

I have created all /var/log/pki/ logs into:

http://142.93.244.157/var-log-pki.tgz

@outman can you post the /var/log/ipaserver-install.log somewhere where it is accessible for a long time please? thanks

@fcami

/var/log/ipaserver-install.log : http://ix.io/1OSk

At the end of pkispawn, the pki-tomcatd server is restarted. Because of the file /etc/systemd/system/pki-tomcatd@pki-tomcat.service.d/ipa.conf, there is an ExecStartPost command launching /usr/libexec/ipa/ipa-pki-wait-running. This python script is opening a http connection to the url http://hostname:8080/ca/admin/ca/getStatus to check that the CA subsystem is ready.
Apparently the script fails on timeout.

In the localhost_access_log.2019-06-18.txt file we don't see trace of this connection attempt around the time displayed in systemctl status pki-tomcatd@pki-tomcat (from Jun 18 11:55:07 to Jun 18 11:55:17). I would check that the name resolves properly, the port is open, etc...

Is this still an issue for you?

Metadata Update from @rcritten:
- Issue close_status updated to: insufficientinfo
- Issue status updated to: Closed (was: Open)
Metadata
None
None
None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.