freeipa

#8838 Nightly test failure in test_integration/test_topology.py/TestTopologyOptions/test_add_remove_segment
Closed: insufficientinfo by frenaud. Opened by mpolovka.

Closed: insufficientinfo
Reopen Issue

Nightly test test_add_remove_segment is failing in [testing_ipa-4.9_latest_selinux] Nightly PR #886 with an error:

    def test_add_remove_segment(self):
        """
        Make sure a topology segment can be manually created and deleted
        with the influence on the real topology
        Testcase http://www.freeipa.org/page/V4/Manage_replication_topology/
        Test_plan#Test_case:_Basic_CRUD_test
        """
        tasks.kinit_admin(self.master)
        # Install the second replica
        tasks.install_replica(self.master, self.replicas[1], setup_ca=False,
                              setup_dns=False)
        # turn a star into a ring
        segment, err = tasks.create_segment(self.master,
                                            self.replicas[0],
                                            self.replicas[1])
        assert err == "", err
        # Make sure the new segment is shown by `ipa topologysegment-find`
        result1 = self.master.run_command(['ipa', 'topologysegment-find',
                                           DOMAIN_SUFFIX_NAME]).stdout_text
        assert(segment['name'] in result1), (
            "%s: segment not found" % segment['name'])
        # Remove master <-> replica2 segment and make sure that the changes get
        # there through replica1
        # Since segment name can be one of master-to-replica2 or
        # replica2-to-master, we need to determine the segment name dynamically
        deleteme = find_segment(self.master, self.replicas[1])
        returncode, error = tasks.destroy_segment(self.master, deleteme)
        assert returncode == 0, error
        # Wait till replication ends and make sure replica1 does not have
        # segment that was deleted on master
        master_ldap = self.master.ldap_connect()
        tasks.wait_for_replication(master_ldap)
        result3 = self.replicas[0].run_command(['ipa', 'topologysegment-find',
                                               DOMAIN_SUFFIX_NAME]).stdout_text
>       assert(deleteme not in result3), "%s: segment still exists" % deleteme
E       AssertionError: master.ipa.test-to-replica2.ipa.test: segment still exists
E       assert 'master.ipa....ca2.ipa.test' not in '-----------...----------\n'
E         'master.ipa.test-to-replica2.ipa.test' is contained here:
E           ------------------
E           2 segments matched
E           ------------------
E             Segment name: master.ipa.test-to-replica1.ipa.test
E             Left node: master.ipa.test
E             Right node: replica1.ipa.test...
E         
E         ...Full output truncated (10 lines hidden), use '-vv' to show
test_integration/test_topology.py:147: AssertionError
 ------------------------------Captured stderr call------------------------------ 
ipa: WARNING: ipa: ERROR: DNS zone with name "122.168.192.in-addr.arpa." already exists

This error looks very similar to #7865, but in my understanding, the cause is different.
Full logs

From the logs on the server, the segment-del is done and then the test checks the replication agreement (test code is waiting for replication to complete with a call to tasks.wait_for_replication(master_ldap)):

[07/May/2021:19:55:22.697336897 +0000] conn=338 op=3 DEL dn="cn=master.ipa.test-to-replica2.ipa.test,cn=domain,cn=topology,cn=ipa,cn=etc,dc=ipa,dc=test"
...
[07/May/2021:19:55:22.911769855 +0000] conn=339 op=2 SRCH base="cn=mapping tree,cn=config" scope=2 filter="(objectClass=nsds5replicationagreement)" attrs="nsds5replicaLastUpdateStatus nsds5replicaUpdateInProgress"
[07/May/2021:19:55:22.913080869 +0000] conn=339 op=2 RESULT err=0 tag=101 nentries=2 wtime=0.000200930 optime=0.001316657 etime=0.001514432

There is only one SRCH for the repl agreement, and I assume it means that the repl is done (otherwise the same SRCH would be seen multiple times in 1-sec delay loops).

On the replica1, the test retrieves the segments (httpd error_log):

[Fri May 07 19:56:14.125762 2021] [wsgi:error] [pid 21519:tid 21859] [remote 192.168.122.6:54930] ipa: INFO: [jsonserver_session] admin@IPA.TEST: topologysegment_find/1('domain', None, version='2.241'): SUCCESS

Corresponding to dirsrv access log:

[07/May/2021:19:56:14.122572181 +0000] conn=39 op=2 SRCH base="cn=domain,cn=topology,cn=ipa,cn=etc,dc=ipa,dc=test" scope=1 filter="(objectClass=iparepltoposegment)" attrs="ipaReplTopoSegmentLeftNode ipaReplTopoSegmentDirection ipaReplTopoSegmentRightNode cn"
[07/May/2021:19:56:14.123870851 +0000] conn=39 op=2 RESULT err=0 tag=101 nentries=2 wtime=0.000072260 optime=0.001301189 etime=0.001370860
...
[07/May/2021:19:56:14.806694869 +0000] conn=31 op=166 ADD dn="cn=replica1.ipa.test-to-replica2.ipa.test,cn=domain,cn=topology,cn=ipa,cn=etc,dc=ipa,dc=test"
...
[07/May/2021:19:56:14.896942199 +0000] conn=31 op=167 DEL dn="cn=master.ipa.test-to-replica2.ipa.test,cn=domain,cn=topology,cn=ipa,cn=etc,dc=ipa,dc=test"

So it looks like the test tries to read the topo segments on replica1 before they have been replicated, even though the call to wait_for_replication returned. The function wait_for_replication logs at debug level only and the traces aren't visible in the runner log, meaning I can only assume that 389ds believes the replication is done.

Let's wait for next run and see if the issue happens again.

The issue didn't happen anymore, closing for now.

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

test-failure tests

None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.