#8466 [tracker] Nightly test failure in [testing_master_pki] during ipa-server-install
Closed: duplicate 3 years ago by frenaud. Opened 3 years ago by frenaud.

Issue

The nightly tests in [testing_master_pki] failed during ipa-server-install in PR #353. The failure happens during pki server installation, see the report for instance for the test test_installation_TestInstallCA:

cls = <class 'ipatests.test_integration.test_installation.TestInstallCA'>
mh = <pytest_multihost.plugin.MultihostFixture object at 0x7f5455a4f040>

    @classmethod
    def install(cls, mh):
>       tasks.install_master(cls.master, setup_dns=False)

test_integration/test_installation.py:241: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
pytest_ipa/integration/tasks.py:326: in install_master
    result = host.run_command(args, raiseonerr=raiseonerr,
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <ipatests.pytest_ipa.integration.host.Host master.ipa.test (master)>
argv = ['ipa-server-install', '-n', 'ipa.test', '-r', 'IPA.TEST', '-p', ...]
set_env = True, stdin_text = None, log_stdout = True, raiseonerr = True
cwd = None, bg = False, encoding = 'utf-8', ok_returncode = 0

    def run_command(self, argv, set_env=True, stdin_text=None,
                    log_stdout=True, raiseonerr=True,
                    cwd=None, bg=False, encoding='utf-8', ok_returncode=0):
        """Wrapper around run_command to log stderr on raiseonerr=True

        :param ok_returncode: return code considered to be correct,
                              you can pass an integer or sequence of integers
        """
        result = super().run_command(
            argv, set_env=set_env, stdin_text=stdin_text,
            log_stdout=log_stdout, raiseonerr=False, cwd=cwd, bg=bg,
            encoding=encoding
        )
        # in FIPS mode SSH may print noise to stderr, remove the string
        # "FIPS mode initialized" + optional newline.
        result.stderr_bytes = FIPS_NOISE_RE.sub(b'', result.stderr_bytes)
        try:
            result_ok = result.returncode in ok_returncode
        except TypeError:
            result_ok = result.returncode == ok_returncode
        if not result_ok and raiseonerr:
            result.log.error('stderr: %s', result.stderr_text)
>           raise subprocess.CalledProcessError(
                result.returncode, argv,
                result.stdout_text, result.stderr_text
            )
E           subprocess.CalledProcessError: Command '['ipa-server-install', '-n', 'ipa.test', '-r', 'IPA.TEST', '-p', 'Secret.123', '-a', 'Secret.123', '--domain-level=1', '-U']' returned non-zero exit status 1.

pytest_ipa/integration/host.py:200: CalledProcessError
 -----------------------------Captured stderr setup------------------------------ 

[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [4/10]: adding default ACIs
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [5/10]: creating a keytab for the directory
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [6/10]: creating a keytab for the machine
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [7/10]: adding the password extension to the directory
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [8/10]: creating anonymous principal
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [9/10]: starting the KDC
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [10/10]: configuring KDC to start on boot
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] Done configuring Kerberos KDC (krb5kdc).
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] Configuring kadmin
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [1/2]: starting kadmin 
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [2/2]: configuring kadmin to start on boot
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] Done configuring kadmin.
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] Configuring ipa-custodia
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [1/5]: Making sure custodia container exists
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [2/5]: Generating ipa-custodia config file
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [3/5]: Generating ipa-custodia keys
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [4/5]: starting ipa-custodia 
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [5/5]: configuring ipa-custodia to start on boot
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] Done configuring ipa-custodia.
[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] 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')
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] See the installation logs and the following files/directories for more information:
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   /var/log/pki/pki-tomcat
[ipatests.pytest_ipa.integration.host.Host.master.cmd29]   [error] RuntimeError: CA configuration failed.
[ipatests.pytest_ipa.integration.host.Host.master.cmd29] CA configuration failed.
[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
ipa: ERROR: stderr: Synchronizing time
No SRV records of NTP servers found and no NTP server or pool address was provided.
Attempting to sync time with chronyc.
Process chronyc waitsync failed to sync time!
Unable to sync time with chrony server, assuming the time is in sync. Please check that 123 UDP port is opened, and any time server is on network.
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')
See the installation logs and the following files/directories for more information:
  /var/log/pki/pki-tomcat
CA configuration failed.
The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

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,

Opened dogtagpki issue 3206.


Metadata Update from @frenaud:
- Issue tagged with: test-failure, tests

3 years ago

Metadata Update from @frenaud:
- Issue tagged with: tracker

3 years ago

Issue can be closed as duplicate of #8524 Deploy & manage the ACME service topology wide from a single system, which got fixed in ipa-4-8.

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

3 years ago

Login to comment on this ticket.

Metadata