check_floating_ip_status utility method can have confusing output

Bug #1788416 reported by Matt Riedemann on 2018-08-22
This bug affects 1 person
Affects Status Importance Assigned to Milestone

Bug Description

I noticed this while debugging an ssh failure in a test:

2018-08-21 23:20:11.728946 | controller | Body: {"floatingip": {"router_id": "188eb35a-1270-4536-a02a-92f9ec031c7a", "status": "ACTIVE", "description": "", "tags": [], "tenant_id": "38bf4237efd54095959153ffc2227946", "created_at": "2018-08-21T23:17:10Z", "updated_at": "2018-08-21T23:17:13Z", "floating_network_id": "0fd1d892-0aa3-4c0c-818f-44f1c9a9b569", "port_details": {"status": "ACTIVE", "name": "", "admin_state_up": true, "network_id": "6c9a79d8-b508-4a97-a15d-bf4acee8b4a8", "device_owner": "compute:nova", "mac_address": "fa:16:3e:2b:a9:39", "device_id": "015f755f-2779-4613-9b28-9bc377056fe2"}, "fixed_ip_address": "", "floating_ip_address": "", "revision_number": 1, "project_id": "38bf4237efd54095959153ffc2227946", "port_id": "b835ff51-0262-4237-ab52-7b08206bd099", "id": "ac394112-d245-461b-b660-00cab7c1b51a"}}
2018-08-21 23:20:11.729248 | controller | 2018-08-21 23:17:58,661 9451 DEBUG [tempest.lib.common.utils.test_utils] Call refresh returns true in 0.103947 seconds
2018-08-21 23:20:11.731057 | controller | 2018-08-21 23:17:58,661 9451 INFO [tempest.scenario.manager] FloatingIP: {u'router_id': u'188eb35a-1270-4536-a02a-92f9ec031c7a', u'description': u'', u'tags': [], u'status': u'DOWN', u'tenant_id': u'38bf4237efd54095959153ffc2227946', u'created_at': u'2018-08-21T23:17:10Z', u'updated_at': u'2018-08-21T23:17:10Z', u'floating_network_id': u'0fd1d892-0aa3-4c0c-818f-44f1c9a9b569', u'fixed_ip_address': u'', u'port_details': {u'status': u'ACTIVE', u'name': u'', u'admin_state_up': True, u'network_id': u'6c9a79d8-b508-4a97-a15d-bf4acee8b4a8', u'device_owner': u'compute:nova', u'mac_address': u'fa:16:3e:2b:a9:39', u'device_id': u'015f755f-2779-4613-9b28-9bc377056fe2'}, u'floating_ip_address': u'', u'revision_number': 0, u'project_id': u'38bf4237efd54095959153ffc2227946', u'id': u'ac394112-d245-461b-b660-00cab7c1b51a', u'port_id': u'b835ff51-0262-4237-ab52-7b08206bd099'} is at status: ACTIVE

Note that the floatingip response body at the top shows the floatingip as active, but the message at the bottom shows the status is down, but the message says "is at status: ACTIVE". This is because the check_floating_ip_status method is printing out the original floating_ip variable state rather than the latest (which is from the top from the refresh() method):

    def check_floating_ip_status(self, floating_ip, status):
        """Verifies floatingip reaches the given status

        :param dict floating_ip: floating IP dict to check status
        :param status: target status
        :raises: AssertionError if status doesn't match
        floatingip_id = floating_ip['id']

        def refresh():
            result = (self.floating_ips_client.
            return status == result['status']

        if not test_utils.call_until_true(refresh,
            floating_ip = self.floating_ips_client.show_floatingip(
            self.assertEqual(status, floating_ip['status'],
                             message="FloatingIP: {fp} is at status: {cst}. "
                                     "failed to reach status: {st}"
                             .format(fp=floating_ip, cst=floating_ip['status'],
                                     st=status))"FloatingIP: {fp} is at status: {st}"
                 .format(fp=floating_ip, st=status))

I suspect the refresh() method should overwrite the floating_ip variable.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers