Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Nightly test failure in ipa-server-install while calling pki-server acme-deploy (with pki nightly repo) #3323

Closed
pki-bot opened this issue Oct 3, 2020 · 8 comments
Closed

Nightly test failure in ipa-server-install while calling pki-server acme-deploy (with pki nightly repo) #3323

pki-bot opened this issue Oct 3, 2020 · 8 comments
Labels
Closed: Fixed

Comments

@pki-bot
Copy link

pki-bot commented Oct 3, 2020

This issue was migrated from Pagure Issue #3206. Originally filed by frenaud (@flo-renaud) on 2020-08-17 09:38:42:

  • Closed at 2020-09-24 04:03:37 as fixed
  • Assigned to nobody

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
@pki-bot pki-bot closed this as completed Oct 3, 2020
@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from frenaud (@flo-renaud) at 2020-08-17 09:41:33

Note: this is blocking our tests using the nightly dogtagpki copr repo @pki/master

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from cipherboy (@cipherboy) at 2020-08-17 10:30:07

@edewata -- Please take a look. Looks like a bug in the pki-acme split.

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from cipherboy (@cipherboy) at 2020-08-17 10:30:08

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

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from cipherboy (@cipherboy) at 2020-08-17 10:34:18

Or, since IPA merged ACME: freeipa/freeipa#4723 -- might need to fix IPA.

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from cipherboy (@cipherboy) at 2020-08-24 15:22:01

One fix is being considered here: freeipa/freeipa#5039

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from frenaud (@flo-renaud) at 2020-09-10 12:26:19

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:

[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

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from frenaud (@flo-renaud) at 2020-09-24 04:03:37

Fixed with https://pagure.io/freeipa/c/c0461eb37ccf0b87b05f81380cf60dffdd26a3dc?branch=master on freeipa side: spec: require pki-acme if pki-ca >= 10.10

@pki-bot
Copy link
Author

pki-bot commented Oct 3, 2020

Comment from frenaud (@flo-renaud) at 2020-09-24 04:03:38

Metadata Update from @flo-renaud:

  • Issue close_status updated to: fixed
  • Issue status updated to: Closed (was: Open)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Closed: Fixed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@pki-bot