[Pkg-freeipa-devel] Bug#898543: freeipa-server: requesting RA certificate from CA fails with "CA_UNREACHABLE"
Adam Reece
adam at svencoop.com
Sun May 13 11:04:38 BST 2018
Package: freeipa-server
Version: 4.6.3-1
Severity: important
-- System Information:
Debian Release: 9.4
APT prefers stable
APT policy: (700, 'stable'), (650, 'unstable'), (500, 'stable-updates')
Architecture: amd64 (x86_64)
Kernel: Linux 4.9.0-6-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), LANGUAGE=en_GB:en (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages freeipa-server depends on:
ii 389-ds-base 1.3.7.10-1+b1
ii acl 2.2.52-3+b1
ii apache2 2.4.25-3+deb9u4
ii certmonger 0.79.5-2
ii custodia 0.5.0-3
ii fonts-font-awesome 4.7.0~dfsg-3
ii fonts-open-sans 1.11-1
ii freeipa-admintools 4.6.3-1
ii freeipa-client 4.6.3-1
ii freeipa-common 4.6.3-1
ii gssproxy 0.8.0-1
ii krb5-admin-server 1.16-2
ii krb5-kdc 1.16-2
ii krb5-kdc-ldap 1.16-2
ii krb5-otp 1.16-2
ii krb5-pkinit 1.16-2
ii ldap-utils 2.4.46+dfsg-5
ii libapache2-mod-auth-gssapi 1.6.0-1
ii libapache2-mod-lookup-identity 1.0.0-1
ii libapache2-mod-nss 1.0.14-1+b1
ii libapache2-mod-wsgi 4.5.17-1+b1
ii libc6 2.27-3
ii libcomerr2 1.44.1-2
ii libjs-dojo-core 1.11.0+dfsg-1
ii libjs-jquery 3.2.1-1
ii libk5crypto3 1.16-2
ii libkrad0 1.16-2
ii libkrb5-3 1.16-2
ii libldap-2.4-2 2.4.46+dfsg-5
ii libnspr4 2:4.19-1
ii libnss3 2:3.36.1-1
ii libnss3-tools 2:3.36.1-1
ii libsasl2-modules-gssapi-mit 2.1.27~101-g0780600+dfsg-3.1
ii libssl1.1 1.1.0f-3+deb9u2
ii libsss-nss-idmap0 1.16.1-1+b1
ii libtalloc2 2.1.10-2
ii libtevent0 0.9.34-1
ii libunistring2 0.9.8-1
ii libuuid1 2.29.2-1+deb9u1
ii libverto1 0.2.4-2.1
ii ntp 1:4.2.8p11+dfsg-1
ii oddjob 0.34.3-4
ii p11-kit 0.23.10-2
ii pki-ca 10.5.5-1
ii pki-kra 10.5.5-1
ii python 2.7.13-2
ii python-dateutil 2.6.1-1
ii python-gssapi 1.4.1-1
ii python-ipaserver 4.6.3-1
ii python-ldap 3.0.0-1
ii python-systemd 234-2
ii samba-libs 2:4.7.4+dfsg-2
ii slapi-nis 0.56.1-1
ii softhsm2 2.4.0-0.1
ii systemd-sysv 238-4
Versions of packages freeipa-server recommends:
ii freeipa-server-dns 4.6.3-1
freeipa-server suggests no packages.
-- Configuration Files:
/etc/default/ipa-dnskeysyncd changed:
SOFTHSM2_CONF=/etc/ipa/dnssec/softhsm2.conf
-- no debconf information
The server installation process will fail when a certificate is requested from the CA with error CA_UNREACHABLE.
Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
[1/28]: configuring certificate server instance
[2/28]: exporting Dogtag certificate store pin
[3/28]: stopping certificate server instance to update CS.cfg
[4/28]: backing up CS.cfg
[5/28]: disabling nonces
[6/28]: set up CRL publishing
[7/28]: enable PKIX certificate path discovery and validation
[8/28]: starting certificate server instance
[9/28]: configure certmonger for renewals
[10/28]: requesting RA certificate from CA
[error] RuntimeError: Certificate issuance failed (CA_UNREACHABLE)
ipapython.admintool: ERROR Certificate issuance failed (CA_UNREACHABLE)
ipapython.admintool: ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information
This was for the 2nd stage of an external CA setup, but also occurs with the standard self-signed CA option.
Things I've checked:
* DNS: The correct zone exists, and resolves correctly when using `dig` on both the server, and my workstation. (Both the root domain name and "ipa-ca" sub-domain records.)
* /etc/hosts file: The server's FQDN is listed.
* pki-tomcatd service: Definitely running.
* Firewall: Port 8080 and 8443 for tomcat are not blocked. (Disabled CSF+LFD completely and tried again to be sure with empty IPTABLES.)
* The dogtag web UI is accessible on both ports 8080 and 8443.
The installation log for PKI is as follows.
2018-05-13T09:56:23Z DEBUG Starting external process
2018-05-13T09:56:23Z DEBUG args=/usr/sbin/pkispawn -s CA -f /tmp/tmpNZQfmj
2018-05-13T09:57:12Z DEBUG Process finished, return code=0
2018-05-13T09:57:12Z DEBUG stdout=Log file: /var/log/pki/pki-ca-spawn.20180513115623.log
Loading deployment configuration from /tmp/tmpNZQfmj.
WARNING: The 'pki_external_ca_cert_path' in [CA] has been deprecated. Use 'pki_ca_signing_cert_path' instead.
WARNING: The 'pki_external_ca_cert_chain_path' in [CA] has been deprecated. Use 'pki_cert_chain_path' instead.
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.
/tmp/tmpQdpnr5/cert0.crt: <X.509 subject>
Starting pki-tomcatd (via systemctl): pki-tomcatd.service.
Stopping pki-tomcatd (via systemctl): pki-tomcatd.service.
Starting pki-tomcatd (via systemctl): pki-tomcatd.service.
==========================================================================
INSTALLATION SUMMARY
==========================================================================
Administrator's username: admin
Administrator's PKCS #12 file:
/root/ca-agent.p12
To check the status of the subsystem:
systemctl status pki-tomcatd at pki-tomcat.service
To restart the subsystem:
systemctl restart pki-tomcatd at pki-tomcat.service
The URL for the subsystem is:
https://<fqdn>:8443/ca
PKI instances will be enabled upon system boot
==========================================================================
2018-05-13T09:57:12Z DEBUG stderr=pkispawn : ERROR ....... subprocess.CalledProcessError: Command '['sysctl', 'crypto.fips_enabled', '-bn']' returned non-zero exit status 255!
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/usr/share/java/slf4j-simple.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/usr/share/java/slf4j-jdk14.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.SimpleLoggerFactory]
Notice: Trust flag u is set automatically if the private key is present.
pkispawn : ERROR ....... subprocess.CalledProcessError: Command '['sysctl', 'crypto.fips_enabled', '-bn']' returned non-zero exit status 255!
2018-05-13T09:57:12Z DEBUG completed creating ca instance
2018-05-13T09:57:12Z DEBUG duration: 49 seconds
2018-05-13T09:57:12Z DEBUG [2/28]: exporting Dogtag certificate store pin
2018-05-13T09:57:12Z DEBUG Loading Index file from '/var/lib/ipa/sysrestore/sysrestore.index'
2018-05-13T09:57:12Z DEBUG duration: 0 seconds
2018-05-13T09:57:12Z DEBUG [3/28]: stopping certificate server instance to update CS.cfg
2018-05-13T09:57:12Z DEBUG Starting external process
2018-05-13T09:57:12Z DEBUG args=/bin/systemctl stop pki-tomcatd.service
2018-05-13T09:57:12Z DEBUG Process finished, return code=0
2018-05-13T09:57:12Z DEBUG stdout=
2018-05-13T09:57:12Z DEBUG stderr=
2018-05-13T09:57:12Z DEBUG duration: 0 seconds
2018-05-13T09:57:12Z DEBUG [4/28]: backing up CS.cfg
2018-05-13T09:57:12Z DEBUG Starting external process
2018-05-13T09:57:12Z DEBUG args=/bin/systemctl is-active pki-tomcatd.service
2018-05-13T09:57:12Z DEBUG Process finished, return code=3
2018-05-13T09:57:12Z DEBUG stdout=inactive
2018-05-13T09:57:12Z DEBUG stderr=
2018-05-13T09:57:12Z DEBUG duration: 0 seconds
2018-05-13T09:57:12Z DEBUG [5/28]: disabling nonces
2018-05-13T09:57:12Z DEBUG duration: 0 seconds
2018-05-13T09:57:12Z DEBUG [6/28]: set up CRL publishing
2018-05-13T09:57:12Z DEBUG duration: 0 seconds
2018-05-13T09:57:12Z DEBUG [7/28]: enable PKIX certificate path discovery and validation
2018-05-13T09:57:12Z DEBUG duration: 0 seconds
2018-05-13T09:57:12Z DEBUG [8/28]: starting certificate server instance
2018-05-13T09:57:12Z DEBUG Starting external process
2018-05-13T09:57:12Z DEBUG args=/bin/systemctl start pki-tomcatd.service
2018-05-13T09:57:18Z DEBUG Process finished, return code=0
2018-05-13T09:57:18Z DEBUG stdout=
2018-05-13T09:57:18Z DEBUG stderr=
2018-05-13T09:57:18Z DEBUG Starting external process
2018-05-13T09:57:18Z DEBUG args=/bin/systemctl is-active pki-tomcatd.service
2018-05-13T09:57:18Z DEBUG Process finished, return code=0
2018-05-13T09:57:18Z DEBUG stdout=active
2018-05-13T09:57:18Z DEBUG stderr=
2018-05-13T09:57:18Z DEBUG duration: 5 seconds
2018-05-13T09:57:18Z DEBUG [9/28]: configure certmonger for renewals
2018-05-13T09:57:18Z DEBUG Starting external process
2018-05-13T09:57:18Z DEBUG args=/bin/systemctl enable certmonger.service
2018-05-13T09:57:18Z DEBUG Process finished, return code=0
2018-05-13T09:57:18Z DEBUG stdout=
2018-05-13T09:57:18Z DEBUG stderr=Synchronizing state of certmonger.service with SysV service script with /lib/systemd/systemd-sysv-install.
Executing: /lib/systemd/systemd-sysv-install enable certmonger
2018-05-13T09:57:18Z DEBUG Starting external process
2018-05-13T09:57:18Z DEBUG args=/bin/systemctl start certmonger.service
2018-05-13T09:57:18Z DEBUG Process finished, return code=0
2018-05-13T09:57:18Z DEBUG stdout=
2018-05-13T09:57:18Z DEBUG stderr=
2018-05-13T09:57:18Z DEBUG Starting external process
2018-05-13T09:57:18Z DEBUG args=/bin/systemctl is-active certmonger.service
2018-05-13T09:57:18Z DEBUG Process finished, return code=0
2018-05-13T09:57:18Z DEBUG stdout=active
2018-05-13T09:57:18Z DEBUG stderr=
2018-05-13T09:57:18Z DEBUG duration: 0 seconds
2018-05-13T09:57:18Z DEBUG [10/28]: requesting RA certificate from CA
2018-05-13T09:57:18Z DEBUG Starting external process
2018-05-13T09:57:18Z DEBUG args=/usr/bin/openssl pkcs7 -inform DER -print_certs -out /var/lib/ipa/tmpH6mrdU
2018-05-13T09:57:18Z DEBUG Process finished, return code=0
2018-05-13T09:57:18Z DEBUG stdout=
2018-05-13T09:57:18Z DEBUG stderr=
2018-05-13T09:57:18Z DEBUG Starting external process
2018-05-13T09:57:18Z DEBUG args=/usr/bin/openssl pkcs12 -nokeys -clcerts -in /root/ca-agent.p12 -out /var/lib/ipa/tmp3Xwfc_ -passin file:/tmp/tmp_V2wgw
2018-05-13T09:57:20Z DEBUG Process finished, return code=0
2018-05-13T09:57:20Z DEBUG stdout=
2018-05-13T09:57:20Z DEBUG stderr=
2018-05-13T09:57:20Z DEBUG Starting external process
2018-05-13T09:57:20Z DEBUG args=/usr/bin/openssl pkcs12 -nodes -nocerts -in /root/ca-agent.p12 -out /var/lib/ipa/tmpVSadnP -passin file:/tmp/tmpFcGABi
2018-05-13T09:57:21Z DEBUG Process finished, return code=0
2018-05-13T09:57:21Z DEBUG stdout=
2018-05-13T09:57:21Z DEBUG stderr=
2018-05-13T09:57:22Z DEBUG certmonger request is in state dbus.String(u'NEWLY_ADDED_READING_KEYINFO', variant_level=1)
2018-05-13T09:57:27Z DEBUG certmonger request is in state dbus.String(u'CA_UNREACHABLE', variant_level=1)
2018-05-13T09:57:27Z DEBUG Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/ipaserver/install/service.py", line 506, in start_creation
run_step(full_msg, method)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/service.py", line 496, in run_step
method()
File "/usr/lib/python2.7/dist-packages/ipaserver/install/cainstance.py", line 900, in __request_ra_certificate
storage="FILE")
File "/usr/lib/python2.7/dist-packages/ipalib/install/certmonger.py", line 320, in request_and_wait_for_cert
raise RuntimeError("Certificate issuance failed ({})".format(state))
RuntimeError: Certificate issuance failed (CA_UNREACHABLE)
2018-05-13T09:57:27Z DEBUG [error] RuntimeError: Certificate issuance failed (CA_UNREACHABLE)
2018-05-13T09:57:27Z DEBUG File "/usr/lib/python2.7/dist-packages/ipapython/admintool.py", line 174, in execute
return_value = self.run()
File "/usr/lib/python2.7/dist-packages/ipapython/install/cli.py", line 319, in run
cfgr.run()
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 364, in run
self.execute()
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 388, in execute
for _nothing in self._executor():
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 430, in __runner
exc_handler(exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 459, in _handle_execute_exception
self._handle_exception(exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 449, in _handle_exception
six.reraise(*exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 420, in __runner
step()
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 417, in <lambda>
step = lambda: next(self.__gen)
File "/usr/lib/python2.7/dist-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
six.reraise(*exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
value = gen.send(prev_value)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 654, in _configure
next(executor)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 430, in __runner
exc_handler(exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 459, in _handle_execute_exception
self._handle_exception(exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 517, in _handle_exception
self.__parent._handle_exception(exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 449, in _handle_exception
six.reraise(*exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 514, in _handle_exception
super(ComponentBase, self)._handle_exception(exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 449, in _handle_exception
six.reraise(*exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 420, in __runner
step()
File "/usr/lib/python2.7/dist-packages/ipapython/install/core.py", line 417, in <lambda>
step = lambda: next(self.__gen)
File "/usr/lib/python2.7/dist-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
six.reraise(*exc_info)
File "/usr/lib/python2.7/dist-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
value = gen.send(prev_value)
File "/usr/lib/python2.7/dist-packages/ipapython/install/common.py", line 66, in _install
for unused in self._installer(self.parent):
File "/usr/lib/python2.7/dist-packages/ipaserver/install/server/__init__.py", line 583, in main
master_install(self)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/server/install.py", line 250, in decorated
func(installer)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/server/install.py", line 807, in install
ca.install_step_0(False, None, options)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/ca.py", line 308, in install_step_0
use_ldaps=standalone)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/cainstance.py", line 465, in configure_instance
self.start_creation(runtime=runtime)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/service.py", line 506, in start_creation
run_step(full_msg, method)
File "/usr/lib/python2.7/dist-packages/ipaserver/install/service.py", line 496, in run_step
method()
File "/usr/lib/python2.7/dist-packages/ipaserver/install/cainstance.py", line 900, in __request_ra_certificate
storage="FILE")
File "/usr/lib/python2.7/dist-packages/ipalib/install/certmonger.py", line 320, in request_and_wait_for_cert
raise RuntimeError("Certificate issuance failed ({})".format(state))
2018-05-13T09:57:27Z DEBUG The ipa-server-install command failed, exception: RuntimeError: Certificate issuance failed (CA_UNREACHABLE)
2018-05-13T09:57:27Z ERROR Certificate issuance failed (CA_UNREACHABLE)
2018-05-13T09:57:27Z ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information
The only other error I see in that is about "crypto.fips_enabled", but that doesn't appear to block the PKI spawning.
Looking into this further I found on Red Hat and Fedora that they had an issue whereby the cURL used was built against OpenSSL instead of NSS, which could be related. [https://bugzilla.redhat.com/show_bug.cgi?id=1455561]
The output of `curl -V` for this Debian server is:
curl 7.52.1 (x86_64-pc-linux-gnu) libcurl/7.52.1 OpenSSL/1.0.2l zlib/1.2.8 libidn2/0.16 libpsl/0.17.0 (+libidn2/0.16) libssh2/1.7.0
nghttp2/1.18.1 librtmp/2.3
They did however fix this issue for FreeIPA 4.6, but that probably wouldn't include Debian's build.
Please let me know if you require any further information.
More information about the Pkg-freeipa-devel
mailing list