stable/zed nova.tests.functional.wsgi.test_services.TestServicesAPI.test_resize_revert_after_deleted_source_compute sporadic failures

Bug #2017370 reported by Alexey Stupnikov
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
New
Undecided
Unassigned

Bug Description

A strange failure happens for one of my patches: nova.tests.functional.wsgi.test_services.TestServicesAPI.test_resize_revert_after_deleted_source_compute test fails because of OpenStackApiNotFoundException error.

Logs and traces are available at https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_ab9/870053/2/gate/nova-tox-functional-py38/ab97c5a/job-output.txt

2023-04-21 06:27:36.066489 | ubuntu-focal | Captured traceback:
2023-04-21 06:27:36.066493 | ubuntu-focal | ~~~~~~~~~~~~~~~~~~~
2023-04-21 06:27:36.066497 | ubuntu-focal | Traceback (most recent call last):
2023-04-21 06:27:36.066502 | ubuntu-focal |
2023-04-21 06:27:36.066506 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/wsgi/test_services.py", line 218, in test_resize_revert_after_deleted_source_compute
2023-04-21 06:27:36.066511 | ubuntu-focal | server = self._boot_and_check_allocations(flavor1, 'host1')
2023-04-21 06:27:36.066516 | ubuntu-focal |
2023-04-21 06:27:36.066520 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/integrated_helpers.py", line 932, in _boot_and_check_allocations
2023-04-21 06:27:36.066552 | ubuntu-focal | server = self._wait_for_state_change(created_server, 'ACTIVE')
2023-04-21 06:27:36.066556 | ubuntu-focal |
2023-04-21 06:27:36.066560 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/integrated_helpers.py", line 144, in _wait_for_state_change
2023-04-21 06:27:36.066564 | ubuntu-focal | return self._wait_for_server_parameter(
2023-04-21 06:27:36.066569 | ubuntu-focal |
2023-04-21 06:27:36.066573 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/integrated_helpers.py", line 130, in _wait_for_server_parameter
2023-04-21 06:27:36.066578 | ubuntu-focal | server = api.get_server(server['id'])
2023-04-21 06:27:36.066582 | ubuntu-focal |
2023-04-21 06:27:36.066586 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/api/client.py", line 248, in get_server
2023-04-21 06:27:36.066591 | ubuntu-focal | return self.api_get('/servers/%s' % server_id).body['server']
2023-04-21 06:27:36.066595 | ubuntu-focal |
2023-04-21 06:27:36.066599 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/api/client.py", line 205, in api_get
2023-04-21 06:27:36.066603 | ubuntu-focal | return APIResponse(self.api_request(relative_uri, **kwargs))
2023-04-21 06:27:36.066608 | ubuntu-focal |
2023-04-21 06:27:36.066612 | ubuntu-focal | File "/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/api/client.py", line 187, in api_request
2023-04-21 06:27:36.066616 | ubuntu-focal | raise OpenStackApiNotFoundException(response=response)
2023-04-21 06:27:36.066621 | ubuntu-focal |
2023-04-21 06:27:36.066625 | ubuntu-focal | nova.tests.functional.api.client.OpenStackApiNotFoundException: Item not found

In Nova logs I can see that hypervisor and instance itself simply disappeared after successfull startup, so nova-api returned 404:

2023-04-21 06:26:17.760125 | ubuntu-focal | 2023-04-21 06:26:14,598 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/servers/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 200 len: 1770 microversion: 2.93 time: 0.026509
2023-04-21 06:26:17.760129 | ubuntu-focal | 2023-04-21 06:26:14,683 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?in_tree=7cf25e47-3e14-4944-91ea-ee3c5377f440&limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1&root_required=%21COMPUTE_STATUS_DISABLED" status: 200 len: 793 microversion: 1.36
2023-04-21 06:26:17.760136 | ubuntu-focal | 2023-04-21 06:26:14,711 INFO [nova.scheduler.host_manager] Host filter forcing available hosts to host1
2023-04-21 06:26:17.760140 | ubuntu-focal | 2023-04-21 06:26:14,718 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 200 len: 19 microversion: 1.28
2023-04-21 06:26:17.760148 | ubuntu-focal | 2023-04-21 06:26:14,764 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 204 len: 0 microversion: 1.36
2023-04-21 06:26:17.760152 | ubuntu-focal | 2023-04-21 06:26:17,081 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/servers/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 200 len: 1787 microversion: 2.93 time: 0.504291
2023-04-21 06:26:17.760156 | ubuntu-focal | 2023-04-21 06:26:17,128 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 200 len: 230 microversion: 1.28
2023-04-21 06:26:17.760160 | ubuntu-focal | 2023-04-21 06:26:17,131 INFO [nova.compute.claims] Claim successful on node host1
2023-04-21 06:26:17.760167 | ubuntu-focal | 2023-04-21 06:26:17,169 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/7cf25e47-3e14-4944-91ea-ee3c5377f440/allocations" status: 200 len: 152 microversion: 1.0
2023-04-21 06:26:17.760171 | ubuntu-focal | 2023-04-21 06:26:17,176 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 200 len: 230 microversion: 1.28
2023-04-21 06:26:17.760175 | ubuntu-focal | 2023-04-21 06:26:17,260 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.
2023-04-21 06:26:17.760179 | ubuntu-focal | 2023-04-21 06:26:17,281 INFO [nova.compute.manager] Took 0.16 seconds to build instance.
2023-04-21 06:26:17.760183 | ubuntu-focal | 2023-04-21 06:26:17,331 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'host1'. Re-created its InstanceList.
2023-04-21 06:26:17.760187 | ubuntu-focal | 2023-04-21 06:26:17,592 INFO [nova.api.openstack.wsgi] HTTP exception thrown: Instance 6fe74316-77a0-4c99-826a-3c4b85613ee5 could not be found.
2023-04-21 06:26:17.760191 | ubuntu-focal | 2023-04-21 06:26:17,594 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/servers/6fe74316-77a0-4c99-826a-3c4b85613ee5" status: 404 len: 111 microversion: 2.93 time: 0.008478

Tags: testing
Revision history for this message
Alexey Stupnikov (astupnikov) wrote :

I took a look at history of nova-tox-functional-py38 tests for stable/zed and it looks like this failure is rare (I wasn't able to find same failures). At the same time it looks like clear race condition that deserves a second look.

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

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.