FreeIPA nightly tests are failing in ipa-server-install in the pkispawn step, when using pki nightly copr repo. See the PR #353, with the following report and logs.
ipa-server-install logs:
2020-08-16T20:29:32Z DEBUG Starting external process 2020-08-16T20:29:32Z DEBUG args=['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmps1az97js'] 2020-08-16T20:30:06Z DEBUG Process finished, return code=1 2020-08-16T20:30:06Z DEBUG stdout=Loading deployment configuration from /tmp/tmps1az97js. WARNING: The 'pki_ssl_server_token' in [CA] has been deprecated. Use 'pki_sslserver_token' instead. Installation log: /var/log/pki/pki-ca-spawn.20200816202933.log Installing CA into /var/lib/pki/pki-tomcat. Installation failed: Command failed: /usr/sbin/runuser -u pkiuser -- /usr/lib/jvm/jre-openjdk/bin/java -classpath /usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/* -Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory -Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp -Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Dcom.redhat.fips=false org.dogtagpki.server.cli.PKIServerCLI ca-db-init --setup-schema --create-database --create-base --create-containers --setup-db-manager --setup-vlv-indexes Please check pkispawn logs in /var/log/pki/pki-ca-spawn.20200816202933.log 2020-08-16T20:30:06Z DEBUG stderr=Notice: Trust flag u is set automatically if the private key is present. Exception in thread "main" java.io.FileNotFoundException: /usr/share/pki/acme/database/ldap/schema.ldif (No such file or directory) at java.io.FileInputStream.open0(Native Method) at java.io.FileInputStream.open(FileInputStream.java:195) at java.io.FileInputStream.<init>(FileInputStream.java:138) at java.io.FileInputStream.<init>(FileInputStream.java:93) at netscape.ldap.util.LDIF.<init>(Unknown Source) at com.netscape.cms.servlet.csadmin.LDAPConfigurator.importSchemaFile(LDAPConfigurator.java:522) at com.netscape.cms.servlet.csadmin.LDAPConfigurator.setupSchema(LDAPConfigurator.java:90) at org.dogtagpki.server.cli.SubsystemDBInitCLI.execute(SubsystemDBInitCLI.java:129) at org.dogtagpki.cli.CommandCLI.execute(CommandCLI.java:57) at org.dogtagpki.cli.CLI.execute(CLI.java:352) at org.dogtagpki.cli.CLI.execute(CLI.java:352) at org.dogtagpki.cli.CLI.execute(CLI.java:352) at org.dogtagpki.server.cli.PKIServerCLI.execute(PKIServerCLI.java:86) at org.dogtagpki.server.cli.PKIServerCLI.main(PKIServerCLI.java:92) ERROR: CalledProcessError: Command '['/usr/sbin/runuser', '-u', 'pkiuser', '--', '/usr/lib/jvm/jre-openjdk/bin/java', '-classpath', '/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*', '-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory', '-Dcatalina.base=/var/lib/pki/pki-tomcat', '-Dcatalina.home=/usr/share/tomcat', '-Djava.endorsed.dirs=', '-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp', '-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties', '-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager', '-Dcom.redhat.fips=false', 'org.dogtagpki.server.cli.PKIServerCLI', 'ca-db-init', '--setup-schema', '--create-database', '--create-base', '--create-containers', '--setup-db-manager', '--setup-vlv-indexes']' returned non-zero exit status 1. 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 840, in spawn subsystem.init_database( File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 915, in init_database self.run(cmd, as_current_user=as_current_user) File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 1137, in run subprocess.run(cmd, check=True) File "/usr/lib64/python3.8/subprocess.py", line 512, in run raise CalledProcessError(retcode, process.args, 2020-08-16T20:30:06Z CRITICAL Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmps1az97js'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nException in thread "main" java.io.FileNotFoundException: /usr/share/pki/acme/database/ldap/schema.ldif (No such file or directory)\n\tat java.io.FileInputStream.open0(Native Method)\n\tat java.io.FileInputStream.open(FileInputStream.java:195)\n\tat java.io.FileInputStream.<init>(FileInputStream.java:138)\n\tat java.io.FileInputStream.<init>(FileInputStream.java:93)\n\tat netscape.ldap.util.LDIF.<init>(Unknown Source)\n\tat com.netscape.cms.servlet.csadmin.LDAPConfigurator.importSchemaFile(LDAPConfigurator.java:522)\n\tat com.netscape.cms.servlet.csadmin.LDAPConfigurator.setupSchema(LDAPConfigurator.java:90)\n\tat org.dogtagpki.server.cli.SubsystemDBInitCLI.execute(SubsystemDBInitCLI.java:129)\n\tat org.dogtagpki.cli.CommandCLI.execute(CommandCLI.java:57)\n\tat org.dogtagpki.cli.CLI.execute(CLI.java:352)\n\tat org.dogtagpki.cli.CLI.execute(CLI.java:352)\n\tat org.dogtagpki.cli.CLI.execute(CLI.java:352)\n\tat org.dogtagpki.server.cli.PKIServerCLI.execute(PKIServerCLI.java:86)\n\tat org.dogtagpki.server.cli.PKIServerCLI.main(PKIServerCLI.java:92)\nERROR: CalledProcessError: Command \'[\'/usr/sbin/runuser\', \'-u\', \'pkiuser\', \'--\', \'/usr/lib/jvm/jre-openjdk/bin/java\', \'-classpath\', \'/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*\', \'-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory\', \'-Dcatalina.base=/var/lib/pki/pki-tomcat\', \'-Dcatalina.home=/usr/share/tomcat\', \'-Djava.endorsed.dirs=\', \'-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp\', \'-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties\', \'-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager\', \'-Dcom.redhat.fips=false\', \'org.dogtagpki.server.cli.PKIServerCLI\', \'ca-db-init\', \'--setup-schema\', \'--create-database\', \'--create-base\', \'--create-containers\', \'--setup-db-manager\', \'--setup-vlv-indexes\']\' returned non-zero exit status 1.\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 840, in spawn\n subsystem.init_database(\n File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 915, in init_database\n self.run(cmd, as_current_user=as_current_user)\n File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 1137, in run\n subprocess.run(cmd, check=True)\n File "/usr/lib64/python3.8/subprocess.py", line 512, in run\n raise CalledProcessError(retcode, process.args,\n\n') 2020-08-16T20:30:06Z CRITICAL See the installation logs and the following files/directories for more information: 2020-08-16T20:30:06Z CRITICAL /var/log/pki/pki-tomcat 2020-08-16T20:30:06Z DEBUG Traceback (most recent call last): File "/usr/lib/python3.8/site-packages/ipaserver/install/dogtaginstance.py", line 201, in spawn_instance ipautil.run(args, nolog=nolog_list) File "/usr/lib/python3.8/site-packages/ipapython/ipautil.py", line 597, in run raise CalledProcessError( ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmps1az97js'] returned non-zero exit status 1: 'Notice: Trust flag u is set automatically if the private key is present.\nException in thread "main" java.io.FileNotFoundException: /usr/share/pki/acme/database/ldap/schema.ldif (No such file or directory)\n\tat java.io.FileInputStream.open0(Native Method)\n\tat java.io.FileInputStream.open(FileInputStream.java:195)\n\tat java.io.FileInputStream.<init>(FileInputStream.java:138)\n\tat java.io.FileInputStream.<init>(FileInputStream.java:93)\n\tat netscape.ldap.util.LDIF.<init>(Unknown Source)\n\tat com.netscape.cms.servlet.csadmin.LDAPConfigurator.importSchemaFile(LDAPConfigurator.java:522)\n\tat com.netscape.cms.servlet.csadmin.LDAPConfigurator.setupSchema(LDAPConfigurator.java:90)\n\tat org.dogtagpki.server.cli.SubsystemDBInitCLI.execute(SubsystemDBInitCLI.java:129)\n\tat org.dogtagpki.cli.CommandCLI.execute(CommandCLI.java:57)\n\tat org.dogtagpki.cli.CLI.execute(CLI.java:352)\n\tat org.dogtagpki.cli.CLI.execute(CLI.java:352)\n\tat org.dogtagpki.cli.CLI.execute(CLI.java:352)\n\tat org.dogtagpki.server.cli.PKIServerCLI.execute(PKIServerCLI.java:86)\n\tat org.dogtagpki.server.cli.PKIServerCLI.main(PKIServerCLI.java:92)\nERROR: CalledProcessError: Command \'[\'/usr/sbin/runuser\', \'-u\', \'pkiuser\', \'--\', \'/usr/lib/jvm/jre-openjdk/bin/java\', \'-classpath\', \'/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*\', \'-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory\', \'-Dcatalina.base=/var/lib/pki/pki-tomcat\', \'-Dcatalina.home=/usr/share/tomcat\', \'-Djava.endorsed.dirs=\', \'-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp\', \'-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties\', \'-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager\', \'-Dcom.redhat.fips=false\', \'org.dogtagpki.server.cli.PKIServerCLI\', \'ca-db-init\', \'--setup-schema\', \'--create-database\', \'--create-base\', \'--create-containers\', \'--setup-db-manager\', \'--setup-vlv-indexes\']\' returned non-zero exit status 1.\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 840, in spawn\n subsystem.init_database(\n File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 915, in init_database\n self.run(cmd, as_current_user=as_current_user)\n File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 1137, in run\n subprocess.run(cmd, check=True)\n File "/usr/lib64/python3.8/subprocess.py", line 512, in run\n raise CalledProcessError(retcode, process.args,\n\n')
pki-ca-spawn logs:
2020-08-16 20:30:06 ERROR: CalledProcessError: Command '['/usr/sbin/runuser', '-u', 'pkiuser', '--', '/usr/lib/jvm/jre-openjdk/bin/java', '-classpath', '/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/ca/webapps/ca/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*', '-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory', '-Dcatalina.base=/var/lib/pki/pki-tomcat', '-Dcatalina.home=/usr/share/tomcat', '-Djava.endorsed.dirs=', '-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp', '-Djava.util.logging.config.file=/etc/pki/pki-tomcat/logging.properties', '-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager', '-Dcom.redhat.fips=false', 'org.dogtagpki.server.cli.PKIServerCLI', 'ca-db-init', '--setup-schema', '--create-database', '--create-base', '--create-containers', '--setup-db-manager', '--setup-vlv-indexes']' returned non-zero exit status 1. 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 840, in spawn subsystem.init_database( File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 915, in init_database self.run(cmd, as_current_user=as_current_user) File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 1137, in run subprocess.run(cmd, check=True) File "/usr/lib64/python3.8/subprocess.py", line 512, in run raise CalledProcessError(retcode, process.args,
Installed packages: - pki-base-10.10.0-0.1.alpha1.20200814013225UTC.13406396.fc32.noarch
Note: this is blocking our tests using the nightly dogtagpki copr repo @pki/master
@edewata -- Please take a look. Looks like a bug in the pki-acme split.
pki-acme
Metadata Update from @cipherboy: - Custom field component adjusted to None - Custom field feature adjusted to None - Custom field origin adjusted to None - Custom field proposedmilestone adjusted to None - Custom field proposedpriority adjusted to None - Custom field reviewer adjusted to None - Custom field type adjusted to None - Custom field version adjusted to None
Or, since IPA merged ACME: https://github.com/freeipa/freeipa/pull/4723 -- might need to fix IPA.
One fix is being considered here: https://github.com/freeipa/freeipa/pull/5039
With a more recent build pki build (10.10.0-0.1.alpha1.20200909013458UTC.eac41b), ipa-server-install is failing later, in the pki-server acme-deploy step. Please see PR #394, with logs:
pki-server acme-deploy
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [1/31]: configuring certificate server instance [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [2/31]: Add ipa-pki-wait-running [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [3/31]: secure AJP connector [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [4/31]: reindex attributes [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [5/31]: exporting Dogtag certificate store pin [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [6/31]: stopping certificate server instance to update CS.cfg [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [7/31]: backing up CS.cfg [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [8/31]: disabling nonces [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [9/31]: set up CRL publishing [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [10/31]: enable PKIX certificate path discovery and validation [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [11/31]: deploying ACME service [ipatests.pytest_ipa.integration.host.Host.master.cmd29] [error] CalledProcessError: CalledProcessError(Command ['pki-server', 'acme-deploy'] returned non-zero exit status 1: 'ERROR: Error reading file \'/usr/share/pki/acme/conf/Catalina/localhost/acme.xml\': failed to load external entity "/usr/share/pki/acme/conf/Catalina/localhost/acme.xml"\n') [ipatests.pytest_ipa.integration.host.Host.master.cmd29] CalledProcessError(Command ['pki-server', 'acme-deploy'] returned non-zero exit status 1: 'ERROR: Error reading file \'/usr/share/pki/acme/conf/Catalina/localhost/acme.xml\': failed to load external entity "/usr/share/pki/acme/conf/Catalina/localhost/acme.xml"\n') [ipatests.pytest_ipa.integration.host.Host.master.cmd29] The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information [ipatests.pytest_ipa.integration.host.Host.master.cmd29] Exit code: 1
Fixed with https://pagure.io/freeipa/c/c0461eb37ccf0b87b05f81380cf60dffdd26a3dc?branch=master on freeipa side: spec: require pki-acme if pki-ca >= 10.10
Metadata Update from @frenaud: - Issue close_status updated to: fixed - Issue status updated to: Closed (was: Open)
Dogtag PKI is moving from Pagure issues to GitHub issues. This means that existing or new issues will be reported and tracked through Dogtag PKI's GitHub Issue tracker.
This issue has been cloned to GitHub and is available here: https://github.com/dogtagpki/pki/issues/3323
If you want to receive further updates on the issue, please navigate to the GitHub issue and click on Subscribe button.
Subscribe
Thank you for understanding, and we apologize for any inconvenience.
Login to comment on this ticket.