Bug 2109862 - Floating IP assignment after volume snapshot might be slow
Summary: Floating IP assignment after volume snapshot might be slow
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-tempest
Version: 17.0 (Wallaby)
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ga
: 17.0
Assignee: Chandan Kumar
QA Contact: Martin Kopec
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-07-22 11:23 UTC by Filip Hubík
Modified: 2022-09-21 12:24 UTC (History)
14 users (show)

Fixed In Version: openstack-tempest-31.1.0-0.20220719160756.56d259d.el9ost
Doc Type: No Doc Update
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-09-21 12:24:19 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
logs.allnodes.failure (326.43 KB, application/gzip)
2022-07-22 11:26 UTC, Filip Hubík
no flags Details


Links
System ID Private Priority Status Summary Last Updated
OpenStack gerrit 849562 0 None master: MERGED tempest: Wait for floating IP assocation in test_minimum_basic test (I05e079237aec332925a88476e45071b34dc722c6) 2022-08-04 15:36:58 UTC
Red Hat Issue Tracker OSP-17808 0 None None None 2022-07-22 11:26:19 UTC
Red Hat Product Errata RHEA-2022:6543 0 None None None 2022-09-21 12:24:40 UTC

Description Filip Hubík 2022-07-22 11:23:42 UTC
Description of problem:
tempest.scenario.test_minimum_basic.TestMinimumBasicScenario.test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion test shows possible issue with a floating IP assignment.

The nature of the test is following: https://github.com/openstack/tempest/blob/master/tempest/scenario/test_minimum_basic.py#L238 in detail, especially the part after #238:

address = self._get_floating_ip_in_server_addresses(
    floating_ip, server)
self.assertIsNotNone(
    address,
    "Failed to find floating IP '%s' in server addresses: %s" %
    (floating_ip['floating_ip_address'], server['addresses']))

Tempest test creates volume and performs snapshot, then assigns floating IP to the server, then checks for the "OS-EXT-IPS:type": "floating" record in server's description, but finds none. Though seconds later the floating IP seems to be available and assigned to the server.

Version-Release number of selected component (if applicable):
OSP17 on RHEL9
happens since RHOS-17.0-RHEL-9-20220718.n.1
also reproduced on RHOS-17.0-RHEL-9-20220721.n.1 so far

How reproducible:
Sporadically, maybe a race condition between tempest, nova and neutron?

Additional info:
I managed to isolate logs from all OC nodes during the example testfailure, attached.

Comment 1 Filip Hubík 2022-07-22 11:26:46 UTC
Created attachment 1898709 [details]
logs.allnodes.failure

Logs from all OC nodes gathered solely during the described failure

Comment 3 Filip Hubík 2022-07-22 11:38:55 UTC
Also note this issue is not isolated to specific topology, it happens on various deployments from 1:1:1 to 3:2:3 .

Comment 4 Filip Hubík 2022-07-22 11:49:15 UTC
Here are also the timing details:

Example of a passing run:

2022-07-22 11:40:10,414 340833 INFO     [tempest.lib.common.rest_client] Request (TestMinimumBasicScenario:test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion): 201 POST http://10.0.0.146:9696/v2.0/floatingips 1.768s
...
2022-07-22 11:40:11,584 340833 INFO     [tempest.lib.common.rest_client] Request (TestMinimumBasicScenario:test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion): 200 PUT http://10.0.0.146:9696/v2.0/floatingips/6f838070-d970-4a78-b57c-0eeb213b7c39 1.090s
2022-07-22 11:40:11,793 340833 INFO     [tempest.lib.common.rest_client] Request (TestMinimumBasicScenario:test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion): 200 GET http://10.0.0.146:8774/v2.1/servers/b24e5802-cfcc-41d3-9541-ec6a3663e08e 0.207s
2022-07-22 11:40:11,793 340833 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.1', 'X-Au^A0NÜ<97>^U³/àQ^ObÚ<8c>Ãß°u^P.test_minimum_basic.TestMinimumBasicScenario.test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion[compute,id-a8fd48ec-1d01-4895-b932-02321661ec1e,image,network,volume]^A^Hworker-0^Ztext/plain; charset="utf8"^Ppythonlogging:''P^@th-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Fri, 22 Jul 2022 11:40:11 GMT', 'server': 'Apache', 'content-length': '1757', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-e79d0a61-a63b-4f6a-b581-8ae0005050b9', 'x-compute-request-id': 'req-e79d0a61-a63b-4f6a-b581-8ae0005050b9', 'content-type': 'application/json', 'connection': 'close', 'status': '200', 'content-location': 'http://10.0.0.146:8774/v2.1/servers/b24e5802-cfcc-41d3-9541-ec6a3663e08e'}
        Body: b'{"server": {"id": "b24e5802-cfcc-41d3-9541-ec6a3663e08e", "name": "tempest-TestMinimumBasicScenario-server-724787694", "status": "ACTIVE", "tenant_id": "baaee9fde6bd4fa5b270546d4b764032", "user_id": "b9b2fc0576c24638b633a2c37d66bd8e", "metadata": {}, "hostId": "c56a872752a0df46bb2241c492ffe4fb481b8ba8d873bfb8c4e0a62e", "image": {"id": "8dc18d7f-7609-437d-9afa-c2e085e38fc2", "links": [{"rel": "bookmark", "href": "http://10.0.0.146:8774/images/8dc18d7f-7609-437d-9afa-c2e085e38fc2"}]}, "flavor": {"id": "21bc9a7d-c339-4493-a896-f0f463d660b3", "links": [{"rel": "bookmark", "href": "http://10.0.0.146:8774/flavors/21bc9a7d-c339-4493-a896-f0f463d660b3"}]}, "created": "2022-07-22T11:39:52Z", "updated": "2022-07-22T11:39:59Z", "addresses": {"tempest-TestMinimumBasicScenario-1285079463-network": [{"version": 4, "addr": "10.100.0.6", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:d8:e6:10"}, {"version": 4, "addr": "10.0.0.203", "OS-EXT-IPS:type": "floating", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:d8:e6:10"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.146:8774/v2.1/servers/b24e5802-cfcc-41d3-9541-ec6a3663e08e"}, {"rel": "bookmark", "href": "http://10.0.0.146:8774/servers/b24e5802-cfcc-41d3-9541-ec6a3663e08e"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": "tempest-TestMinimumBasicScenario-1610602698", "OS-SRV-USG:launched_at": "2022-07-22T11:39:59.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": null, "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "b7d2b3c1-223e-43e2-9d0b-ae56bcc78ce1"}]}}'


Where "OS-EXT-IPS:type": "floating" is available ~1.7s after the POST request.

Failing run:

2022-07-21 20:36:24,023 147347 INFO     [tempest.lib.common.rest_client] Request (TestMinimumBasicScenario:test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion): 201 POST http://10.0.0.149:9696/v2.0/floatingips 2.422s
...
2022-07-21 20:36:25,522 147347 INFO     [tempest.lib.common.rest_client] Request (TestMinimumBasicScenario:test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion): 200 PUT http://10.0.0.149:9696/v2.0/floatingips/ea9de5da-3220-43aa-a896-3d0b792d3289 1.410s
(TestMinimumBasicScenario:test_minimum_basic_instance_hard_reboot_after_vol_snap_deletion): 200 GET http://10.0.0.149:8774/v2.1/servers/d54cd9ed-5cc1-4046-a3d0-fadfc7960707 0.413s
2022-07-21 20:36:25,936 147347 DEBUG    [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.1', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Thu, 21 Jul 2022 20:36:25 GMT', 'server': 'Apache', 'content-length': '1638', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version,Accept-Encoding', 'x-openstack-request-id': 'req-4b03e8b0-6523-4734-83fe-70e502a4796a', 'x-compute-request-id': 'req-4b03e8b0-6523-4734-83fe-70e502a4796a', 'content-type': 'application/json', 'connection': 'close', 'status': '200', 'content-location': 'http://10.0.0.149:8774/v2.1/servers/d54cd9ed-5cc1-4046-a3d0-fadfc7960707'}
        Body: b'{"server": {"id": "d54cd9ed-5cc1-4046-a3d0-fadfc7960707", "name": "tempest-TestMinimumBasicScenario-server-483554465", "status": "ACTIVE", "tenant_id": "9233e1102bcc4329b6846f1f8fe66b3b", "user_id": "e905d2f64d3741c49213992a29c5bbfc", "metadata": {}, "hostId": "4fabc35697ab9baebcacdfcba723b8f25a0e929681fb7e6c1283b076", "image": {"id": "f5d0c845-03bb-420a-86fe-82989a1aa0a7", "links": [{"rel": "bookmark", "href": "http://10.0.0.149:8774/images/f5d0c845-03bb-420a-86fe-82989a1aa0a7"}]}, "flavor": {"id": "b5b32a01-257f-4441-b2e9-d7d37f550780", "links": [{"rel": "bookmark", "href": "http://10.0.0.149:8774/flavors/b5b32a01-257f-4441-b2e9-d7d37f550780"}]}, "created": "2022-07-21T20:36:01Z", "updated": "2022-07-21T20:36:11Z", "addresses": {"tempest-TestMinimumBasicScenario-171981277-network": [{"version": 4, "addr": "10.100.0.8", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:51:c8:61"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://10.0.0.149:8774/v2.1/servers/d54cd9ed-5cc1-4046-a3d0-fadfc7960707"}, {"rel": "bookmark", "href": "http://10.0.0.149:8774/servers/d54cd9ed-5cc1-4046-a3d0-fadfc7960707"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "nova", "config_drive": "", "key_name": "tempest-TestMinimumBasicScenario-393939333", "OS-SRV-USG:launched_at": "2022-07-21T20:36:11.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-STS:task_state": null, "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": [{"id": "4541c346-7a2d-4da4-8b69-08eaeaea9878"}]}}'


Where "OS-EXT-IPS:type": "floating" is still missing ~1.5 second after POST request.

Comment 5 Filip Hubík 2022-07-22 11:52:15 UTC
Also, there might be possibly similar issue upstream? https://bugs.launchpad.net/tripleo/+bug/1980255 .

Comment 10 spower 2022-08-09 11:25:34 UTC
TRAC have moved this to GA blocker but not a Beta blocker.

Comment 11 Martin Kopec 2022-08-16 13:19:32 UTC
The fix (https://review.opendev.org/c/openstack/tempest/+/849562/) is part of the 'Fixed In Version' package and it is available in openstack-tempest package since RHOS-17.0-RHEL-9-20220811.n.0 (and newer ones). Marking this as VERIFIED.

Comment 16 errata-xmlrpc 2022-09-21 12:24:19 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Release of components for Red Hat OpenStack Platform 17.0 (Wallaby)), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2022:6543


Note You need to log in before you can comment on or make changes to this bug.