#7340 Test test_backup_and_restore.TestBackupAndRestoreWithDNSSEC is faliing
Closed: fixed Opened by fbarreto.

Issue

Test test_backup_and_restore.TestBackupAndRestoreWithDNSSEC.test_full_backup_and_restore_with_DNSSEC_zone is faling with message:

[ipa.ipatests.test_integration.host.Host.master.cmd28] Preparing restore from /var/lib/ipa/backup/ipa-full-2017-12-28-15-39-52 on master.ipa.test
[2017-12-28T15:42:36Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Preparing restore from /var/lib/ipa/backup/ipa-full-2017-12-28-15-39-52 on master.ipa.test
[ipa.ipatests.test_integration.host.Host.master.cmd28] Performing FULL restore from FULL backup
[2017-12-28T15:42:36Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Performing FULL restore from FULL backup
[ipa.ipatests.test_integration.host.Host.master.cmd28] Each master will individually need to be re-initialized or
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Each master will individually need to be re-initialized or
[ipa.ipatests.test_integration.host.Host.master.cmd28] re-created from this one. The replication agreements on
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: re-created from this one. The replication agreements on
[ipa.ipatests.test_integration.host.Host.master.cmd28] masters running IPA 3.1 or earlier will need to be manually
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: masters running IPA 3.1 or earlier will need to be manually
[ipa.ipatests.test_integration.host.Host.master.cmd28] re-enabled. See the man page for details.
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: re-enabled. See the man page for details.
[ipa.ipatests.test_integration.host.Host.master.cmd28] Disabling all replication.
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Disabling all replication.
[ipa.ipatests.test_integration.host.Host.master.cmd28] Unable to get connection, skipping disabling agreements: directory server instance is not running/configured
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Unable to get connection, skipping disabling agreements: directory server instance is not running/configured
[ipa.ipatests.test_integration.host.Host.master.cmd28] Stopping IPA services
[2017-12-28T15:42:37Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Stopping IPA services
[ipa.ipatests.test_integration.host.Host.master.cmd28] Directory Manager (existing master) password:
[2017-12-28T15:42:38Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Directory Manager (existing master) password:
[ipa.ipatests.test_integration.host.Host.master.cmd28] Restoring data will overwrite existing live data. Continue to restore? [no]: Configuring certmonger to stop tracking system certificates for CA
[2017-12-28T15:42:38Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Restoring data will overwrite existing live data. Continue to restore? [no]: Configuring certmonger to stop tracking system certificates for CA
[ipa.ipatests.test_integration.host.Host.master.cmd28] Restoring files
[2017-12-28T15:42:39Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Restoring files
[ipa.ipatests.test_integration.host.Host.master.cmd28] Systemwide CA database updated.
[2017-12-28T15:42:39Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Systemwide CA database updated.
[ipa.ipatests.test_integration.host.Host.master.cmd28] Restoring from userRoot in IPA-TEST
[2017-12-28T15:42:39Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Restoring from userRoot in IPA-TEST
[ipa.ipatests.test_integration.host.Host.master.cmd28] Restoring from ipaca in IPA-TEST
[2017-12-28T15:42:42Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Restoring from ipaca in IPA-TEST
[ipa.ipatests.test_integration.host.Host.master.cmd28] Starting IPA services
[2017-12-28T15:42:45Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Starting IPA services
[ipa.ipatests.test_integration.host.Host.master.cmd28] Restarting SSSD
[2017-12-28T15:43:14Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Restarting SSSD
[ipa.ipatests.test_integration.host.Host.master.cmd28] The ipa-restore command was successful
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: The ipa-restore command was successful
[ipa.ipatests.test_integration.host.Host.master.cmd28] Exit code: 0
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.cmd28] <DEBUG>: Exit code: 0
[ipa.ipatests.test_integration.base.IntegrationTest] Waiting for signed SOA record of example.test. from server 192.168.137.101 (timeout 100 sec)
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.base.IntegrationTest] <INFO>: Waiting for signed SOA record of example.test. from server 192.168.137.101 (timeout 100 sec)
[ipa.ipatests.test_integration.host.Host.master.ParamikoTransport] RUN ['kinit', 'admin']
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.ParamikoTransport] <INFO>: RUN ['kinit', 'admin']
[ipa.ipatests.test_integration.host.Host.master.cmd29] RUN ['kinit', 'admin']
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.cmd29] <DEBUG>: RUN ['kinit', 'admin']
[ipa.ipatests.test_integration.host.Host.master.cmd29] Password for admin@IPA.TEST:
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.cmd29] <DEBUG>: Password for admin@IPA.TEST:
[ipa.ipatests.test_integration.host.Host.master.cmd29] Exit code: 0
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.cmd29] <DEBUG>: Exit code: 0
[ipa.ipatests.test_integration.host.Host.master.ParamikoTransport] RUN ['ipa', 'dnszone-add', 'example2.test.', '--dnssec', 'true']
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.ParamikoTransport] <INFO>: RUN ['ipa', 'dnszone-add', 'example2.test.', '--dnssec', 'true']
[ipa.ipatests.test_integration.host.Host.master.cmd30] RUN ['ipa', 'dnszone-add', 'example2.test.', '--dnssec', 'true']
[2017-12-28T15:43:15Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>: RUN ['ipa', 'dnszone-add', 'example2.test.', '--dnssec', 'true']
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Zone name: example2.test.
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Zone name: example2.test.
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Active zone: TRUE
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Active zone: TRUE
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Authoritative nameserver: master.ipa.test.
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Authoritative nameserver: master.ipa.test.
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Administrator e-mail address: hostmaster
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Administrator e-mail address: hostmaster
[ipa.ipatests.test_integration.host.Host.master.cmd30]   SOA serial: 1514475797
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   SOA serial: 1514475797
[ipa.ipatests.test_integration.host.Host.master.cmd30]   SOA refresh: 3600
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   SOA refresh: 3600
[ipa.ipatests.test_integration.host.Host.master.cmd30]   SOA retry: 900
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   SOA retry: 900
[ipa.ipatests.test_integration.host.Host.master.cmd30]   SOA expire: 1209600
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   SOA expire: 1209600
[ipa.ipatests.test_integration.host.Host.master.cmd30]   SOA minimum: 3600
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   SOA minimum: 3600
[ipa.ipatests.test_integration.host.Host.master.cmd30]   BIND update policy: grant IPA.TEST krb5-self * A; grant IPA.TEST krb5-self * AAAA; grant IPA.TEST krb5-self * SSHFP;
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   BIND update policy: grant IPA.TEST krb5-self * A; grant IPA.TEST krb5-self * AAAA; grant IPA.TEST krb5-self * SSHFP;
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Dynamic update: FALSE
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Dynamic update: FALSE
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Allow query: any;
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Allow query: any;
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Allow transfer: none;
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Allow transfer: none;
[ipa.ipatests.test_integration.host.Host.master.cmd30]   Allow in-line DNSSEC signing: TRUE
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>:   Allow in-line DNSSEC signing: TRUE
[ipa.ipatests.test_integration.host.Host.master.cmd30] Exit code: 0
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.host.Host.master.cmd30] <DEBUG>: Exit code: 0
[ipa.ipatests.test_integration.base.IntegrationTest] Waiting for signed SOA record of example2.test. from server 192.168.137.101 (timeout 100 sec)
[2017-12-28T15:43:17Z ipa.ipatests.test_integration.base.IntegrationTest] <INFO>: Waiting for signed SOA record of example2.test. from server 192.168.137.101 (timeout 100 sec)
FAILED
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> traceback >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
self = <ipatests.test_integration.test_backup_and_restore.TestBackupAndRestoreWithDNSSEC object at 0x7f9bf9b3a490>
    def test_full_backup_and_restore_with_DNSSEC_zone(self):
        """backup, uninstall, restore"""
>       self._full_backup_and_restore_with_DNSSEC_zone(reinstall=False)
test_integration/test_backup_and_restore.py:336:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <ipatests.test_integration.test_backup_and_restore.TestBackupAndRestoreWithDNSSEC object at 0x7f9bf9b3a490>, reinstall = False
    def _full_backup_and_restore_with_DNSSEC_zone(self, reinstall=False):
        with restore_checker(self.master):
            self.master.run_command([
                'ipa', 'dnszone-add',
                self.example_test_zone,
                '--dnssec', 'true',
            ])
            assert wait_until_record_is_signed(self.master.ip,
                self.example_test_zone, self.log), "Zone is not signed"
            backup_path = backup(self.master)
            self.master.run_command(['ipa-server-install',
                                     '--uninstall',
                                     '-U'])
            if reinstall:
                tasks.install_master(self.master, setup_dns=True)
            dirman_password = self.master.config.dirman_password
            self.master.run_command(['ipa-restore', backup_path],
                                    stdin_text=dirman_password + '\nyes')
            assert wait_until_record_is_signed(self.master.ip,
                self.example_test_zone, self.log), ("Zone is not signed after "
                                                    "restore")
            tasks.kinit_admin(self.master)
            self.master.run_command([
                'ipa', 'dnszone-add',
                self.example2_test_zone,
                '--dnssec', 'true',
            ])
>           assert wait_until_record_is_signed(self.master.ip,
                self.example2_test_zone, self.log), "A new zone is not signed"
E           AssertionError: A new zone is not signed
E           assert False
E            +  where False = wait_until_record_is_signed('192.168.137.101', 'example2.test.', <logging.Logger object at 0x7f9c01ffbcd0>)
E            +    where '192.168.137.101' = <ipatests.test_integration.host.Host master.ipa.test (master)>.ip
E            +      where <ipatests.test_integration.host.Host master.ipa.test (master)> = <ipatests.test_integration.test_backup_and_restore.TestBackupAndRestoreWithDNSSEC object at 0x7f9bf9b3a490>.master
E            +    and   'example2.test.' = <ipatests.test_integration.test_backup_and_restore.TestBackupAndRestoreWithDNSSEC object at 0x7f9bf9b3a490>.example2_test_zone
E            +    and   <logging.Logger object at 0x7f9c01ffbcd0> = <ipatests.test_integration.test_backup_and_restore.TestBackupAndRestoreWithDNSSEC object at 0x7f9bf9b3a490>.log
test_integration/test_backup_and_restore.py:329: AssertionError
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> entering PDB >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
> /usr/lib/python2.7/site-packages/ipatests/test_integration/test_backup_and_restore.py(329)_full_backup_and_restore_with_DNSSEC_zone()
(Pdb) wait_until_record_is_signed(self.master.ip, self.example2_test_zone, self.log)
[ipa.ipatests.test_integration.base.IntegrationTest] Waiting for signed SOA record of example2.test. from server 192.168.137.101 (timeout 100 sec)
[2017-12-28T16:22:03Z ipa.ipatests.test_integration.base.IntegrationTest] <INFO>: Waiting for signed SOA record of example2.test. from server 192.168.137.101 (timeout 100 sec)
False
(Pdb) c
[ipa.ipatests.test_integration.host.Host.master.ParamikoTransport] RUN ['kinit', 'admin']
[2017-12-28T16:29:51Z ipa.ipatests.test_integration.host.Host.master.ParamikoTransport] <INFO>: RUN ['kinit', 'admin']
[ipa.ipatests.test_integration.host.Host.master.cmd31] RUN ['kinit', 'admin']
[2017-12-28T16:29:51Z ipa.ipatests.test_integration.host.Host.master.cmd31] <DEBUG>: RUN ['kinit', 'admin']
[ipa.ipatests.test_integration.host.Host.master.cmd31] Password for admin@IPA.TEST:

Steps to Reproduce

  1. IPATEST_YAML_CONFIG=/vagrant/ipa-test-config.yaml ipa-run-tests-2 test_integration/test_backup_and_restore.py::TestBackupAndRestoreWithDNSSEC

Actual behavior

Fails with the message above

Expected behavior

Should be green

Version/Release/Distribution

Git master (last commit 9400a4058d70958360167acc0b27f7554a45f74f)


Metadata Update from @fbarreto:
- Issue tagged with: test-failure

I wonder if https://github.com/freeipa/freeipa/pull/1289 would fix it.

I'll run the tests again with the PR 1289.

@pvoborni Is hard to tell at this time because we have a test blocker: ticket https://pagure.io/freeipa/issue/7343
Once that ticket is fixed, I'll run the tests again and share the results.

edit: Just to be clear, the ticket 7343 must be fixed first, then we'll be able to run the DNSSEC tests against PR 1289.

Using a personal instance of PR CI, I put test_backup_and_restore.py::TestBackupReinstallRestoreWithDNSSEC and
test_backup_and_restore.py::TestBackupAndRestoreWithDNSSEC to run against the PR 1289 [1]. Running them 3 times, they passed in all.
The result can be checked here [2].

[1] github.com/freeipa/freeipa/pull/1289
[2] https://github.com/felipevolpone/freeipa/pull/161

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

Metadata