Bug 1878616 - Running ipa-server-install fails in step [1/30]: configuring certificate server instance
Summary: Running ipa-server-install fails in step [1/30]: configuring certificate serv...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: pki-core
Version: 33
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Matthew Harmsen
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: openqa RejectedBlocker
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-09-14 07:36 UTC by Jan Pazdziora (Red Hat)
Modified: 2020-09-25 17:01 UTC (History)
23 users (show)

Fixed In Version: pki-core-10.9.4-3.fc33
Clone Of:
Environment:
Last Closed: 2020-09-25 17:01:39 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Fedora Pagure dogtagpki issue 3210 0 None None None 2020-09-14 09:16:59 UTC
Fedora Pagure freeipa issue 8495 0 None None None 2020-09-14 09:16:59 UTC

Description Jan Pazdziora (Red Hat) 2020-09-14 07:36:10 UTC
Description of problem:

Running ipa-server-install fails in step

  [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/tmpkz6bibam'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nJob for pki-tomcatd failed because the control process exited with error code.\nSee "systemctl status pki-tomcatd" and "journalctl -xe" for details.\nERROR: CalledProcessError: Command \'[\'systemctl\', \'start\', \'pki-tomcatd\']\' returned non-zero exit status 1.\n  File "/usr/lib/python3.9/site-packages/pki/server/pkispawn.py", line 575, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.9/site-packages/pki/server/deployment/scriptlets/configuration.py", line 900, in spawn\n    instance.start()\n  File "/usr/lib/python3.9/site-packages/pki/server/__init__.py", line 261, in start\n    subprocess.check_call(cmd)\n  File "/usr/lib64/python3.9/subprocess.py", line 373, in check_call\n    raise CalledProcessError(retcode, cmd)\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

Version-Release number of selected component (if applicable):

freeipa-server-4.8.9-2.fc34.x86_64
pki-server-10.9.4-1.fc34.noarch

How reproducible:

Deterministic.

Steps to Reproduce:
1. ipa-server-install -U -r EXAMPLE.TEST -n example.test -p Secret123 -a Secret123

Actual results:

  [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/30]: configuring certificate server instance
Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpkz6bibam'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nJob for pki-tomcatd failed because the control process exited with error code.\nSee "systemctl status pki-tomcatd" and "journalctl -xe" for details.\nERROR: CalledProcessError: Command \'[\'systemctl\', \'start\', \'pki-tomcatd\']\' returned non-zero exit status 1.\n  File "/usr/lib/python3.9/site-packages/pki/server/pkispawn.py", line 575, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.9/site-packages/pki/server/deployment/scriptlets/configuration.py", line 900, in spawn\n    instance.start()\n  File "/usr/lib/python3.9/site-packages/pki/server/__init__.py", line 261, in start\n    subprocess.check_call(cmd)\n  File "/usr/lib64/python3.9/subprocess.py", line 373, in check_call\n    raise CalledProcessError(retcode, cmd)\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

Expected results:

No error.

Additional info:

The /var/log/ipaserver-install.log end with

2020-09-14T11:18:00Z DEBUG Starting external process
2020-09-14T11:18:00Z DEBUG args=['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpkz6bibam']
2020-09-14T11:18:46Z DEBUG Process finished, return code=1
2020-09-14T11:18:46Z DEBUG stdout=Loading deployment configuration from /tmp/tmpkz6bibam.
WARNING: The 'pki_ssl_server_token' in [CA] has been deprecated. Use 'pki_sslserver_token' instead.
Installation log: /var/log/pki/pki-ca-spawn.20200914071801.log
Installing CA into /var/lib/pki/pki-tomcat.

Installation failed: Command failed: systemctl start pki-tomcatd

Please check pkispawn logs in /var/log/pki/pki-ca-spawn.20200914071801.log

2020-09-14T11:18:46Z DEBUG stderr=Notice: Trust flag u is set automatically if the private key is present.
Job for pki-tomcatd failed because the control process exited with error code.
See "systemctl status pki-tomcatd" and "journalctl -xe" for details.
ERROR: CalledProcessError: Command '['systemctl', 'start', 'pki-tomcatd']' returned non-zero exit status 1.
  File "/usr/lib/python3.9/site-packages/pki/server/pkispawn.py", line 575, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.9/site-packages/pki/server/deployment/scriptlets/configuration.py", line 900, in spawn
    instance.start()
  File "/usr/lib/python3.9/site-packages/pki/server/__init__.py", line 261, in start
    subprocess.check_call(cmd)
  File "/usr/lib64/python3.9/subprocess.py", line 373, in check_call
    raise CalledProcessError(retcode, cmd)


2020-09-14T11:18:46Z CRITICAL Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpkz6bibam'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nJob for pki-tomcatd failed because the control process exited with error code.\nSee "systemctl status pki-tomcatd" and "journalctl -xe" for details.\nERROR: CalledProcessError: Command \'[\'systemctl\', \'start\', \'pki-tomcatd\']\' returned non-zero exit status 1.\n  File "/usr/lib/python3.9/site-packages/pki/server/pkispawn.py", line 575, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.9/site-packages/pki/server/deployment/scriptlets/configuration.py", line 900, in spawn\n    instance.start()\n  File "/usr/lib/python3.9/site-packages/pki/server/__init__.py", line 261, in start\n    subprocess.check_call(cmd)\n  File "/usr/lib64/python3.9/subprocess.py", line 373, in check_call\n    raise CalledProcessError(retcode, cmd)\n\n')
2020-09-14T11:18:46Z CRITICAL See the installation logs and the following files/directories for more information:
2020-09-14T11:18:46Z CRITICAL   /var/log/pki/pki-tomcat
2020-09-14T11:18:46Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/ipaserver/install/dogtaginstance.py", line 194, in spawn_instance
    ipautil.run(args, nolog=nolog_list)
  File "/usr/lib/python3.9/site-packages/ipapython/ipautil.py", line 597, in run
    raise CalledProcessError(
ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpkz6bibam'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nJob for pki-tomcatd failed because the control process exited with error code.\nSee "systemctl status pki-tomcatd" and "journalctl -xe" for details.\nERROR: CalledProcessError: Command \'[\'systemctl\', \'start\', \'pki-tomcatd\']\' returned non-zero exit status 1.\n  File "/usr/lib/python3.9/site-packages/pki/server/pkispawn.py", line 575, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.9/site-packages/pki/server/deployment/scriptlets/configuration.py", line 900, in spawn\n    instance.start()\n  File "/usr/lib/python3.9/site-packages/pki/server/__init__.py", line 261, in start\n    subprocess.check_call(cmd)\n  File "/usr/lib64/python3.9/subprocess.py", line 373, in check_call\n    raise CalledProcessError(retcode, cmd)\n\n')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.9/site-packages/ipaserver/install/cainstance.py", line 603, in __spawn_instance
    DogtagInstance.spawn_instance(
  File "/usr/lib/python3.9/site-packages/ipaserver/install/dogtaginstance.py", line 196, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/dogtaginstance.py", line 519, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)
RuntimeError: CA configuration failed.

2020-09-14T11:18:46Z DEBUG   [error] RuntimeError: CA configuration failed.
2020-09-14T11:18:46Z DEBUG Removing /root/.dogtag/pki-tomcat/ca
2020-09-14T11:18:46Z DEBUG   File "/usr/lib/python3.9/site-packages/ipapython/admintool.py", line 180, in execute
    return_value = self.run()
  File "/usr/lib/python3.9/site-packages/ipapython/install/cli.py", line 340, in run
    return cfgr.run()
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 360, in run
    return self.execute()
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 386, in execute
    for rval in self._executor():
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.9/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.9/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.9/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.9/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 655, in _configure
    next(executor)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 518, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.9/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 515, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.9/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.9/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.9/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.9/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.9/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.9/site-packages/ipapython/install/common.py", line 65, in _install
    for unused in self._installer(self.parent):
  File "/usr/lib/python3.9/site-packages/ipaserver/install/server/__init__.py", line 569, in main
    master_install(self)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/server/install.py", line 272, in decorated
    func(installer)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/server/install.py", line 890, in install
    ca.install_step_0(False, None, options, custodia=custodia)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/ca.py", line 338, in install_step_0
    ca.configure_instance(
  File "/usr/lib/python3.9/site-packages/ipaserver/install/cainstance.py", line 482, in configure_instance
    self.start_creation(runtime=runtime)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.9/site-packages/ipaserver/install/cainstance.py", line 603, in __spawn_instance
    DogtagInstance.spawn_instance(
  File "/usr/lib/python3.9/site-packages/ipaserver/install/dogtaginstance.py", line 196, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/dogtaginstance.py", line 519, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)

2020-09-14T11:18:46Z DEBUG The ipa-server-install command failed, exception: RuntimeError: CA configuration failed.
2020-09-14T11:18:46Z ERROR CA configuration failed.
2020-09-14T11:18:46Z ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

Journal shows

Sep 14 07:18:44 master.example.com systemd[1]: Created slice system-pki\x2dtomcatd.slice.
Sep 14 07:18:44 master.example.com systemd[1]: Starting PKI Tomcat Server pki-tomcat...
Sep 14 07:18:45 master.example.com pki-server[14133]: NoClassDefFoundError: javax/xml/bind/JAXBContext
Sep 14 07:18:45 master.example.com pki-server[14104]: ERROR: Command: pki -d /etc/pki/pki-tomcat/alias -C /tmp/tmpy8qfojtg/
password.txt nss-cert-export --with-chain --format PEM Server-Cert cert-pki-ca /etc/pki/pki-tomcat/alias/ca.crt
Sep 14 07:18:45 master.example.com systemd[1]: pki-tomcatd: Control process exited, code=exited, status=
255/EXCEPTION
Sep 14 07:18:45 master.example.com systemd[1]: pki-tomcatd: Failed with result 'exit-code'.
Sep 14 07:18:45 master.example.com systemd[1]: Failed to start PKI Tomcat Server pki-tomcat.
Sep 14 07:18:45 master.example.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_
r:init_t:s0 msg='unit=pki-tomcatd@pki-tomcat comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Sep 14 07:18:45 master.example.com systemd[1]: pki-tomcatd: Consumed 1.575s CPU time.

Comment 2 Jan Pazdziora (Red Hat) 2020-09-14 07:40:13 UTC
When comparing previously passing FreeIPA installation on rawhide, the freeipa-server-4.8.9-2.fc33.x86_64 is the same on both.

On the other hand, for example the pki-server version has changed from pki-server-10.9.2-3.fc33.noarch to pki-server-10.9.4-1.fc34.

Comment 3 Alexander Bokovoy 2020-09-14 07:43:05 UTC
Moving to dogtag for an initial investigation.

Comment 4 Alexander Bokovoy 2020-09-14 07:46:08 UTC
I think this was already happening:

Sep 14 07:18:45 qe-blade-14.idmqe.lab.eng.bos.redhat.com pki-server[14133]: NoClassDefFoundError: javax/xml/bind/JAXBContext

Comment 5 Alexander Bokovoy 2020-09-14 09:16:35 UTC
This issue also reproduced in FreeIPA upstream nightly tests on Rawhide:
https://pagure.io/freeipa/issue/8495 and https://pagure.io/dogtagpki/issue/3210

Comment 7 Adam Williamson 2020-09-14 19:56:24 UTC
yeah, tests started failing in openQA between Fedora-Rawhide-20200911.n.0 and Fedora-Rawhide-20200913.n.0 too. Here's one failure: https://openqa.fedoraproject.org/tests/663987

Comment 9 Adam Williamson 2020-09-14 20:02:43 UTC
As well as pki-core going from 10.9.2-3 to 10.9.4-1, jss went from 4.7.2-1 to 4.7.3-1.

Comment 10 Adam Williamson 2020-09-14 20:03:25 UTC
pki-ca appears to be not owned by anyone, so moving to pki-core.

Comment 12 Fedora Update System 2020-09-18 14:08:47 UTC
FEDORA-2020-8badd13df4 has been submitted as an update to Fedora 33. https://bodhi.fedoraproject.org/updates/FEDORA-2020-8badd13df4

Comment 13 Fedora Blocker Bugs Application 2020-09-18 14:57:07 UTC
Proposed as a Blocker for 33-beta by Fedora user abbra using the blocker tracking app because:

 PKI violates Fedora server release requirement:

FreeIPA server requirements
It must be possible to configure a Fedora Server system installed according to the above criteria as a FreeIPA domain controller, using the official deployment tools provided in the distribution FreeIPA packages. Once deployed, the system must handle multiple client enrolments and unenrolments, and client authentication via Kerberos. The web UI must be available and allow at least basic configuration of user accounts and permissions. Prior to Beta, it is acceptable if moderate workarounds are necessary to allow the above.

Since there is no workaround to broken PKI with JDK 11, we have to accept a build that fixes the issue.

Comment 14 Adam Williamson 2020-09-18 17:45:24 UTC
This isn't broken in F33. pki-core 10.9.4-1 and jss 4.7.3-1 never went into F33. There's no need for it to be a Beta blocker.

The replica test is failing on F33 composes currently, but that's fallout from the systemd-resolved stuff, I think. Other FreeIPA tests are passing.

Comment 15 Fedora Update System 2020-09-18 19:00:53 UTC
FEDORA-2020-8badd13df4 has been pushed to the Fedora 33 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-8badd13df4`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-8badd13df4

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 16 Alexander Bokovoy 2020-09-19 19:27:08 UTC
I verified with pki-core 10.9.2-3.fc33, the installation, indeed works.

Comment 17 Kamil Páral 2020-09-21 13:09:33 UTC
Rejected as a Beta blocker:
https://pagure.io/fedora-qa/blocker-review/issue/102

Comment 18 Fedora Update System 2020-09-25 17:01:39 UTC
FEDORA-2020-8badd13df4 has been pushed to the Fedora 33 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.