← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 2017370] [NEW] stable/zed nova.tests.functional.wsgi.test_services.TestServicesAPI.test_resize_revert_after_deleted_source_compute sporadic failures

 

Public bug reported:

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

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: testing

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/2017370

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

Status in OpenStack Compute (nova):
  New

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

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/2017370/+subscriptions