test_bug_1944619.TestRollbackWithHWOffloadedOVS.test_rollback_pre_live_migration fails intermittently

[Balazs Gibizer]

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.

[Balazs Gibizer (balazs-gibizer)]

This test was introduced recently by https://review.opendev.org/c/openstack/nova/+/821840

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/nova/+/833079

[OpenStack Infra (hudson-openstack)]

Change abandoned by "Balazs Gibizer <email address hidden>" on branch: master
Review: https://review.opendev.org/c/openstack/nova/+/833079
Reason: We went to reverting the original patch instead with https://review.opendev.org/c/openstack/nova/+/832902

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/c/openstack/nova/+/833166

[OpenStack Infra (hudson-openstack)]

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 <email address hidden>
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

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/xena
Review: https://review.opendev.org/c/openstack/nova/+/838550

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/yoga
Review: https://review.opendev.org/c/openstack/nova/+/838788

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/nova/+/838788
Committed: https://opendev.org/openstack/nova/commit/3402aa7a53a48e6abc0fb8a2620cd449fd3f75fe
Submitter: "Zuul (22348)"
Branch: stable/yoga

commit 3402aa7a53a48e6abc0fb8a2620cd449fd3f75fe
Author: Erlon R. Cruz <email address hidden>
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
    (cherry picked from commit 2ddb8bf53fdf9a17c09afc4987ab6efe8ba97696)

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/c/openstack/nova/+/838550
Committed: https://opendev.org/openstack/nova/commit/1059921383060257b3a66596dec96a04b208dea9
Submitter: "Zuul (22348)"
Branch: stable/xena

commit 1059921383060257b3a66596dec96a04b208dea9
Author: Erlon R. Cruz <email address hidden>
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
    (cherry picked from commit 2ddb8bf53fdf9a17c09afc4987ab6efe8ba97696)
    (cherry picked from commit 3402aa7a53a48e6abc0fb8a2620cd449fd3f75fe)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 25.0.1 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 24.1.1 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 26.0.0.0rc1 release candidate.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/nova/+/862401

[OpenStack Infra (hudson-openstack)]

Change abandoned by "Erlon R. Cruz <email address hidden>" on branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/nova/+/862401
Reason: Abandoning in favor of Change Ia208ef0dd0bab1c59d025234f4da7537c39cda61

[OpenStack Infra (hudson-openstack)]

Change abandoned by "Erlon R. Cruz <email address hidden>" on branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/nova/+/838332
Reason: Not backporting this anymore as is not that critical and is causing failures on the unit tests.

[OpenStack Infra (hudson-openstack)]

Change abandoned by "Elod Illes <email address hidden>" on branch: stable/wallaby
Review: https://review.opendev.org/c/openstack/nova/+/838332
Reason: stable/wallaby branch of openstack/nova is about to be deleted. To be able to do that, all open patches need to be abandoned. Please cherry pick the patch to unmaintained/wallaby if you want to further work on this patch.