#5129 pkispawn fails when creating 4.2 replica from 3.0 server
Closed: Fixed None Opened 8 years ago by dkupka.

  1. install freeipa-3.0 server

    ipa-server-install -a Password -p Password --realm domainname -d | tr [:lower:] [:upper:] -U

  2. copy copy-schema-to-ca.py from freeipa-4.2 server

    scp replica.domainname -d:/usr/share/ipa/copy-schema-to-ca.py /root/copy-schema-to-ca.py

  3. run copy-schema-to-ca.py

    python /root/copy-schema-to-ca.py

  4. create replica file

    ipa-replica-prepare replica.domainname -d

  5. install freeipa-4.2 replica

    ipa-replica-install replica-info-replica.domainname -d.gpg --setup-ca

Installation fails with:

...
Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes 30 seconds
  [1/17]: creating certificate server user
  [2/17]: configuring certificate server instance
ipa.ipaserver.install.cainstance.CAInstance: CRITICAL Failed to configure CA instance: Command ''/usr/sbin/pkispawn' '-s' 'CA' '-f' '/tmp/tmpHvD_yv'' returned non-zero exit status 1
ipa.ipaserver.install.cainstance.CAInstance: CRITICAL See the installation logs and the following files/directories for more information:
ipa.ipaserver.install.cainstance.CAInstance: CRITICAL   /var/log/pki-ca-install.log
ipa.ipaserver.install.cainstance.CAInstance: CRITICAL   /var/log/pki/pki-tomcat
  [error] RuntimeError: CA configuration failed.
Your system may be partly configured.
Run /usr/sbin/ipa-server-install --uninstall to clean up.

ipa.ipapython.install.cli.install_tool(Replica): ERROR    CA configuration failed.

pki log files mentioned in the log (/var/log/pki-ca-install.log and /var/log/pki/pki-tomcat) does not exist.

from ipareplica-install.log

...
2015-07-14T11:11:27Z DEBUG Contents of pkispawn configuration file (/tmp/tmpHvD_yv):
[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_client_database_dir = /tmp/tmp-niThP3
pki_client_database_password = XXXXXXXX
pki_client_database_purge = False
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=ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
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=ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
pki_ocsp_signing_subject_dn = cn=OCSP Subsystem,O=ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
pki_ssl_server_subject_dn = cn=vm-047.abc.idm.lab.eng.brq.redhat.com,O=ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
pki_audit_signing_subject_dn = cn=CA Audit,O=ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
pki_ca_signing_subject_dn = cn=Certificate Authority,O=ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
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_security_domain_hostname = vm-042.abc.idm.lab.eng.brq.redhat.com
pki_security_domain_https_port = 443
pki_security_domain_user = admin
pki_security_domain_password = XXXXXXXX
pki_clone = True
pki_clone_pkcs12_path = /tmp/ca.p12
pki_clone_pkcs12_password = XXXXXXXX
pki_clone_replication_security = TLS
pki_clone_replication_master_port = 7389
pki_clone_replication_clone_port = 389
pki_clone_replicate_schema = False
pki_clone_uri = https://vm-042.abc.idm.lab.eng.brq.redhat.com:443


2015-07-14T11:11:27Z DEBUG Starting external process
2015-07-14T11:11:27Z DEBUG args='/usr/sbin/pkispawn' '-s' 'CA' '-f' '/tmp/tmpHvD_yv'
2015-07-14T11:11:28Z DEBUG Process finished, return code=1
2015-07-14T11:11:28Z DEBUG stdout=Log file: /var/log/pki/pki-ca-spawn.20150714131127.log
Loading deployment configuration from /tmp/tmpHvD_yv.

2015-07-14T11:11:28Z DEBUG stderr=/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py:768: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.org/en/latest/security.html
  InsecureRequestWarning)
/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py:768: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.org/en/latest/security.html  
  InsecureRequestWarning)
/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py:768: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.org/en/latest/security.html  
  InsecureRequestWarning)
Traceback (most recent call last):
  File "/usr/sbin/pkispawn", line 676, in <module>
    main(sys.argv)
  File "/usr/sbin/pkispawn", line 570, in main
    parser.sd_authenticate()
  File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkiparser.py", line 488, in sd_authenticate
    account.login()
  File "/usr/lib/python2.7/site-packages/pki/__init__.py", line 297, in handler
    clazz = exc.response.json()['ClassName']
  File "/usr/lib/python2.7/site-packages/requests/models.py", line 819, in json
    return json.loads(self.text, **kwargs)
  File "/usr/lib64/python2.7/site-packages/simplejson/__init__.py", line 501, in loads
    return _default_decoder.decode(s)
  File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 370, in decode
    obj, end = self.raw_decode(s)
  File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 393, in raw_decode
    return self.scan_once(s, idx=_w(s, idx).end())
simplejson.scanner.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

2015-07-14T11:11:28Z CRITICAL Failed to configure CA instance: Command ''/usr/sbin/pkispawn' '-s' 'CA' '-f' '/tmp/tmpHvD_yv'' returned non-zero exit status 1
2015-07-14T11:11:28Z CRITICAL See the installation logs and the following files/directories for more information:
2015-07-14T11:11:28Z CRITICAL   /var/log/pki-ca-install.log
2015-07-14T11:11:28Z CRITICAL   /var/log/pki/pki-tomcat
2015-07-14T11:11:28Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 416, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 406, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 614, in __spawn_instance
    DogtagInstance.spawn_instance(self, cfg_file)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 179, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 443, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)
RuntimeError: CA configuration failed.

2015-07-14T11:11:28Z DEBUG   [error] RuntimeError: CA configuration failed.
2015-07-14T11:11:28Z DEBUG   File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 171, in execute
    return_value = self.run()
  File "/usr/lib/python2.7/site-packages/ipapython/install/cli.py", line 308, in run
    cfgr.run()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 280, in run
    self.execute()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 302, in execute
    for nothing in self._executor():
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 342, in __runner
    self._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in _handle_exception
    util.raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 332, in __runner
    step()
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 87, in run_generator_with_yield_from
    raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 65, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 523, in _configure
    executor.next()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 342, in __runner
    self._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 420, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in _handle_exception
    util.raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 417, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in _handle_exception
    util.raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 332, in __runner
    step()
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 87, in run_generator_with_yield_from
    raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 65, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python2.7/site-packages/ipapython/install/common.py", line 63, in _install
    for nothing in self._installer(self.parent):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 881, in main
    install(self)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 295, in decorated
    func(installer)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 567, in install
    ca.install(False, config, options)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/ca.py", line 106, in install
    install_step_0(standalone, replica_config, options)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/ca.py", line 129, in install_step_0
    cainstance.install_replica_ca(replica_config, postinstall)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 1526, in install_replica_ca
    subject_base=config.subject_base)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 480, in configure_instance
    self.start_creation(runtime=210)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 416, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 406, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py", line 614, in __spawn_instance
    DogtagInstance.spawn_instance(self, cfg_file)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 179, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dogtaginstance.py", line 443, in handle_setup_error
    raise RuntimeError("%s configuration failed." % self.subsystem)

2015-07-14T11:11:28Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: CA configuration failed.
2015-07-14T11:11:28Z ERROR CA configuration failed.

I have a suspicion that new cert profiles and related schema might cause some troubles.

Hello dkupka,

a bug in Dogtag's exception handler hides the true error. Please edit /usr/lib/python2.7/site-packages/pki/init.py, apply this patch manually and try again. With this patch, the script will print the error message and traceback of the error.

You can probably reproduce the error faster than me. I suspect it's an authentication error. Maybe a wrong password?

--- a/base/common/python/pki/__init__.py
+++ b/base/common/python/pki/__init__.py
@@ -294,6 +294,8 @@ def handle_exceptions():
             try:
                 return fn_call(inst, *args, **kwargs)
             except requests.exceptions.HTTPError as exc:
+                print exc
+                import traceback; traceback.print_exc()
                 clazz = exc.response.json()['ClassName']
                 if clazz in EXCEPTION_MAPPINGS:
                     exception_class = EXCEPTION_MAPPINGS[clazz]

Now I can see this exception:

Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/pki/__init__.py", line 295, in handler
    return fn_call(inst, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/pki/account.py", line 55, in login
    self.connection.get('/rest/account/login')
  File "/usr/lib/python2.7/site-packages/pki/client.py", line 116, in get
    r.raise_for_status()
  File "/usr/lib/python2.7/site-packages/requests/models.py", line 834, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
HTTPError: 404 Client Error: Not Found

And in httpd/access_log on master:

<replica IP> - - [16/Jul/2015:08:59:01 +0200] "GET /ca/rest/securityDomain/domainInfo HTTP/1.1" 404 -
<replica IP> - - [16/Jul/2015:08:59:01 +0200] "GET /ca/admin/ca/getDomainXML HTTP/1.1" 200 1168
<replica IP> - - [16/Jul/2015:08:59:01 +0200] "GET /ca/rest/account/login HTTP/1.1" 404 -

It seems that pkispawn tries to use REST API and fails. Replacing /etc/httpd/conf.d/ipa-pki-proxy.conf on master with one from git does not help.

My ipa-pki-proxy.conf has this block with a match for /ca/rest/account/login:

# matches for admin port and installer
<LocationMatch "^/ca/admin/ca/getCertChain|^/ca/admin/ca/getConfigEntries|^/ca/admin/ca/getCookie|^/ca/admin/ca/getStatus|^/ca/admin/ca/securityDomainLogin|^/ca/admin/ca/getDomainXML|^/ca/rest/installer/installToken|^/ca/admin/ca/updateNumberRange|^/ca/rest/securityDomain/domainInfo|^/ca/rest/account/login|^/ca/admin/ca/tokenAuthenticate|^/ca/admin/ca/updateNumberRange|^/ca/admin/ca/updateDomainXML|^/ca/rest/account/logout|^/ca/rest/securityDomain/installToken">
    NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
    NSSVerifyClient none
    ProxyPassMatch ajp://localhost:8009
    ProxyPassReverse ajp://localhost:8009
</LocationMatch>

Are you able to access the route with wget? You should see a 401 Unauthorized:

    $ wget https://your.hostname.tld:8443/ca/rest/account/login

Mine looks like this:

# VERSION 3 - DO NOT REMOVE THIS LINE

ProxyRequests Off

# matches for ee port
<LocationMatch "^/ca/ee/ca/checkRequest|^/ca/ee/ca/getCertChain|^/ca/ee/ca/getTokenInfo|^/ca/ee/ca/tokenAuthenticate|^/ca/ocsp|^/ca/ee/ca/updateNumberRange|^/ca/ee/ca/getCRL|^/ca/ee/ca/profileSubmit">
    NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
    NSSVerifyClient none
    ProxyPassMatch ajp://localhost:9447
    ProxyPassReverse ajp://localhost:9447
</LocationMatch>

# matches for admin port and installer
<LocationMatch "^/ca/admin/ca/getCertChain|^/ca/admin/ca/getConfigEntries|^/ca/admin/ca/getCookie|^/ca/admin/ca/getStatus|^/ca/admin/ca/securityDomainLogin|^/ca/admin/ca/getDomainXML|^/ca/rest/installer/installToken">
    NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
    NSSVerifyClient none
    ProxyPassMatch ajp://localhost:9447
    ProxyPassReverse ajp://localhost:9447
</LocationMatch>

# matches for agent port and eeca port
<LocationMatch "^/ca/agent/ca/displayBySerial|^/ca/agent/ca/doRevoke|^/ca/agent/ca/doUnrevoke|^/ca/agent/ca/updateDomainXML|^/ca/eeca/ca/profileSubmitSSLClient">
    NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
    NSSVerifyClient require
    ProxyPassMatch ajp://localhost:9447
    ProxyPassReverse ajp://localhost:9447
</LocationMatch>

# matches for CA REST API
<LocationMatch "^/ca/rest/account/login|^/ca/rest/account/logout|^/ca/rest/installer/installToken|^/ca/rest/securityDomain/domainInfo|^/ca/rest/securityDomain/installToken|^/ca/rest/profiles|^/ca/rest/admin/kraconnector/remove">
    NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
    NSSVerifyClient optional
    ProxyPassMatch ajp://localhost:9447
    ProxyPassReverse ajp://localhost:9447
</LocationMatch>

# matches for KRA REST API
<LocationMatch "^/kra/rest/config/cert/transport|^/kra/rest/account|^/kra/rest/agent/keyrequests|^/kra/rest/agent/keys">
    NSSOptions +StdEnvVars +ExportCertData +StrictRequire +OptRenegotiate
    NSSVerifyClient optional
    ProxyPassMatch ajp://localhost:9447
    ProxyPassReverse ajp://localhost:9447
</LocationMatch>

I added rules for "matches for KRA REST API" and "matches for CA REST API" manually from git template.

$ wget https://master.`domainname -d`:8443/ca/rest/account/login
--2015-07-16 14:41:43--  https://<master-fqdn>:8443/ca/rest/account/login
Resolving <master-fqdn> (<master-fqdn>)... <master-ip>
Connecting to <master-fqdn> (<master-fqdn>)|<master-ip>|:8443... failed: Connection refused.

Ade Lee and analyzed the bug. My patch for PKI bug 1488 will solve the issue. pkispawn will still try to log in to /ca/rest/account/login. With my patch the 404 error is raised properly and is catched and only logged by pkispawn.

I'm going to try the last version of https://git.fedorahosted.org/cgit/pki.git/plain/base/common/python/pki/__init__.py on the replica machine.

Christian's fix addressed the issue within the python code. This allowed the installation to move forward.
The installation then got stuck in a similar situation in the Java code.

A Dogtag ticket has been created to address this:
https://fedorahosted.org/pki/ticket/1495

I tested a fix on the replica, (added a new cms.jar file) and was able to complete the CA part of the replica install. Now its stuck on kerberos install.

Both Dogtag fixes will be checked into the 10.2.6 build.

The KDC issue is caused by an ABI mismatch. You have to rebuild the RHEL packages against krb5 1.13 to fix the problem.

In my opinion the bug is fixed. I'll close this ticket as soon as Dogtag 10.2.6 is released and I can bump the requirements to 10.2.6.

master:

  • 4e18a62 Require Dogtag PKI >= 10.2.6

ipa-4-2:

  • b01dc89 Require Dogtag PKI >= 10.2.6

Metadata Update from @dkupka:
- Issue assigned to cheimes
- Issue set to the milestone: FreeIPA 4.2.1

7 years ago

Login to comment on this ticket.

Metadata