← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1964472] [NEW] test_bug_1944619.TestRollbackWithHWOffloadedOVS.test_rollback_pre_live_migration fails intermittently

 

Public bug reported:

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.

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: gate-failure

** Tags added: gate-failure

-- 
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):
  New

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



Follow ups