yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #88557
[Bug 1964472] Re: test_bug_1944619.TestRollbackWithHWOffloadedOVS.test_rollback_pre_live_migration fails intermittently
Reviewed: https://review.opendev.org/c/openstack/nova/+/833166
Committed: https://opendev.org/openstack/nova/commit/2ddb8bf53fdf9a17c09afc4987ab6efe8ba97696
Submitter: "Zuul (22348)"
Branch: master
commit 2ddb8bf53fdf9a17c09afc4987ab6efe8ba97696
Author: Erlon R. Cruz <erlon@xxxxxxxxxxxxx>
Date: Thu Mar 10 15:50:54 2022 -0300
Adds regression test for bug LP#1944619
Related-bug: #1944619
Closes-bug: #1964472
Change-Id: Ie7e5377aea23a4fbd7ad91f245d17def6d0fb927
** Changed in: nova
Status: In Progress => Fix Released
--
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/1964472
Title:
test_bug_1944619.TestRollbackWithHWOffloadedOVS.test_rollback_pre_live_migration
fails intermittently
Status in OpenStack Compute (nova):
Fix Released
Bug description:
Example failure:
https://zuul.opendev.org/t/openstack/build/99a1e4f3deb4478cb6fa19ed666a950f/log/job-
output.txt
Recently this test started failing frequently. In the last 7 days from
8 failed functional test run 6 was due to this in nova. But this
happened as far back as 14th of February.
Signature: https://paste.opendev.org/show/btHI7ErFfhKYFGdfoujl/
Stack trace:
2022-03-09 14:37:34.960791 | ubuntu-focal | {7} nova.tests.functional.regressions.test_bug_1944619.TestRollbackWithHWOffloadedOVS.test_rollback_pre_live_migration [5.854784s] ... FAILED
2022-03-09 14:37:34.960833 | ubuntu-focal |
2022-03-09 14:37:34.960849 | ubuntu-focal | Captured traceback:
2022-03-09 14:37:34.960861 | ubuntu-focal | ~~~~~~~~~~~~~~~~~~~
2022-03-09 14:37:34.960872 | ubuntu-focal | Traceback (most recent
call last):
2022-03-09 14:37:34.960883 | ubuntu-focal |
2022-03-09 14:37:34.960894 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/tests/functional/regressions/test_bug_1944619.py",
line 87, in test_rollback_pre_live_migration
2022-03-09 14:37:34.960906 | ubuntu-focal |
self.libvirt_mock.mock.assert_called_once()
2022-03-09 14:37:34.960917 | ubuntu-focal |
2022-03-09 14:37:34.960929 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 891, in
assert_called_once
2022-03-09 14:37:34.960959 | ubuntu-focal | raise
AssertionError(msg)
2022-03-09 14:37:34.960972 | ubuntu-focal |
2022-03-09 14:37:34.960985 | ubuntu-focal | AssertionError:
Expected 'rollback_live_migration_at_source' to have been called once.
Called 0 times.
2022-03-09 14:37:34.960996 | ubuntu-focal |
2022-03-09 14:37:34.961005 | ubuntu-focal |
2022-03-09 14:37:34.961015 | ubuntu-focal | Captured pythonlogging:
2022-03-09 14:37:34.961025 | ubuntu-focal | ~~~~~~~~~~~~~~~~~~~~~~~
2022-03-09 14:37:34.961036 | ubuntu-focal | 2022-03-09
14:37:29,292 WARNING [oslo_policy.policy] JSON formatted policy_file
support is deprecated since Victoria release. You need to use YAML
format which will be default in future. You can use ``oslopolicy-
convert-json-to-yaml`` tool to convert existing JSON-formatted policy
file to YAML-formatted in backward compatible way:
https://docs.openstack.org/oslo.policy/latest/cli/oslopolicy-convert-
json-to-yaml.html.
2022-03-09 14:37:34.961048 | ubuntu-focal | 2022-03-09 14:37:29,293
WARNING [oslo_policy.policy] JSON formatted policy_file support is
deprecated since Victoria release. You need to use YAML format which
will be default in future. You can use ``oslopolicy-convert-json-to-
yaml`` tool to convert existing JSON-formatted policy file to YAML-
formatted in backward compatible way:
https://docs.openstack.org/oslo.policy/latest/cli/oslopolicy-convert-
json-to-yaml.html.
2022-03-09 14:37:34.961071 | ubuntu-focal | 2022-03-09 14:37:29,296
WARNING [oslo_policy.policy] Policy Rules
['os_compute_api:extensions', 'os_compute_api:os-floating-ip-pools',
'os_compute_api:os-quota-sets:defaults', 'os_compute_api:os-
availability-zone:list', 'os_compute_api:limits', 'project_admin_api',
'project_member_api', 'project_reader_api', 'project_reader_or_admin',
'os_compute_api:limits:other_project', 'os_compute_api:os-lock-
server:unlock:unlock_override',
'os_compute_api:servers:create:zero_disk_flavor',
'compute:servers:resize:cross_cell'] specified in policy files are the
same as the defaults provided by the service. You can remove these
rules from policy files which will make maintenance easier. You can
detect these redundant rules by ``oslopolicy-list-redundant`` tool
also.
2022-03-09 14:37:34.961108 | ubuntu-focal | 2022-03-09 14:37:29,301
WARNING [placement.db_api] TransactionFactory already started, not
reconfiguring.
2022-03-09 14:37:34.961121 | ubuntu-focal | 2022-03-09 14:37:29,406
INFO [nova.service] Starting conductor node (version 24.1.0)
2022-03-09 14:37:34.961133 | ubuntu-focal | 2022-03-09 14:37:29,463
INFO [nova.service] Starting scheduler node (version 24.1.0)
2022-03-09 14:37:34.961144 | ubuntu-focal | 2022-03-09 14:37:31,524
INFO [nova.virt.driver] Loading compute driver 'libvirt.LibvirtDriver'
2022-03-09 14:37:34.961153 | ubuntu-focal | 2022-03-09 14:37:31,527
INFO [nova.compute.provider_config] No provider configs found in
/etc/nova/provider_config/. If files are present, ensure the Nova
process has access.
2022-03-09 14:37:34.961175 | ubuntu-focal | 2022-03-09 14:37:31,536
INFO [nova.service] Starting compute node (version 24.1.0)
2022-03-09 14:37:34.961183 | ubuntu-focal | 2022-03-09 14:37:31,554
INFO [nova.virt.libvirt.host] Secure Boot support detected
2022-03-09 14:37:34.961189 | ubuntu-focal | 2022-03-09 14:37:31,558
WARNING [nova.virt.libvirt.driver] my_ip address (149.202.187.126) was
not found on any of the interfaces:
2022-03-09 14:37:34.961201 | ubuntu-focal | 2022-03-09 14:37:31,559
WARNING [nova.virt.libvirt.driver] Running Nova with a libvirt version
less than 7.0.0 is deprecated. The required minimum version of libvirt
will be raised to 7.0.0 in the next release.
2022-03-09 14:37:34.961213 | ubuntu-focal | 2022-03-09 14:37:31,559
WARNING [nova.virt.libvirt.driver] Running Nova with a QEMU version
less than 5.2.0 is deprecated. The required minimum version of QEMU
will be raised to 5.2.0 in the next release.
2022-03-09 14:37:34.961250 | ubuntu-focal | 2022-03-09 14:37:31,598
WARNING [nova.compute.manager] Compute node src not found in the
database. If this is the first time this service is starting on this
host, then you can ignore this warning.
2022-03-09 14:37:34.961257 | ubuntu-focal | 2022-03-09 14:37:31,606
INFO [nova.compute.manager] Looking for unclaimed instances stuck in
BUILDING status for nodes managed by this host
2022-03-09 14:37:34.961270 | ubuntu-focal | 2022-03-09 14:37:31,624
WARNING [nova.compute.manager] No compute node record found for host
src. If this is the first time this service is starting on this host,
then you can ignore this warning.
2022-03-09 14:37:34.961276 | ubuntu-focal | 2022-03-09 14:37:31,632
WARNING [nova.compute.resource_tracker] No compute node record for
src:src
2022-03-09 14:37:34.961282 | ubuntu-focal | 2022-03-09 14:37:31,639
INFO [nova.compute.resource_tracker] Compute node record created for
src:src with uuid: 7f41f57e-1c75-4533-beb4-2e1f31ce4327
2022-03-09 14:37:34.961288 | ubuntu-focal | 2022-03-09 14:37:31,707
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?in_tree=7f41f57e-1c75-4533-beb4-2e1f31ce4327"
status: 200 len: 26 microversion: 1.14
2022-03-09 14:37:34.961293 | ubuntu-focal | 2022-03-09 14:37:31,717
INFO [placement.requestlog] 127.0.0.1 "POST
/placement/resource_providers" status: 200 len: 826 microversion: 1.20
2022-03-09 14:37:34.961299 | ubuntu-focal | 2022-03-09 14:37:31,718
INFO [nova.scheduler.client.report]
[req-d4bdf881-be30-4d23-bd99-cf75934974ab] Created resource provider
2022-03-09 14:37:34.961305 | ubuntu-focal | record via placement
API for resource provider with UUID
7f41f57e-1c75-4533-beb4-2e1f31ce4327 and name src.
2022-03-09 14:37:34.961310 | ubuntu-focal | 2022-03-09 14:37:31,719
INFO [nova.virt.libvirt.host] kernel doesn't support AMD SEV
2022-03-09 14:37:34.961316 | ubuntu-focal | 2022-03-09 14:37:31,742
INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/7f41f57e-1c75-4533-beb4-2e1f31ce4327/inventories"
status: 200 len: 407 microversion: 1.26
2022-03-09 14:37:34.961323 | ubuntu-focal | 2022-03-09 14:37:31,757
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/traits?name=in:COMPUTE_IMAGE_TYPE_ISO,COMPUTE_NODE,COMPUTE_IMAGE_TYPE_ARI,COMPUTE_IMAGE_TYPE_AMI,HW_CPU_X86_INTEL_VMX,COMPUTE_SECURITY_UEFI_SECURE_BOOT,COMPUTE_GRAPHICS_MODEL_QXL,COMPUTE_GRAPHICS_MODEL_NONE,COMPUTE_VOLUME_EXTEND,COMPUTE_STORAGE_BUS_FDC,HW_CPU_X86_AESNI,HW_CPU_X86_VMX,COMPUTE_DEVICE_TAGGING,COMPUTE_STORAGE_BUS_SATA,COMPUTE_GRAPHICS_MODEL_VMVGA,COMPUTE_NET_VIF_MODEL_PCNET,COMPUTE_NET_VIF_MODEL_E1000E,COMPUTE_SOCKET_PCI_NUMA_AFFINITY,COMPUTE_RESCUE_BFV,COMPUTE_IMAGE_TYPE_AKI,COMPUTE_NET_VIF_MODEL_VIRTIO,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_GRAPHICS_MODEL_BOCHS,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_GRAPHICS_MODEL_VIRTIO,COMPUTE_NET_VIF_MODEL_RTL8139,COMPUTE_IMAGE_TYPE_QCOW2,COMPUTE_GRAPHICS_MODEL_VGA,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_TRUSTED_CERTS,COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_NET_VIF_MODEL_VMXNET3,COMPUTE_IMAGE_TYPE_RAW,COMPUTE_STORAGE_BUS_IDE,COMPUTE_NET_VIF_MODEL_NE2K_PCI,COMPUTE_STORAGE_BUS_SCSI,COMPUTE_NET_VIF_MODEL_SPAPR_VLAN,COMPUTE_ACCELERATORS,COMPUTE_STORAGE_BUS_USB,COMPUTE_NET_VIF_MODEL_E1000,COMPUTE_GRAPHICS_MODEL_CIRRUS,COMPUTE_STORAGE_BUS_VIRTIO"
status: 200 len: 1231 microversion: 1.6
2022-03-09 14:37:34.961330 | ubuntu-focal | 2022-03-09 14:37:31,793
INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/7f41f57e-1c75-4533-beb4-2e1f31ce4327/traits"
status: 200 len: 1266 microversion: 1.6
2022-03-09 14:37:34.961347 | ubuntu-focal | 2022-03-09 14:37:31,807
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?name=src" status: 200 len: 430
microversion: 1.0
2022-03-09 14:37:34.961355 | ubuntu-focal | 2022-03-09 14:37:31,820
INFO [nova.virt.driver] Loading compute driver 'libvirt.LibvirtDriver'
2022-03-09 14:37:34.961361 | ubuntu-focal | 2022-03-09 14:37:31,822
INFO [nova.compute.provider_config] No provider configs found in
/etc/nova/provider_config/. If files are present, ensure the Nova
process has access.
2022-03-09 14:37:34.961366 | ubuntu-focal | 2022-03-09 14:37:31,829
INFO [nova.service] Starting compute node (version 24.1.0)
2022-03-09 14:37:34.961372 | ubuntu-focal | 2022-03-09 14:37:31,845
INFO [nova.virt.libvirt.host] Secure Boot support detected
2022-03-09 14:37:34.961378 | ubuntu-focal | 2022-03-09 14:37:31,846
WARNING [nova.virt.libvirt.driver] my_ip address (149.202.187.126) was
not found on any of the interfaces:
2022-03-09 14:37:34.961383 | ubuntu-focal | 2022-03-09 14:37:31,847
WARNING [nova.virt.libvirt.driver] Running Nova with a libvirt version
less than 7.0.0 is deprecated. The required minimum version of libvirt
will be raised to 7.0.0 in the next release.
2022-03-09 14:37:34.961389 | ubuntu-focal | 2022-03-09 14:37:31,847
WARNING [nova.virt.libvirt.driver] Running Nova with a QEMU version
less than 5.2.0 is deprecated. The required minimum version of QEMU
will be raised to 5.2.0 in the next release.
2022-03-09 14:37:34.961395 | ubuntu-focal | 2022-03-09 14:37:31,859
WARNING [nova.compute.manager] Compute node dest not found in the
database. If this is the first time this service is starting on this
host, then you can ignore this warning.
2022-03-09 14:37:34.961401 | ubuntu-focal | 2022-03-09 14:37:31,863
INFO [nova.compute.manager] Looking for unclaimed instances stuck in
BUILDING status for nodes managed by this host
2022-03-09 14:37:34.961412 | ubuntu-focal | 2022-03-09 14:37:31,877
WARNING [nova.compute.manager] No compute node record found for host
dest. If this is the first time this service is starting on this host,
then you can ignore this warning.
2022-03-09 14:37:34.961418 | ubuntu-focal | 2022-03-09 14:37:31,885
WARNING [nova.compute.resource_tracker] No compute node record for
dest:dest
2022-03-09 14:37:34.961424 | ubuntu-focal | 2022-03-09 14:37:31,890
INFO [nova.compute.resource_tracker] Compute node record created for
dest:dest with uuid: 656a0c68-a66b-41c6-bf12-a76a9254c623
2022-03-09 14:37:34.961430 | ubuntu-focal | 2022-03-09 14:37:31,929
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?in_tree=656a0c68-a66b-41c6-bf12-a76a9254c623"
status: 200 len: 26 microversion: 1.14
2022-03-09 14:37:34.961435 | ubuntu-focal | 2022-03-09 14:37:31,941
INFO [placement.requestlog] 127.0.0.1 "POST
/placement/resource_providers" status: 200 len: 827 microversion: 1.20
2022-03-09 14:37:34.961441 | ubuntu-focal | 2022-03-09 14:37:31,942
INFO [nova.scheduler.client.report] [req-bf
2022-03-09 14:37:34.961447 | ubuntu-focal |
6d495f-00a1-4a16-bfb0-fca447e478a6] Created resource provider record
via placement API for resource provider with UUID
656a0c68-a66b-41c6-bf12-a76a9254c623 and name dest.
2022-03-09 14:37:34.961452 | ubuntu-focal | 2022-03-09 14:37:31,957
INFO [nova.virt.libvirt.host] kernel doesn't support AMD SEV
2022-03-09 14:37:34.961458 | ubuntu-focal | 2022-03-09 14:37:31,992
INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/656a0c68-a66b-41c6-bf12-a76a9254c623/inventories"
status: 200 len: 407 microversion: 1.26
2022-03-09 14:37:34.961464 | ubuntu-focal | 2022-03-09 14:37:32,010
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/traits?name=in:COMPUTE_IMAGE_TYPE_ISO,COMPUTE_NODE,COMPUTE_IMAGE_TYPE_ARI,COMPUTE_IMAGE_TYPE_AMI,HW_CPU_X86_INTEL_VMX,COMPUTE_SECURITY_UEFI_SECURE_BOOT,COMPUTE_GRAPHICS_MODEL_QXL,COMPUTE_GRAPHICS_MODEL_NONE,COMPUTE_VOLUME_EXTEND,COMPUTE_STORAGE_BUS_FDC,HW_CPU_X86_AESNI,HW_CPU_X86_VMX,COMPUTE_DEVICE_TAGGING,COMPUTE_STORAGE_BUS_SATA,COMPUTE_GRAPHICS_MODEL_VMVGA,COMPUTE_NET_VIF_MODEL_PCNET,COMPUTE_NET_VIF_MODEL_E1000E,COMPUTE_SOCKET_PCI_NUMA_AFFINITY,COMPUTE_RESCUE_BFV,COMPUTE_IMAGE_TYPE_AKI,COMPUTE_NET_VIF_MODEL_VIRTIO,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_GRAPHICS_MODEL_BOCHS,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_GRAPHICS_MODEL_VIRTIO,COMPUTE_NET_VIF_MODEL_RTL8139,COMPUTE_IMAGE_TYPE_QCOW2,COMPUTE_GRAPHICS_MODEL_VGA,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_TRUSTED_CERTS,COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_NET_VIF_MODEL_VMXNET3,COMPUTE_IMAGE_TYPE_RAW,COMPUTE_STORAGE_BUS_IDE,COMPUTE_NET_VIF_MODEL_NE2K_PCI,COMPUTE_STORAGE_BUS_SCSI,COMPUTE_NET_VIF_MODEL_SPAPR_VLAN,COMPUTE_ACCELERATORS,COMPUTE_STORAGE_BUS_USB,COMPUTE_NET_VIF_MODEL_E1000,COMPUTE_GRAPHICS_MODEL_CIRRUS,COMPUTE_STORAGE_BUS_VIRTIO"
status: 200 len: 1231 microversion: 1.6
2022-03-09 14:37:34.961491 | ubuntu-focal | 2022-03-09 14:37:32,054
INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/resource_providers/656a0c68-a66b-41c6-bf12-a76a9254c623/traits"
status: 200 len: 1266 microversion: 1.6
2022-03-09 14:37:34.961499 | ubuntu-focal | 2022-03-09 14:37:32,069
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/resource_providers?name=dest" status: 200 len: 431
microversion: 1.0
2022-03-09 14:37:34.961505 | ubuntu-focal | 2022-03-09 14:37:32,094
INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/images/detail" status: 200 len: 5173 microversion: 2.35 time:
0.018258
2022-03-09 14:37:34.961510 | ubuntu-focal | 2022-03-09 14:37:32,122
INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/flavors/detail" status: 200 len: 2605 microversion: 2.90 time:
0.023321
2022-03-09 14:37:34.961516 | ubuntu-focal | 2022-03-09 14:37:32,421
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocation_candidates?in_tree=7f41f57e-1c75-4533-beb4-2e1f31ce4327&limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1&root_required=%21COMPUTE_STATUS_DISABLED"
status: 200 len: 1735 microversion: 1.36
2022-03-09 14:37:34.961523 | ubuntu-focal | 2022-03-09 14:37:32,456
INFO [nova.scheduler.host_manager] Host filter only checking host src
and node src
2022-03-09 14:37:34.961528 | ubuntu-focal | 2022-03-09 14:37:32,485
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 19 microversion: 1.28
2022-03-09 14:37:34.961534 | ubuntu-focal | 2022-03-09 14:37:32,541
INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
204 len: 0 microversion: 1.36
2022-03-09 14:37:34.961540 | ubuntu-focal | 2022-03-09 14:37:32,737
INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/servers"
status: 202 len: 414 microversion: 2.90 time: 0.609876
2022-03-09 14:37:34.961550 | ubuntu-focal | 2022-03-09 14:37:32,901
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.961556 | ubuntu-focal | 2022-03-09 14:37:32,907
INFO [nova.compute.claims] Claim successful on node src
2022-03-09 14:37:34.961564 | ubuntu-focal | 2022-03-09 14:37:32,973
INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/servers/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status: 200 len:
1779 microversion: 2.90 time: 0.231145
2022-03-09 14:37:34.961570 | ubuntu-focal | 2022-03-09 14:37:33,208
INFO [nova.virt.libvirt.driver] Instance spawned successfully.
2022-03-09 14:37:34.961575 | ubuntu-focal | 2022-03-09 14:37:33,250
INFO [nova.compute.manager] Took 0.13 seconds to spawn the instance on
the hypervisor.
2022-03-09 14:37:34.961581 | ubuntu-focal | 2022-03-09 14:37:33,293
INFO [nova.scheduler.host_manager] Received an update from an unknown
host 'src'. Re-created its InstanceList.
2022-03-09 14:37:34.961618 | ubuntu-focal | 2022-03-09 14:37:33,298
INFO [nova.compute.manager] Took 0.48 seconds to build instance.
2022-03-09 14:37:34.961626 | ubuntu-focal | 2022-03-09 14:37:33,591
INFO [nova.api.openstack.requestlog
2022-03-09 14:37:34.961634 | ubuntu-focal | ] 127.0.0.1 "GET
/v2.1/servers/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status: 200 len:
1868 microversion: 2.90 time: 0.106982
2022-03-09 14:37:34.961640 | ubuntu-focal | 2022-03-09 14:37:33,885
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.961645 | ubuntu-focal | 2022-03-09 14:37:33,901
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.961660 | ubuntu-focal | 2022-03-09 14:37:33,912
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/f2ee6ad9-dfbf-47fa-8d54-d6e56095894f" status:
200 len: 19 microversion: 1.28
2022-03-09 14:37:34.961667 | ubuntu-focal | 2022-03-09 14:37:33,969
INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations"
status: 204 len: 0 microversion: 1.28
2022-03-09 14:37:34.961673 | ubuntu-focal | 2022-03-09 14:37:34,066
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1&root_required=%21COMPUTE_STATUS_DISABLED"
status: 200 len: 3423 microversion: 1.36
2022-03-09 14:37:34.961681 | ubuntu-focal | 2022-03-09 14:37:34,106
INFO [nova.scheduler.host_manager] Host filter ignoring hosts: src
2022-03-09 14:37:34.961686 | ubuntu-focal | 2022-03-09 14:37:34,119
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 19 microversion: 1.28
2022-03-09 14:37:34.961692 | ubuntu-focal | 2022-03-09 14:37:34,158
INFO [placement.requestlog] 127.0.0.1 "PUT
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
204 len: 0 microversion: 1.36
2022-03-09 14:37:34.961719 | ubuntu-focal | 2022-03-09 14:37:34,263
INFO [nova.virt.libvirt.driver] Instance launched has CPU info:
{"arch": "x86_64", "model": "Penryn", "vendor": "Intel", "topology":
{"cells": 1, "sockets": 1, "cores": 4, "threads": 1}, "features":
["tm", "pbe", "est", "aes", "ds_cpl", "xtpr", "monitor", "vmx", "vme",
"ss", "acpi", "ds", "ht", "tm2"]}
2022-03-09 14:37:34.961748 | ubuntu-focal | 2022-03-09 14:37:34,280
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.961761 | ubuntu-focal | 2022-03-09 14:37:34,494
INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST
/v2.1/servers/c8e381b7-df10-46f5-8aac-aa6d52f64b4a/action" status: 202
len: 0 microversion: 2.90 time: 0.897295
2022-03-09 14:37:34.961780 | ubuntu-focal | 2022-03-09 14:37:34,596
INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET
/v2.1/servers/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status: 200 len:
1878 microversion: 2.90 time: 0.097029
2022-03-09 14:37:34.961794 | ubuntu-focal | 2022-03-09 14:37:34,633
ERROR [oslo_messaging.rpc.server] Exception during message handling
2022-03-09 14:37:34.961805 | ubuntu-focal | Traceback (most recent
call last):
2022-03-09 14:37:34.961815 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/server.py", line
165, in _process_incoming
2022-03-09 14:37:34.961820 | ubuntu-focal | res =
self.dispatcher.dispatch(message)
2022-03-09 14:37:34.961826 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/dispatcher.py",
line 309, in dispatch
2022-03-09 14:37:34.961831 | ubuntu-focal | return
self._do_dispatch(endpoint, method, ctxt, args)
2022-03-09 14:37:34.961838 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/dispatcher.py",
line 229, in _do_dispatch
2022-03-09 14:37:34.961843 | ubuntu-focal | result = func(ctxt,
**new_args)
2022-03-09 14:37:34.961849 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/exception_wrapper.py",
line 71, in wrapped
2022-03-09 14:37:34.961854 | ubuntu-focal |
_emit_versioned_exception_notification(
2022-03-09 14:37:34.961866 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 227, in
__exit__
2022-03-09 14:37:34.961881 | ubuntu-focal | self.force_reraise()
2022-03-09 14:37:34.961899 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 200, in
force_reraise
2022-03-09 14:37:34.961910 | ubuntu-focal | raise self.value
2022-03-09 14:37:34.961920 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/exception_wrapper.py",
line 63, in wrapped
2022-03-09 14:37:34.961930 | ubuntu-focal | return f(self,
context, *args, **kw)
2022-03-09 14:37:34.961939 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/utils.py",
line 1439, in decorated_function
2022-03-09 14:37:34.961972 | ubuntu-focal | return function(self,
context, *args, **kwargs)
2022-03-09 14:37:34.961985 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 211, in decorated_function
2022-03-09 14:37:34.961994 | ubuntu-focal |
compute_utils.add_instance_fault_from_exc(context,
2022-03-09 14:37:34.962004 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/e
2022-03-09 14:37:34.962013 | ubuntu-focal | xcutils.py", line 227,
in __exit__
2022-03-09 14:37:34.962021 | ubuntu-focal | self.force_reraise()
2022-03-09 14:37:34.962032 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 200, in
force_reraise
2022-03-09 14:37:34.962041 | ubuntu-focal | raise self.value
2022-03-09 14:37:34.962051 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 200, in decorated_function
2022-03-09 14:37:34.962060 | ubuntu-focal | return function(self,
context, *args, **kwargs)
2022-03-09 14:37:34.962069 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 8347, in pre_live_migration
2022-03-09 14:37:34.962078 | ubuntu-focal | bdm.save()
2022-03-09 14:37:34.962088 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 227, in
__exit__
2022-03-09 14:37:34.962097 | ubuntu-focal | self.force_reraise()
2022-03-09 14:37:34.962107 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 200, in
force_reraise
2022-03-09 14:37:34.962115 | ubuntu-focal | raise self.value
2022-03-09 14:37:34.962125 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 8303, in pre_live_migration
2022-03-09 14:37:34.962133 | ubuntu-focal | migrate_data =
self.driver.pre_live_migration(context,
2022-03-09 14:37:34.962142 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 1100, in __call__
2022-03-09 14:37:34.962152 | ubuntu-focal | return
_mock_self._mock_call(*args, **kwargs)
2022-03-09 14:37:34.962161 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 1104, in
_mock_call
2022-03-09 14:37:34.962170 | ubuntu-focal | return
_mock_self._execute_mock_call(*args, **kwargs)
2022-03-09 14:37:34.962178 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 1161, in
_execute_mock_call
2022-03-09 14:37:34.962186 | ubuntu-focal | raise effect
2022-03-09 14:37:34.962195 | ubuntu-focal |
nova.exception.DestinationDiskExists: The supplied disk path
(/var/non/existent) already exists, it is expected not to exist.
2022-03-09 14:37:34.962206 | ubuntu-focal | 2022-03-09 14:37:34,642
ERROR [nova.compute.manager] Pre live migration failed at dest
2022-03-09 14:37:34.962216 | ubuntu-focal | Traceback (most recent
call last):
2022-03-09 14:37:34.962227 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 8478, in _do_pre_live_migration_from_source
2022-03-09 14:37:34.962236 | ubuntu-focal | migrate_data =
self.compute_rpcapi.pre_live_migration(
2022-03-09 14:37:34.962243 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/rpcapi.py",
line 945, in pre_live_migration
2022-03-09 14:37:34.962248 | ubuntu-focal | return
cctxt.call(ctxt, 'pre_live_migration',
2022-03-09 14:37:34.962253 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/client.py", line
189, in call
2022-03-09 14:37:34.962259 | ubuntu-focal | result =
self.transport._send(
2022-03-09 14:37:34.962264 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/transport.py", line
123, in _send
2022-03-09 14:37:34.962270 | ubuntu-focal | return
self._driver.send(target, ctxt, message,
2022-03-09 14:37:34.962275 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-
packages/oslo_messaging/_drivers/impl_fake.py", line 222, in send
2022-03-09 14:37:34.962296 | ubuntu-focal | return
self._send(target, ctxt, message, wait_for_reply, timeout,
2022-03-09 14:37:34.962304 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-
packages/oslo_messaging/_drivers/impl_fake.py", line 209, in _send
2022-03-09 14:37:34.962309 | ubuntu-focal | raise failure
2022-03-09 14:37:34.962315 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/server.py", line
165, in _process_incoming
2022-03-09 14:37:34.962320 | ubuntu-focal | res =
self.dispatcher.dispatch(message)
2022-03-09 14:37:34.962333 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/dispatcher.py",
line 309, in dispatch
2022-03-09 14:37:34.962339 | ubuntu-focal | return
self._do_dispatch(endpoint, method, ctxt, args)
2022-03-09 14:37:34.962345 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_messaging/rpc/dispatcher.py",
line 229, in _do_dispatch
2022-03-09 14:37:34.962350 | ubuntu-focal | result = func(ctxt,
**new_args)
2022-03-09 14:37:34.962356 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/exception_wrapper.py",
line 71, in wrapped
2022-03-09 14:37:34.962361 | ubuntu-focal |
_emit_versioned_exception_notification(
2022-03-09 14:37:34.962366 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 227, in
__exit__
2022-03-09 14:37:34.962372 | ubuntu-focal | self.force_reraise()
2022-03-09 14:37:34.962378 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 200, in
force_reraise
2022-03-09 14:37:34.962386 | ubuntu-focal | raise self.value
2022-03-09 14:37:34.962392 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/no
2022-03-09 14:37:34.962397 | ubuntu-focal |
va/nova/exception_wrapper.py", line 63, in wrapped
2022-03-09 14:37:34.962403 | ubuntu-focal | return f(self,
context, *args, **kw)
2022-03-09 14:37:34.962408 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/utils.py",
line 1439, in decorated_function
2022-03-09 14:37:34.962416 | ubuntu-focal | return function(self,
context, *args, **kwargs)
2022-03-09 14:37:34.962421 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 211, in decorated_function
2022-03-09 14:37:34.962427 | ubuntu-focal |
compute_utils.add_instance_fault_from_exc(context,
2022-03-09 14:37:34.962432 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 227, in
__exit__
2022-03-09 14:37:34.962447 | ubuntu-focal | self.force_reraise()
2022-03-09 14:37:34.962454 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 200, in
force_reraise
2022-03-09 14:37:34.962459 | ubuntu-focal | raise self.value
2022-03-09 14:37:34.962465 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 200, in decorated_function
2022-03-09 14:37:34.962470 | ubuntu-focal | return function(self,
context, *args, **kwargs)
2022-03-09 14:37:34.962476 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 8347, in pre_live_migration
2022-03-09 14:37:34.962482 | ubuntu-focal | bdm.save()
2022-03-09 14:37:34.962493 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 227, in
__exit__
2022-03-09 14:37:34.962502 | ubuntu-focal | self.force_reraise()
2022-03-09 14:37:34.962512 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/oslo_utils/excutils.py", line 200, in
force_reraise
2022-03-09 14:37:34.962521 | ubuntu-focal | raise self.value
2022-03-09 14:37:34.962531 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py",
line 8303, in pre_live_migration
2022-03-09 14:37:34.962541 | ubuntu-focal | migrate_data =
self.driver.pre_live_migration(context,
2022-03-09 14:37:34.962550 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 1100, in __call__
2022-03-09 14:37:34.962579 | ubuntu-focal | return
_mock_self._mock_call(*args, **kwargs)
2022-03-09 14:37:34.962592 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 1104, in
_mock_call
2022-03-09 14:37:34.962603 | ubuntu-focal | return
_mock_self._execute_mock_call(*args, **kwargs)
2022-03-09 14:37:34.962613 | ubuntu-focal | File
"/home/zuul/src/opendev.org/openstack/nova/.tox/functional-
py38/lib/python3.8/site-packages/mock/mock.py", line 1161, in
_execute_mock_call
2022-03-09 14:37:34.962623 | ubuntu-focal | raise effect
2022-03-09 14:37:34.962632 | ubuntu-focal |
nova.exception.DestinationDiskExists: The supplied disk path
(/var/non/existent) already exists, it is expected not to exist.
2022-03-09 14:37:34.962641 | ubuntu-focal | 2022-03-09 14:37:34,686
INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/os-
migrations" status: 200 len: 510 microversion: 2.90 time: 0.084727
2022-03-09 14:37:34.962651 | ubuntu-focal | 2022-03-09 14:37:34,692
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/f2ee6ad9-dfbf-47fa-8d54-d6e56095894f" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.962661 | ubuntu-focal | 2022-03-09 14:37:34,694
INFO [nova.compute.manager] Swapping old allocation on
dict_keys(['7f41f57e-1c75-4533-beb4-2e1f31ce4327']) held by migration
f2ee6ad9-dfbf-47fa-8d54-d6e56095894f for instance
2022-03-09 14:37:34.962671 | ubuntu-focal | 2022-03-09 14:37:34,707
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/f2ee6ad9-dfbf-47fa-8d54-d6e56095894f" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.962680 | ubuntu-focal | 2022-03-09 14:37:34,720
INFO [placement.requestlog] 127.0.0.1 "GET
/placement/allocations/c8e381b7-df10-46f5-8aac-aa6d52f64b4a" status:
200 len: 230 microversion: 1.28
2022-03-09 14:37:34.962691 | ubuntu-focal | 2022-03-09 14:37:34,780
INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations"
status: 204 len: 0 microversion: 1.28
2022-03-09 14:37:34.962702 | ubuntu-focal | 2022-03-09 14:37:34,805
WARNING [nova.compute.manager] Unable to cancel live migration.
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1964472/+subscriptions
References
