#9601 Replication fails in KRA stage when upgrading cluster from Fedora 39 to Fedora 40
Closed: duplicate by abbra. Opened by jsf9k.

Issue

I have a three-member FreeIPA cluster in AWS that I attempted to upgrade from Fedora 39 to Fedora 40. I built a new AMI based on Fedora 40, removed two of the servers from the cluster, then replaced one of the removed servers with the new AMI. When I ran ipa-install-replica on the new Fedora 40 server it failed at the KRA stage with this output in /var/log/ipareplica-install.log:

DEBUG: NSSDatabase.get_cert_info(Server-Cert cert-pki-ca) ends
INFO: Updating /etc/pki/pki-tomcat/serverCertNick.conf
INFO: Updating serverCertNickFile in server.xml
INFO: Joining security domain at https://ipa0.staging.cool.cyber.dhs.gov:443
INFO: Searching for ipa0.staging.cool.cyber.dhs.gov:443
INFO: - ipa2.staging.cool.cyber.dhs.gov:443
INFO: - ipa0.staging.cool.cyber.dhs.gov:443
INFO: Getting install token
DEBUG: https://ipa0.staging.cool.cyber.dhs.gov:443 "GET /ca/rest/securityDomain/installToken?hostname=ipa0.staging.cool.cyber.dhs.gov&subsystem=KRA HTTP/1.1" 200 51
DEBUG: Response:
{
    "token": "2654056564209680742"
}
INFO: Storing subsystem config: /etc/pki/pki-tomcat/kra/CS.cfg
INFO: Storing registry config: /etc/pki/pki-tomcat/kra/registry.cfg
INFO: Retrieving config params from KRA master
DEBUG: Command: pki -d /etc/pki/pki-tomcat/alias -f /etc/pki/pki-tomcat/password.conf -U https://ipa2.staging.cool.cyber.dhs.gov:443 --ignore-banner kra-config-export --names internaldb.ldapauth.password,internaldb.replication.password,kra.transport.certreq,kra.storage.certreq,kra.subsystem.certreq,kra.audit_signing.certreq,cloning.ca.type --substores internaldb,internaldb.ldapauth,internaldb.ldapconn --install-token /tmp/tmp0jpyox9u/install-token --output-format json --debug
INFO: Connecting to https://ipa2.staging.cool.cyber.dhs.gov:443
INFO: HTTP request: GET /pki/v2/info HTTP/1.1
FINE: - Authorization: ********
FINE: - Host: ipa2.staging.cool.cyber.dhs.gov:443
FINE: - Connection: Keep-Alive
FINE: - User-Agent: Apache-HttpClient/4.5.14 (Java/21.0.3)
FINE: Request:
INFO: Server certificate: CN=ipa2.staging.cool.cyber.dhs.gov,O=STAGING.COOL.CYBER.DHS.GOV
INFO: HTTP response: HTTP/1.1 404 Not Found
FINE: - Date: Sun, 02 Jun 2024 02:29:09 GMT
FINE: - Server: Apache/2.4.59 (Fedora Linux) OpenSSL/3.1.1 mod_wsgi/4.9.4 Python/3.12 mod_auth_gssapi/1.6.5
FINE: - Strict-Transport-Security: max-age=31536000; includeSubdomains; preload
FINE: - Content-Length: 196
FINE: - Keep-Alive: timeout=30, max=100
FINE: - Connection: Keep-Alive
FINE: - Content-Type: text/html; charset=iso-8859-1
FINE: Response:
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>404 Not Found</title>
</head><body>
<h1>Not Found</h1>
<p>The requested URL was not found on this server.</p>
</body></html>
WARNING: Unable to get server info: Not Found
INFO: Getting configuration properties
INFO: HTTP request: POST /kra/admin/kra/getConfigEntries HTTP/1.1
FINE: - Authorization: ********
FINE: - Content-Type: application/x-www-form-urlencoded
FINE: - Content-Length: 301
FINE: - Host: ipa2.staging.cool.cyber.dhs.gov:443
FINE: - Connection: Keep-Alive
FINE: - User-Agent: Apache-HttpClient/4.5.14 (Java/21.0.3)
FINE: Request:
op=get&names=internaldb.ldapauth.password%2Cinternaldb.replication.password%2Ckra.transport.certreq%2Ckra.storage.certreq%2Ckra.subsystem.certreq%2Ckra.audit_signing.certreq%2Ccloning.ca.type&xmlOutput=true&sessionID=2654056564209680742&substores=internaldb%2Cinternaldb.ldapauth%2Cinternaldb.ldapconn
INFO: HTTP response: HTTP/1.1 200 200
FINE: - Date: Sun, 02 Jun 2024 02:29:09 GMT
FINE: - Server: Apache/2.4.59 (Fedora Linux) OpenSSL/3.1.1 mod_wsgi/4.9.4 Python/3.12 mod_auth_gssapi/1.6.5
FINE: - Strict-Transport-Security: max-age=31536000; includeSubdomains; preload
FINE: - Content-Type: text/html; charset=UTF-8
FINE: - Vary: Accept-Encoding
FINE: - Keep-Alive: timeout=30, max=99
FINE: - Connection: Keep-Alive
FINE: - Transfer-Encoding: chunked
FINE: Response:
<HTML>
<BODY BGCOLOR=white>
<P>
The Certificate System has encountered an unrecoverable error.
<P>
Error Message:<BR>
<I>java.security.AccessControlException: access denied (&quot;java.io.FilePermission&quot; &quot;/var/lib/pki/pki-tomcat/logs/kra&quot; &quot;read&quot;)</I>
<P>
Please contact your local administrator for assistance.
</BODY>
</HTML>
FINE: Response: <HTML>
<BODY BGCOLOR=white>
<P>
The Certificate System has encountered an unrecoverable error.
<P>
Error Message:<BR>
<I>java.security.AccessControlException: access denied (&quot;java.io.FilePermission&quot; &quot;/var/lib/pki/pki-tomcat/logs/kra&quot; &quot;read&quot;)</I>
<P>
Please contact your local administrator for assistance.
</BODY>
</HTML>
[Fatal Error] :2:15: Open quote is expected for attribute "BGCOLOR" associated with an  element type  "BODY".
org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 15; Open quote is expected for attribute "BGCOLOR" associated with an  element type  "BODY".
        at java.xml/com.sun.org.apache.xerces.internal.parsers.DOMParser.parse(DOMParser.java:262)
        at java.xml/com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderImpl.parse(DocumentBuilderImpl.java:342)
        at java.xml/javax.xml.parsers.DocumentBuilder.parse(DocumentBuilder.java:122)
        at com.netscape.cmsutil.xml.XMLObject.<init>(XMLObject.java:64)
        at org.dogtagpki.common.ConfigClient.getConfig(ConfigClient.java:81)
        at com.netscape.cmstools.config.ConfigExportCLI.execute(ConfigExportCLI.java:84)
        at org.dogtagpki.cli.CommandCLI.execute(CommandCLI.java:58)
        at org.dogtagpki.cli.CLI.execute(CLI.java:353)
        at org.dogtagpki.cli.CLI.execute(CLI.java:353)
        at com.netscape.cmstools.cli.SubsystemCLI.execute(SubsystemCLI.java:79)
        at org.dogtagpki.cli.CLI.execute(CLI.java:353)
        at com.netscape.cmstools.cli.MainCLI.execute(MainCLI.java:659)
        at com.netscape.cmstools.cli.MainCLI.main(MainCLI.java:698)
ERROR: CalledProcessError: Command '['pki', '-d', '/etc/pki/pki-tomcat/alias', '-f', '/etc/pki/pki-tomcat/password.conf', '-U', 'https://ipa2.staging.cool.cyber.dhs.gov:443', '--ignore-banner', 'kra-config-export', '--names', 'internaldb.ldapauth.password,internaldb.replication.password,kra.transport.certreq,kra.storage.certreq,kra.subsystem.certreq,kra.audit_signing.certreq,cloning.ca.type', '--substores', 'internaldb,internaldb.ldapauth,internaldb.ldapconn', '--install-token', '/tmp/tmp0jpyox9u/install-token', '--output-format', 'json', '--debug']' returned non-zero exit status 255.
  File "/usr/lib/python3.12/site-packages/pki/server/pkispawn.py", line 568, in main
    deployer.spawn()
  File "/usr/lib/python3.12/site-packages/pki/server/deployment/__init__.py", line 4985, in spawn
    scriptlet.spawn(self)
  File "/usr/lib/python3.12/site-packages/pki/server/deployment/scriptlets/configuration.py", line 113, in spawn
    master_config = deployer.import_master_config(subsystem)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/pki/server/deployment/__init__.py", line 1456, in import_master_config
    master_config = subsystem.retrieve_config(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/pki/server/subsystem.py", line 1577, in retrieve_config
    output = subprocess.check_output(cmd)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib64/python3.12/subprocess.py", line 466, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib64/python3.12/subprocess.py", line 571, in run
    raise CalledProcessError(retcode, process.args,
2024-06-02T02:29:10Z CRITICAL Failed to configure KRA instance
2024-06-02T02:29:10Z CRITICAL See the installation logs and the following files/directories for more information:
2024-06-02T02:29:10Z CRITICAL   /var/log/pki/pki-tomcat
2024-06-02T02:29:10Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.12/site-packages/ipaserver/install/service.py", line 686, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/service.py", line 672, in run_step
    method()
  File "/usr/lib/python3.12/site-packages/ipaserver/install/krainstance.py", line 223, in __spawn_instance
    DogtagInstance.spawn_instance(
  File "/usr/lib/python3.12/site-packages/ipaserver/install/dogtaginstance.py", line 227, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/dogtaginstance.py", line 604, in handle_setup_error
    raise RuntimeError(
RuntimeError: KRA configuration failed.
2024-06-02T02:29:10Z DEBUG   [error] RuntimeError: KRA configuration failed.
2024-06-02T02:29:10Z DEBUG Removing /var/lib/ipa/tmp-kwux5zuz
2024-06-02T02:29:10Z DEBUG Removing /root/.dogtag/pki-tomcat/kra
2024-06-02T02:29:10Z DEBUG   File "/usr/lib/python3.12/site-packages/ipapython/admintool.py", line 180, in execute
    return_value = self.run()
                   ^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/cli.py", line 344, in run
    return cfgr.run()
           ^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 360, in run
    return self.execute()
           ^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 386, in execute
    for rval in self._executor():
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 435, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 468, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 458, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.12/site-packages/six.py", line 719, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 425, in __runner
    step()
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 419, in step_next
    return next(self.__gen)
           ^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.12/site-packages/six.py", line 719, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
            ^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 663, in _configure
    next(executor)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 435, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 468, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 526, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 458, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.12/site-packages/six.py", line 719, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 523, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 458, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.12/site-packages/six.py", line 719, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 425, in __runner
    step()
  File "/usr/lib/python3.12/site-packages/ipapython/install/core.py", line 419, in step_next
    return next(self.__gen)
           ^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.12/site-packages/six.py", line 719, in reraise
    raise value
  File "/usr/lib/python3.12/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
            ^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/ipapython/install/common.py", line 65, in _install
    for unused in self._installer(self.parent):
  File "/usr/lib/python3.12/site-packages/ipaserver/install/server/__init__.py", line 599, in main
    replica_install(self)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/server/replicainstall.py", line 401, in decorated
    func(installer)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/server/replicainstall.py", line 1402, in install
    kra.install(api, config, options, custodia=custodia)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/kra.py", line 100, in install
    kra.configure_instance(
  File "/usr/lib/python3.12/site-packages/ipaserver/install/krainstance.py", line 139, in configure_instance
    self.start_creation(runtime=120)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/service.py", line 686, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/service.py", line 672, in run_step
    method()
  File "/usr/lib/python3.12/site-packages/ipaserver/install/krainstance.py", line 223, in __spawn_instance
    DogtagInstance.spawn_instance(
  File "/usr/lib/python3.12/site-packages/ipaserver/install/dogtaginstance.py", line 227, in spawn_instance
    self.handle_setup_error(e)
  File "/usr/lib/python3.12/site-packages/ipaserver/install/dogtaginstance.py", line 604, in handle_setup_error
    raise RuntimeError(
2024-06-02T02:29:10Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: KRA configuration failed.
2024-06-02T02:29:10Z ERROR KRA configuration failed.
2024-06-02T02:29:10Z ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

Steps to Reproduce

1.
2.
3.

Actual behavior

The setup of a new replica fails at the KRA stage.

Expected behavior

I expect the setup of a new replica to proceed without error, as it has for years.

Version/Release/Distribution

On Fedora 39 (old AMI):

$ rpm -q freeipa-server freeipa-client ipa-server ipa-client 389-ds-base pki-ca krb5-server
freeipa-server-4.11.1-2.fc39.x86_64
freeipa-client-4.11.1-2.fc39.x86_64
package ipa-server is not installed
package ipa-client is not installed
389-ds-base-2.4.5-1.fc39.x86_64
package pki-ca is not installed
krb5-server-1.21.2-3.fc39.x86_64

On Fedora 40 (new AMI):

$ rpm -q freeipa-server freeipa-client ipa-server ipa-client 389-ds-base pki-ca krb5-server
freeipa-server-4.11.1-4.fc40.x86_64
freeipa-client-4.11.1-4.fc40.x86_64
package ipa-server is not installed
package ipa-client is not installed
389-ds-base-3.0.2-1.fc40.x86_64
package pki-ca is not installed
krb5-server-1.21.2-5.fc40.x86_64

Additional info:

Any additional information, configuration, data or log snippets that is needed for reproduction or investigation of the issue.

Log file locations: https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Linux/7/html/Linux_Domain_Identity_Authentication_and_Policy_Guide/config-files-logs.html
Troubleshooting guide: https://www.freeipa.org/page/Troubleshooting


I was able to confirm that creating a replica using the old Fedora 39 AMI works fine, so the problem is definitely related to creating a Fedora 40 replica from a Fedora 39 server.

This looks like a problem within Dogtag PKI, specifically with Java IO access permissions system. We had this reported in a freeipa-container as well and further reproduced on RHEL too: https://issues.redhat.com/browse/RHEL-27610. There is an upstream PKI issue reported by us: https://github.com/dogtagpki/pki/issues/4703

I'd close this one because the fix needs to happen on the PKI side. If you want to track that, please subscribe to their issue.

Metadata Update from @abbra:
- Issue close_status updated to: duplicate
- Issue status updated to: Closed (was: Open)

Metadata