#8476 Nightly test failure in CA/KRA install on replica: java.io.FilePermission
Closed: worksforme 2 years ago by frenaud. Opened 3 years ago by fcami.

testing_master_pki Nightly PR #369 failed at KRA install time:

E           subprocess.CalledProcessError: Command '['ipa-replica-install', '--admin-password', 'Secret.123', '--password', 'Secret.123', '-U', '--setup-ca', '--setup-kra', '--ip-address', '192.168.122.106', '--realm', 'IPA.TEST', '--domain', 'ipa.test']' returned non-zero exit status 1.

Specifically:

DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557   [3/10]: configuring KRA instance
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 Failed to configure KRA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'KRA', '-f', '/tmp/tmpmseufhae'] returned non-zero exit status 1: 'WARNING: Directory already exists: /etc/pki/pki-tomcat\nWARNING: Certificate already exists: caSigningCert cert-pki-ca\nWARNING: Directory already exists: /var/lib/ipa/tmp-i2dhlro5\nWARNING: Unable to add cn=revokedby,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=issuedby,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=publicKeyData,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=clientId,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=dataType,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=status,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=description,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=serialno,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=metaInfo,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=certstatus,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=requestid,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=requesttype,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=requeststate,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=requestowner,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=notbefore,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=notafter,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=duration,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=dateOfCreate,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=revokedOn,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=archivedBy,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=ownername,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=subjectname,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=requestsourceid,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=revInfo,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add cn=extension,cn=index,cn=ipaca,cn=ldbm database, cn=plugins, cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to add ou=csusers,cn=config: netscape.ldap.LDAPException: error result (68); Already exists\nWARNING: Unable to modify o=kra,o=ipaca: netscape.ldap.LDAPException: error result (20); Type or value exists\nWARNING: Unable to modify cn="o=kra,o=ipaca",cn=mapping tree,cn=config: netscape.ldap.LDAPException: error result (32); No such object\nWARNING: Unable to modify cn="o=kra,o=ipaca",cn=mapping tree,cn=config: netscape.ldap.LDAPException: error result (32); No such object\nWARNING: Unable to modify cn="o=kra,o=ipaca",cn=mapping tree,cn=config: netscape.ldap.LDAPException: error result (32); No such object\nPKIException: Internal Server Error\nERROR: CalledProcessError: Command \'[\'pki\', \'-d\', \'/etc/pki/pki-tomcat/alias\', \'-f\', \'/etc/pki/pki-tomcat/password.conf\', \'-U\', \'https://replica2.ipa.test:443\', \'kra-range-request\', \'request\', \'--session\', \'2894848019521579307\', \'--output-format\', \'json\']\' returned non-zero exit status 255.\n  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 575, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 854, in spawn\n    subsystem.update_ranges(master_url, deployer.install_token)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 975, in update_ranges\n    request_range = self.request_range(master_url, \'request\', install_token)\n  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 967, in request_range\n    output = subprocess.check_output(cmd)\n  File "/usr/lib64/python3.8/subprocess.py", line 411, in check_output\n    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,\n  File "/usr/lib64/python3.8/subprocess.py", line 512, in run\n    raise CalledProcessError(retcode, process.args,\n\n')
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 See the installation logs and the following files/directories for more information:
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557   /var/log/pki/pki-tomcat
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557   [error] RuntimeError: KRA configuration failed.
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 KRA configuration failed.
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 Your system may be partly configured.
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 Run /usr/sbin/ipa-server-install --uninstall to clean up.
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:557 
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:transport.py:217 Exit code: 1
ERROR    ipatests.pytest_ipa.integration.host.Host.replica1.cmd87:host.py:199 stderr: Lookup failed: Preferred host replica1.ipa.test does not provide DNS.
Could not resolve hostname replica1.ipa.test using DNS. Clients may not function properly. Please check your DNS setup. (Note that this check queries IPA DNS directly and ignores /etc/hosts.)
Lookup failed: Preferred host master.ipa.test does not provide KRA.

logs


Investigations:

  • ipa-replica-install --setup-kra fails on replica1
2020-08-23T22:26:30Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: KRA configuration failed.
2020-08-23T22:26:30Z ERROR KRA configuration failed.
2020-08-23T22:26:30Z ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information
  • Contents of pki-kra-spawn.log on replica1:
2020-08-23 22:25:20 WARNING: Directory already exists: /etc/pki/pki-tomcat
2020-08-23 22:25:27 WARNING: Directory already exists: /var/lib/ipa/tmp-i2dhlro5
2020-08-23 22:26:29 ERROR: CalledProcessError: Command '['pki', '-d', '/etc/pki/pki-tomcat/alias', '-f', '/etc/pki/pki-tomcat/password.conf', '-U', 'https://replica2.ipa.test:443', 'kra-range-request', 'request', '--session', '2894848019521579307', '--output-format', 'json']' returned non-zero exit status 255.
  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 575, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 854, in spawn
    subsystem.update_ranges(master_url, deployer.install_token)
  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 975, in update_ranges
    request_range = self.request_range(master_url, 'request', install_token)
  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 967, in request_range
    output = subprocess.check_output(cmd)
  File "/usr/lib64/python3.8/subprocess.py", line 411, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
  File "/usr/lib64/python3.8/subprocess.py", line 512, in run
    raise CalledProcessError(retcode, process.args,

This means that replica2 is used to build the clone.

  • Contents of /var/log/pki/pki-tomcat/pki/debug on replica2:
2020-08-23 22:26:28 [ajp-nio-127.0.0.1-8009-exec-6] SEVERE: Servlet.init() for servlet [Resteasy] threw exception
Caused by: java.lang.ExceptionInInitializerError
Caused by: java.lang.IllegalStateException: Unexpected initialization failure
Caused by: java.security.AccessControlException: access denied ("java.io.FilePermission" "/usr/share/pki/server/webapps/pki/WEB-INF/lib/pki-cmsbundle.jar" "read")
2020-08-23 22:26:28 [ajp-nio-127.0.0.1-8009-exec-6] SEVERE: Allocate exception for servlet [Resteasy]
java.security.AccessControlException: access denied ("java.io.FilePermission" "/usr/share/pki/server/webapps/pki/WEB-INF/lib/pki-cmsbundle.jar" "read")

The issue seems similar to https://pagure.io/dogtagpki/issue/3182

Test failure observed in testing_master_previous

PR 964
Logs

The test failure in the above comment is related to a different issue: #8870:

org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

Since this issue hasn't been reproduced in a long time, closing. Feel free to re-open if needed.

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

2 years ago

Login to comment on this ticket.

Metadata