** Also affects: nova/train
Importance: Undecided
Status: New
** Changed in: nova/train
Status: New => Confirmed
** Changed in: nova/train
Importance: Undecided => Medium
--
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/1850514
Title:
ReshapeForPCPUsTest.test_vcpu_to_pcpu_reshape intermittently fails
with "Cannot 'migrate' instance while it is in vm_state building"
Status in OpenStack Compute (nova):
In Progress
Status in OpenStack Compute (nova) train series:
Confirmed
Bug description:
Seen here:
https://storage.gra1.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_f05/691390/6/check
/nova-tox-functional/f059dc0/testr_results.html.gz
ft1.1:
nova.tests.functional.libvirt.test_numa_servers.ReshapeForPCPUsTest.test_vcpu_to_pcpu_reshapetesttools.testresult.real._StringException:
pythonlogging:'': {{{
2019-10-29 17:33:28,372 WARNING [placement.db_api] TransactionFactory already
started, not reconfiguring.
2019-10-29 17:33:28,423 INFO [nova.service] Starting conductor node (version
20.1.0)
2019-10-29 17:33:28,478 INFO [nova.service] Starting scheduler node (version
20.1.0)
2019-10-29 17:33:29,023 INFO [nova.virt.driver] Loading compute driver
'libvirt.LibvirtDriver'
2019-10-29 17:33:29,026 WARNING [os_brick.initiator.connectors.remotefs]
Connection details not present. RemoteFsClient may not initialize properly.
2019-10-29 17:33:29,028 INFO [nova.service] Starting compute node (version
20.1.0)
2019-10-29 17:33:29,030 WARNING [nova.virt.libvirt.driver] The 'vcpu_pin_set'
config option has been deprecated and will be removed in a future release. When
defined, 'vcpu_pin_set' will be used to calculate 'VCPU' inventory and schedule
instances that have 'VCPU' allocations. If you wish to define specific host
CPUs to be used for 'VCPU' or 'PCPU' inventory, you must migrate the
'vcpu_pin_set' config option value to '[compute] cpu_shared_set' and '[compute]
cpu_dedicated_set', respectively, and undefine 'vcpu_pin_set'.
2019-10-29 17:33:29,038 WARNING [nova.virt.libvirt.driver] my_ip address
(38.108.68.36) was not found on any of the interfaces:
2019-10-29 17:33:29,039 WARNING [nova.virt.libvirt.driver] Running Nova with
a libvirt version less than 4.0.0 is deprecated. The required minimum version
of libvirt will be raised to 4.0.0 in the next release.
2019-10-29 17:33:29,039 WARNING [nova.virt.libvirt.driver] Running Nova with
a QEMU version less than 2.11.0 is deprecated. The required minimum version of
QEMU will be raised to 2.11.0 in the next release.
2019-10-29 17:33:29,059 WARNING [nova.compute.manager] Compute node
test_compute0 not found in the database. If this is the first time this service
is starting on this host, then you can ignore this warning.
2019-10-29 17:33:29,066 INFO [nova.compute.manager] Looking for unclaimed
instances stuck in BUILDING status for nodes managed by this host
2019-10-29 17:33:29,081 WARNING [nova.compute.manager] No compute node record
found for host test_compute0. If this is the first time this service is
starting on this host, then you can ignore this warning.
2019-10-29 17:33:29,094 WARNING [nova.compute.resource_tracker] No compute
node record for test_compute0:test_compute0
2019-10-29 17:33:29,101 INFO [nova.compute.resource_tracker] Compute node
record created for test_compute0:test_compute0 with uuid:
cada8f90-3f3d-4f22-8312-770a0a818828
2019-10-29 17:33:29,179 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?in_tree=cada8f90-3f3d-4f22-8312-770a0a818828"
status: 200 len: 26 microversion: 1.14
2019-10-29 17:33:29,192 INFO [placement.requestlog] 127.0.0.1 "POST
/placement/resource_providers" status: 200 len: 836 microversion: 1.20
2019-10-29 17:33:29,193 INFO [nova.scheduler.client.report]
[req-3fabe3ee-b8f4-4d5e-9c62-185c0ae18c74] Created resource provider record via
placement API for resource provider with UUID
cada8f90-3f3d-4f22-8312-770a0a818828 and name test_compute0.
2019-10-29 17:33:29,195 INFO [nova.virt.libvirt.host] kernel doesn't support
AMD SEV
2019-10-29 17:33:29,227 INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/cada8f90-3f3d-4f22-8312-770a0a818828/inventories"
status: 200 len: 405 microversion: 1.26
2019-10-29 17:33:29,241 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/traits?name=in:COMPUTE_IMAGE_TYPE_ARI,COMPUTE_IMAGE_TYPE_AKI,COMPUTE_VOLUME_EXTEND,COMPUTE_IMAGE_TYPE_AMI,COMPUTE_IMAGE_TYPE_RAW,HW_CPU_X86_VMX,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_VOLUME_MULTI_ATTACH,HW_CPU_X86_AESNI,HW_CPU_HYPERTHREADING,COMPUTE_IMAGE_TYPE_QCOW2,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_IMAGE_TYPE_ISO,COMPUTE_TRUSTED_CERTS,COMPUTE_DEVICE_TAGGING"
status: 200 len: 447 microversion: 1.6
2019-10-29 17:33:29,266 INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/cada8f90-3f3d-4f22-8312-770a0a818828/traits"
status: 200 len: 482 microversion: 1.6
2019-10-29 17:33:29,284 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?name=test_compute0" status: 200 len: 440
microversion: 1.0
2019-10-29 17:33:29,328 INFO [nova.virt.driver] Loading compute driver
'libvirt.LibvirtDriver'
2019-10-29 17:33:29,332 WARNING [os_brick.initiator.connectors.remotefs]
Connection details not present. RemoteFsClient may not initialize properly.
2019-10-29 17:33:29,334 INFO [nova.service] Starting compute node (version
20.1.0)
2019-10-29 17:33:29,336 WARNING [nova.virt.libvirt.driver] The 'vcpu_pin_set'
config option has been deprecated and will be removed in a future release. When
defined, 'vcpu_pin_set' will be used to calculate 'VCPU' inventory and schedule
instances that have 'VCPU' allocations. If you wish to define specific host
CPUs to be used for 'VCPU' or 'PCPU' inventory, you must migrate the
'vcpu_pin_set' config option value to '[compute] cpu_shared_set' and '[compute]
cpu_dedicated_set', respectively, and undefine 'vcpu_pin_set'.
2019-10-29 17:33:29,342 WARNING [nova.virt.libvirt.driver] my_ip address
(38.108.68.36) was not found on any of the interfaces:
2019-10-29 17:33:29,343 WARNING [nova.virt.libvirt.driver] Running Nova with
a libvirt version less than 4.0.0 is deprecated. The required minimum version
of libvirt will be raised to 4.0.0 in the next release.
2019-10-29 17:33:29,343 WARNING [nova.virt.libvirt.driver] Running Nova with
a QEMU version less than 2.11.0 is deprecated. The required minimum version of
QEMU will be raised to 2.11.0 in the next release.
2019-10-29 17:33:29,363 WARNING [nova.compute.manager] Compute node
test_compute1 not found in the database. If this is the first time this service
is starting on this host, then you can ignore this warning.
2019-10-29 17:33:29,368 INFO [nova.compute.manager] Looking for unclaimed
instances stuck in BUILDING status for nodes managed by this host
2019-10-29 17:33:29,388 WARNING [nova.compute.manager] No compute node record
found for host test_compute1. If this is the first time this service is
starting on this host, then you can ignore this warning.
2019-10-29 17:33:29,397 WARNING [nova.compute.resource_tracker] No compute
node record for test_compute1:test_compute1
2019-10-29 17:33:29,401 INFO [nova.compute.resource_tracker] Compute node
record created for test_compute1:test_compute1 with uuid:
3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7
2019-10-29 17:33:29,466 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?in_tree=3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7"
status: 200 len: 26 microversion: 1.14
2019-10-29 17:33:29,479 INFO [placement.requestlog] 127.0.0.1 "POST
/placement/resource_providers" status: 200 len: 836 microversion: 1.20
2019-10-29 17:33:29,480 INFO [nova.scheduler.client.report]
[req-3f530fdb-07b5-42e6-b147-968b7df51b8d] Created resource provider record via
placement API for resource provider with UUID
3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7 and name test_compute1.
2019-10-29 17:33:29,481 INFO [nova.virt.libvirt.host] kernel doesn't support
AMD SEV
2019-10-29 17:33:29,506 INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7/inventories"
status: 200 len: 405 microversion: 1.26
2019-10-29 17:33:29,518 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/traits?name=in:COMPUTE_IMAGE_TYPE_ARI,COMPUTE_IMAGE_TYPE_AKI,COMPUTE_VOLUME_EXTEND,COMPUTE_IMAGE_TYPE_AMI,COMPUTE_IMAGE_TYPE_RAW,HW_CPU_X86_VMX,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_VOLUME_MULTI_ATTACH,HW_CPU_X86_AESNI,HW_CPU_HYPERTHREADING,COMPUTE_IMAGE_TYPE_QCOW2,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_IMAGE_TYPE_ISO,COMPUTE_TRUSTED_CERTS,COMPUTE_DEVICE_TAGGING"
status: 200 len: 447 microversion: 1.6
2019-10-29 17:33:29,543 INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7/traits"
status: 200 len: 482 microversion: 1.6
2019-10-29 17:33:29,556 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?name=test_compute1" status: 200 len: 440
microversion: 1.0
2019-10-29 17:33:29,567 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers/3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7/inventories"
status: 200 len: 405 microversion: 1.0
2019-10-29 17:33:29,578 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers/cada8f90-3f3d-4f22-8312-770a0a818828/inventories"
status: 200 len: 405 microversion: 1.0
2019-10-29 17:33:29,582 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1" status: 204 len: 0 microversion: - time: 0.001150
2019-10-29 17:33:29,737 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/6f70656e737461636b20342065766572/flavors/detail" status: 200 len: 3007
microversion: 2.74 time: 0.150618
2019-10-29 17:33:29,774 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST
/v2.1/6f70656e737461636b20342065766572/flavors" status: 200 len: 533
microversion: 2.74 time: 0.032605
2019-10-29 17:33:29,804 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST
/v2.1/6f70656e737461636b20342065766572/flavors/11878059/os-extra_specs" status:
200 len: 47 microversion: 2.74 time: 0.026474
2019-10-29 17:33:29,811 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/6f70656e737461636b20342065766572/images/detail" status: 200 len: 5635
microversion: 2.35 time: 0.003158
2019-10-29 17:33:29,827 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/6f70656e737461636b20342065766572/flavors/11878059" status: 200 len: 561
microversion: 2.74 time: 0.011782
2019-10-29 17:33:29,945 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/6f70656e737461636b20342065766572/servers/detail" status: 200 len: 15
microversion: 2.74 time: 0.114258
2019-10-29 17:33:30,178 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocation_candidates?in_tree=cada8f90-3f3d-4f22-8312-770a0a818828&limit=1000&required=%21COMPUTE_STATUS_DISABLED&resources=DISK_GB%3A20%2CMEMORY_MB%3A2048%2CPCPU%3A2"
status: 200 len: 53 microversion: 1.32
2019-10-29 17:33:30,255 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocation_candidates?in_tree=cada8f90-3f3d-4f22-8312-770a0a818828&limit=1000&required=%21COMPUTE_STATUS_DISABLED&resources=DISK_GB%3A20%2CMEMORY_MB%3A2048%2CVCPU%3A2"
status: 200 len: 893 microversion: 1.32
2019-10-29 17:33:30,298 INFO [nova.scheduler.host_manager] Host filter only
checking host test_compute0 and node test_compute0
2019-10-29 17:33:30,304 INFO [nova.virt.hardware] Computed NUMA topology CPU
pinning: usable pCPUs: [[0, 1], [2, 3]], vCPUs mapping: [(0, 0), (1, 1)]
2019-10-29 17:33:30,316 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/1dbe015f-9d41-40fe-a556-7fa17b9927e3" status: 200 len:
19 microversion: 1.28
2019-10-29 17:33:30,350 INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/allocations/1dbe015f-9d41-40fe-a556-7fa17b9927e3" status: 204 len: 0
microversion: 1.32
2019-10-29 17:33:30,353 INFO [nova.virt.hardware] Computed NUMA topology CPU
pinning: usable pCPUs: [[0, 1], [2, 3]], vCPUs mapping: [(0, 0), (1, 1)]
2019-10-29 17:33:30,491 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST
/v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 478
microversion: 2.74 time: 0.541017
2019-10-29 17:33:30,616 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/1dbe015f-9d41-40fe-a556-7fa17b9927e3" status: 200 len:
232 microversion: 1.28
2019-10-29 17:33:30,618 ERROR [nova.virt.libvirt.host] Hostname has changed
from test_compute0 to test_compute1. A restart is required to take effect.
2019-10-29 17:33:30,644 INFO [nova.virt.hardware] Computed NUMA topology CPU
pinning: usable pCPUs: [[0, 1], [2, 3]], vCPUs mapping: [(0, 0), (1, 1)]
2019-10-29 17:33:30,644 INFO [nova.compute.claims] Claim successful on node
test_compute0
2019-10-29 17:33:30,722 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/6f70656e737461636b20342065766572/servers/1dbe015f-9d41-40fe-a556-7fa17b9927e3"
status: 200 len: 1944 microversion: 2.74 time: 0.227641
2019-10-29 17:33:31,300 INFO [nova.virt.libvirt.driver] Instance spawned
successfully.
2019-10-29 17:33:31,303 INFO [nova.compute.manager] Took 0.17 seconds to
spawn the instance on the hypervisor.
2019-10-29 17:33:31,450 INFO [nova.scheduler.host_manager] Received an update
from an unknown host 'test_compute0'. Re-created its InstanceList.
2019-10-29 17:33:31,457 INFO [nova.compute.manager] Took 0.90 seconds to
build instance.
2019-10-29 17:33:31,600 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocation_candidates?in_tree=cada8f90-3f3d-4f22-8312-770a0a818828&limit=1000&required=%21COMPUTE_STATUS_DISABLED&resources=DISK_GB%3A20%2CMEMORY_MB%3A2048%2CPCPU%3A2"
status: 200 len: 53 microversion: 1.32
2019-10-29 17:33:31,678 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocation_candidates?in_tree=cada8f90-3f3d-4f22-8312-770a0a818828&limit=1000&required=%21COMPUTE_STATUS_DISABLED&resources=DISK_GB%3A20%2CMEMORY_MB%3A2048%2CVCPU%3A2"
status: 200 len: 897 microversion: 1.32
2019-10-29 17:33:31,708 INFO [nova.scheduler.host_manager] Host filter only
checking host test_compute0 and node test_compute0
2019-10-29 17:33:31,720 INFO [nova.virt.hardware] Computed NUMA topology CPU
pinning: usable pCPUs: [[2, 3]], vCPUs mapping: [(0, 2), (1, 3)]
2019-10-29 17:33:31,748 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/15246707-924c-4d39-b746-4499ec174f90" status: 200 len:
19 microversion: 1.28
2019-10-29 17:33:31,806 INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/allocations/15246707-924c-4d39-b746-4499ec174f90" status: 204 len: 0
microversion: 1.32
2019-10-29 17:33:31,811 INFO [nova.virt.hardware] Computed NUMA topology CPU
pinning: usable pCPUs: [[2, 3]], vCPUs mapping: [(0, 2), (1, 3)]
2019-10-29 17:33:32,050 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST
/v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 478
microversion: 2.74 time: 1.322930
2019-10-29 17:33:32,229 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/15246707-924c-4d39-b746-4499ec174f90" status: 200 len:
232 microversion: 1.28
2019-10-29 17:33:32,232 ERROR [nova.virt.libvirt.host] Hostname has changed
from test_compute0 to test_compute1. A restart is required to take effect.
2019-10-29 17:33:32,248 INFO [nova.virt.hardware] Computed NUMA topology CPU
pinning: usable pCPUs: [[2, 3]], vCPUs mapping: [(0, 2), (1, 3)]
2019-10-29 17:33:32,248 INFO [nova.compute.claims] Claim successful on node
test_compute0
2019-10-29 17:33:32,312 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/6f70656e737461636b20342065766572/servers/15246707-924c-4d39-b746-4499ec174f90"
status: 200 len: 1944 microversion: 2.74 time: 0.255498
2019-10-29 17:33:32,365 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers/cada8f90-3f3d-4f22-8312-770a0a818828/inventories"
status: 200 len: 405 microversion: 1.0
2019-10-29 17:33:32,438 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers/cada8f90-3f3d-4f22-8312-770a0a818828/usages"
status: 200 len: 92 microversion: 1.0
2019-10-29 17:33:32,489 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers/3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7/inventories"
status: 200 len: 405 microversion: 1.0
2019-10-29 17:33:32,562 INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers/3b8479be-2d4d-4ccc-8f31-c7bc31e4b8e7/usages"
status: 200 len: 88 microversion: 1.0
2019-10-29 17:33:33,382 INFO [nova.api.openstack.wsgi] HTTP exception thrown:
Cannot 'migrate' instance 15246707-924c-4d39-b746-4499ec174f90 while it is in
vm_state building
2019-10-29 17:33:33,385 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST
/v2.1/6f70656e737461636b20342065766572/servers/15246707-924c-4d39-b746-4499ec174f90/action"
status: 409 len: 147 microversion: 2.74 time: 0.158307
2019-10-29 17:33:33,397 INFO [nova.virt.libvirt.driver] Instance spawned
successfully.
2019-10-29 17:33:33,398 INFO [nova.compute.manager] Took 0.15 seconds to
spawn the instance on the hypervisor.
2019-10-29 17:33:33,538 INFO [nova.compute.manager] Took 1.42 seconds to
build instance.
2019-10-29 17:33:33,630 INFO [oslo_db.sqlalchemy.provision] DROP ALL OBJECTS,
BACKEND sqlite://
2019-10-29 17:33:33,659 INFO [oslo_db.sqlalchemy.provision] DISPOSE ENGINE
Engine(sqlite://)
}}}
Traceback (most recent call last):
File "nova/tests/functional/libvirt/test_numa_servers.py", line 625, in
test_vcpu_to_pcpu_reshape
self.api.post_server_action(server2['id'], post)
File "nova/tests/functional/api/client.py", line 294, in post_server_action
'/servers/%s/action' % server_id, data, **kwargs).body
File "nova/tests/functional/api/client.py", line 235, in api_post
return APIResponse(self.api_request(relative_uri, **kwargs))
File "nova/tests/functional/api/client.py", line 213, in api_request
response=response)
nova.tests.functional.api.client.OpenStackApiException: Unexpected status
code: {"conflictingRequest": {"message": "Cannot 'migrate' instance
15246707-924c-4d39-b746-4499ec174f90 while it is in vm_state building", "code":
409}}
http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22%7B%5C%5C%5C%22conflictingRequest%5C%5C%5C%22%3A%20%7B%5C%5C%5C%22message%5C%5C%5C%22%3A%20%5C%5C%5C%22Cannot%20'migrate'%20instance%5C%22%20AND%20message%3A%5C%22while%20it%20is%20in%20vm_state%20building%5C%5C%5C%22%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d
4 hits in 7 days, check and gate, all failures. I wouldn't be
surprised if this is a test that is using the ServersTestBase version
of _wait_for_state_change which waits for the status to change from
what is passed in rather than waiting for a terminal status.
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1850514/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : [email protected]
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
