#8208 Nightly tests: random failure in ipa-replica-install with timeout restarting PKI
Closed: worksforme 3 years ago by frenaud. Opened 4 years ago by frenaud.

The nightly tests randomly fail in the ipa-replica-install step with a timeout while restarting PKI.
For instance, see PR #4279 with the following logs in the test test_integration/test_installation.py::TestInstallWithCA1::test_replica2_with_ca_kra_install:

self = <ipatests.test_integration.test_installation.TestInstallWithCA1 object at 0x7f261ebcc090>

    @pytest.mark.skipif(config.domain_level == DOMAIN_LEVEL_0,
                        reason='does not work on DOMAIN_LEVEL_0 by design')
    def test_replica2_with_ca_kra_install(self):
>       super(TestInstallWithCA1, self).test_replica2_with_ca_kra_install()

test_integration/test_installation.py:197: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
test_integration/test_installation.py:123: in test_replica2_with_ca_kra_install
    setup_kra=True)
pytest_ipa/integration/tasks.py:516: in install_replica
    stdin_text=stdin_text)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <ipatests.pytest_ipa.integration.host.Host replica1.ipa.test (replica)>
argv = ['ipa-replica-install', '--admin-password', 'Secret.123', '--password', 'Secret.123', '-U', ...]
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-replica-install', '--admin-password', 'Secret.123', '--password', 'Secret.123', '-U', '--setup-ca', '--setup-kra', '--ip-address', '192.168.122.46', '--realm', 'IPA.TEST', '--domain', 'ipa.test']' returned non-zero exit status 1.

pytest_ipa/integration/host.py:193: CalledProcessError
 ------------------------------Captured stderr call------------------------------ 

[ipatests.pytest_ipa.integration.host.Host.replica1.cmd39] RUN ['true']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd39] Exit code: 0
[ipatests.pytest_ipa.integration] Adding replica1.ipa.test:/ipatests/env.sh to list of logs to collect
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] STAT /ipatests
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] WRITE /ipatests/env.sh
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] STAT /etc/hostname
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] STAT /ipatests/file_backup/etc
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] RUN ['cp', '-af', '/etc/hostname', '/ipatests/file_backup/etc/hostname']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd40] RUN ['cp', '-af', '/etc/hostname', '/ipatests/file_backup/etc/hostname']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd40] Exit code: 0
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] WRITE /etc/hostname
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] RUN ['hostname', 'replica1.ipa.test']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd41] RUN ['hostname', 'replica1.ipa.test']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd41] Exit code: 0
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] RUN hostname > '/ipatests/backup_hostname'
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd42] RUN hostname > '/ipatests/backup_hostname'
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd42] Exit code: 0
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] RUN ['ss', '--all', '--tcp', '--udp', '--numeric', '--processes']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] RUN ['ss', '--all', '--tcp', '--udp', '--numeric', '--processes']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] Netid  State   Recv-Q  Send-Q         Local Address:Port     Peer Address:Port                                                                                  
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] udp    UNCONN  0       0        192.168.122.46%eth0:68            0.0.0.0:*      users:(("NetworkManager",pid=1976,fd=20))                                      
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] udp    UNCONN  0       0                  127.0.0.1:323           0.0.0.0:*      users:(("chronyd",pid=507,fd=6))                                               
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] udp    UNCONN  0       0                      [::1]:323              [::]:*      users:(("chronyd",pid=507,fd=7))                                               
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] tcp    LISTEN  0       128                  0.0.0.0:22            0.0.0.0:*      users:(("sshd",pid=566,fd=5))                                                  
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] tcp    ESTAB   0       0             192.168.122.46:22      192.168.122.1:54822  users:(("sshd",pid=2699,fd=5),("sshd",pid=2672,fd=5))                          
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] tcp    ESTAB   0       0             192.168.122.46:22     192.168.122.13:34764  users:(("sshd",pid=18136,fd=5),("sshd",pid=18133,fd=5))                        
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] tcp    LISTEN  0       128                     [::]:22               [::]:*      users:(("sshd",pid=566,fd=7))                                                  
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd43] Exit code: 0
[ipatests.pytest_ipa.integration.host.Host.replica1.ParamikoTransport] RUN ['ss', '--all', '--tcp', '--udp', '--numeric', '--processes', '-o', 'state', 'all', '( sport = :749 or dport = :749 or sport = :464 or dport = :464 )']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd44] RUN ['ss', '--all', '--tcp', '--udp', '--numeric', '--processes', '-o', 'state', 'all', '( sport = :749 or dport = :749 or sport = :464 or dport = :464 )']
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd44] Netid   State   Recv-Q   Send-Q     Local Address:Port      Peer Address:Port   
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd44] Exit code: 0
[ipatests.pytest_ipa.integration.host.Host.master.ParamikoTransport] RUN ['kinit', 'admin']
[ipatests.pytest_ipa.integration.host.Host.master.cmd75] RUN ['kinit', 'admin']
[ipatests.pytest_ipa.integration.host.Host.master.cmd75] Password for admin@IPA.TEST: 
[ipatests.pytest_ipa.integration.host.Host.master.cmd75] Exit code: 0
[ipatests.pytest_ipa.integration.host.Host.master.ParamikoTransport] RUN ['ipa', 'dnsconfig-mod', '--allow-sync-ptr=true']
[ipatests.pytest_ipa.integration.host.Host.master.cmd76] RUN ['ipa', 'dnsconfig-mod', '--allow-sync-ptr=true']
[ipatests.pytest_ipa.integration.host.Host.master.cmd76] ipa: ERROR: no modifications to be performed
[ipatests.pytest_ipa.integration.host.Host.master.cmd76] Exit code: 1
[ipatests.pytest_ipa.integration.host.Host.master.ParamikoTransport] RUN ['ipa', 'dnszone-add', '122.168.192.in-addr.arpa.']
[ipatests.pytest_ipa.integration.host.Host.master.cmd77] RUN ['ipa', 'dnszone-add', '122.168.192.in-addr.arpa.']
[ipatests.pytest_ipa.integration.host.Host.master.cmd77] ipa: ERROR: DNS zone with name "122.168.192.in-addr.arpa." already exists
[ipatests.pytest_ipa.integration.host.Host.master.cmd77] Exit code: 1
ipa: WARNING: ipa: ERROR: DNS zone with name "122.168.192.in-addr.arpa." already exists


[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58]   [18/29]: Importing RA key
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58]   [19/29]: setting audit signing renewal to 2 years
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58]   [20/29]: restarting certificate server
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58]   [error] CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'restart', 'pki-tomcatd@pki-tomcat.service'] returned non-zero exit status 1: 'Job for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\n')
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58] CalledProcessError(Command ['/bin/systemctl', 'restart', 'pki-tomcatd@pki-tomcat.service'] returned non-zero exit status 1: 'Job for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\n')
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58] The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58] Your system may be partly configured.
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58] Run /usr/sbin/ipa-server-install --uninstall to clean up.
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58] 
[ipatests.pytest_ipa.integration.host.Host.replica1.cmd58] Exit code: 1
ipa: ERROR: stderr: Lookup failed: Preferred host replica1.ipa.test does not provide DNS.
Reverse DNS resolution of address 192.168.122.89 (master.ipa.test) failed. 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.
Custodia uses 'replica2.ipa.test' as master peer.
CalledProcessError(Command ['/bin/systemctl', 'restart', 'pki-tomcatd@pki-tomcat.service'] returned non-zero exit status 1: 'Job for pki-tomcatd@pki-tomcat.service failed because a timeout was exceeded.\nSee "systemctl status pki-tomcatd@pki-tomcat.service" and "journalctl -xe" for details.\n')
The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

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

4 years ago

Also seen in ipa-server-install in PR #255 in test_vault

Issue not seen any more, closing as worksforme. Feel free to re-open if it happens again.

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

3 years ago

Login to comment on this ticket.

Metadata