Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 2109862

Summary: Floating IP assignment after volume snapshot might be slow
Product: Red Hat OpenStack Reporter: Filip Hubík <fhubik>
Component: openstack-tempestAssignee: Chandan Kumar <chkumar>
Status: CLOSED ERRATA QA Contact: Martin Kopec <mkopec>
Severity: high Docs Contact:
Priority: high    
Version: 17.0 (Wallaby)CC: alifshit, apevec, dasmith, eglynn, jhakimra, jschluet, kchamart, lhh, sbauza, sgordon, slinaber, spower, udesale, vromanso
Target Milestone: gaKeywords: TestBlocker, Triaged
Target Release: 17.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: openstack-tempest-31.1.0-0.20220719160756.56d259d.el9ost Doc Type: No Doc Update
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2022-09-21 12:24:19 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
logs.allnodes.failure none

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