yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1736976] [NEW] test_live_migration_actions functional test randomly fails with "AssertionError: The migration table left empty."

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date: Thu, 07 Dec 2017 15:41:27 -0000
Reply-to: Bug 1736976 <1736976@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Seen here:

http://logs.openstack.org/85/330285/175/check/openstack-tox-functional-
py35/9a23bfd/testr_results.html.gz

ft1.1: nova.tests.functional.notification_sample_tests.test_instance.TestInstanceNotificationSampleWithMultipleComputeOldAttachFlow.test_live_migration_actions_StringException: pythonlogging:'': {{{
2017-12-07 10:10:57,771 WARNING [oslo_config.cfg] Config option key_manager.api_class  is deprecated. Use option key_manager.backend instead.
2017-12-07 10:10:59,554 INFO [nova.service] Starting conductor node (version 17.0.0)
2017-12-07 10:10:59,571 INFO [nova.service] Starting scheduler node (version 17.0.0)
2017-12-07 10:10:59,595 INFO [nova.network.driver] Loading network driver 'nova.network.linux_net'
2017-12-07 10:10:59,596 INFO [nova.service] Starting network node (version 17.0.0)
2017-12-07 10:10:59,624 INFO [nova.virt.driver] Loading compute driver 'fake.FakeLiveMigrateDriver'
2017-12-07 10:10:59,624 INFO [nova.service] Starting compute node (version 17.0.0)
2017-12-07 10:10:59,647 WARNING [nova.compute.manager] No compute node record found for host compute. If this is the first time this service is starting on this host, then you can ignore this warning.
2017-12-07 10:10:59,647 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).
2017-12-07 10:10:59,651 WARNING [nova.compute.resource_tracker] No compute node record for compute:fake-mini
2017-12-07 10:10:59,654 INFO [nova.compute.resource_tracker] Compute node record created for compute:fake-mini with uuid: 6dfc5763-1a0b-47e1-941f-af8b88f2cf6e
2017-12-07 10:10:59,672 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e" status: 404 len: 227 microversion: 1.0
2017-12-07 10:10:59,677 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 201 len: 0 microversion: 1.0
2017-12-07 10:10:59,678 INFO [nova.scheduler.client.report] [req-583c10f0-5400-48e0-9e17-9ca12bbd4c98] Created resource provider record via placement API for resource provider with UUID 6dfc5763-1a0b-47e1-941f-af8b88f2cf6e and name fake-mini.
2017-12-07 10:10:59,684 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/aggregates" status: 200 len: 18 microversion: 1.1
2017-12-07 10:10:59,692 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 54 microversion: 1.0
2017-12-07 10:10:59,702 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 413 microversion: 1.0
2017-12-07 10:10:59,725 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/allocations" status: 200 len: 54 microversion: 1.0
2017-12-07 10:10:59,726 INFO [nova.compute.resource_tracker] Final resource view: name=fake-mini phys_ram=800000MB used_ram=512MB phys_disk=600000GB used_disk=0GB total_vcpus=1000 used_vcpus=0 pci_stats=[]
2017-12-07 10:10:59,739 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 413 microversion: 1.0
2017-12-07 10:10:59,744 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000319
2017-12-07 10:10:59,755 WARNING [nova.policy] Start using the new action 'os_compute_api:os-flavor-manage:create'. The existing action 'os_compute_api:os-flavor-manage' is being deprecated and will be removed in future release.
2017-12-07 10:10:59,769 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors" status: 200 len: 592 microversion: 2.56 time: 0.022701
2017-12-07 10:10:59,772 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000249
2017-12-07 10:10:59,792 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors/a22d5517-147c-4147-a0d1-e698df5cd4e3/os-extra_specs" status: 200 len: 51 microversion: 2.56 time: 0.018083
2017-12-07 10:10:59,823 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/os-keypairs" status: 201 len: 379 microversion: 2.56 time: 0.027772
2017-12-07 10:10:59,918 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 32 microversion: 2.56 time: 0.091302
2017-12-07 10:10:59,992 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers?reservation_id=r-os80yaw0" status: 200 len: 404 microversion: 2.56 time: 0.070785
2017-12-07 10:11:00,046 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 1815 microversion: 2.56 time: 0.051105
2017-12-07 10:11:00,059 INFO [nova.objects.resource_provider] Synced traits from os_traits into API DB: {'HW_GPU_API_DIRECT3D_V11_3', 'HW_NIC_SRIOV_QOS_TX', 'HW_GPU_API_DIRECT3D_V11_0', 'HW_GPU_API_DIRECT3D_V7_0', 'HW_GPU_API_DIRECTX_V11', 'HW_GPU_API_DIRECT3D_V9_0L', 'HW_CPU_X86_AESNI', 'HW_GPU_API_CUDA_V2_0', 'HW_GPU_RESOLUTION_W1024H768', 'HW_GPU_RESOLUTION_W1280H800', 'HW_NIC_DCB_PFC', 'HW_NIC_OFFLOAD_GENEVE', 'HW_GPU_API_DIRECT3D_V9_0C', 'HW_GPU_API_OPENGL_V2_1', 'HW_NIC_OFFLOAD_VXLAN', 'HW_GPU_API_CUDA_V5_3', 'HW_CPU_X86_TSX', 'HW_GPU_API_CUDA_V3_5', 'HW_CPU_X86_AVX512BW', 'HW_GPU_API_OPENGL_V1_5', 'STORAGE_DISK_HDD', 'HW_GPU_API_OPENGL_V2_0', 'HW_GPU_API_DIRECT3D_V9_0', 'HW_NIC_OFFLOAD_FDF', 'HW_NIC_OFFLOAD_SCS', 'HW_GPU_API_OPENGL_V3_0', 'HW_GPU_API_OPENCL_V2_1', 'HW_NIC_SRIOV', 'HW_NIC_ACCEL_TLS', 'HW_CPU_X86_VMX', 'HW_GPU_API_CUDA_V1_0', 'HW_CPU_X86_ASF', 'HW_CPU_X86_XOP', 'HW_GPU_API_CUDA_V6_0', 'HW_GPU_RESOLUTION_W1600H900', 'HW_CPU_X86_TBM', 'HW_GPU_API_OPENGL_V4_3', 'HW_GPU_API_OPENCL_V2_0', 'HW_NIC_OFFLOAD_QINQ', 'HW_NIC_OFFLOAD_LSO', 'HW_GPU_API_DIRECT3D_V11_1', 'HW_NIC_ACCEL_LZS', 'HW_NIC_DCB_QCN', 'HW_NIC_ACCEL_SSL', 'HW_GPU_API_CUDA_V3_0', 'HW_NIC_OFFLOAD_RX', 'HW_NIC_PROGRAMMABLE_PIPELINE', 'HW_GPU_API_DIRECTX_V12', 'HW_CPU_X86_SVM', 'HW_GPU_RESOLUTION_W1360H768', 'HW_CPU_X86_AVX512DQ', 'HW_GPU_API_CUDA_V2_1', 'HW_GPU_API_DIRECT3D_V10_1', 'HW_CPU_X86_AVX512F', 'HW_GPU_API_CUDA_V7_1', 'HW_NIC_SRIOV_MULTIQUEUE', 'HW_NIC_OFFLOAD_SG', 'HW_CPU_X86_SSE4A', 'HW_CPU_X86_AVX512VL', 'HW_CPU_X86_SGX', 'HW_GPU_API_DIRECT3D_V6_0', 'HW_NIC_ACCEL_ECC', 'HW_GPU_API_CUDA_V6_1', 'HW_NIC_OFFLOAD_RDMA', 'HW_GPU_API_OPENGL_V4_4', 'STORAGE_DISK_SSD', 'HW_GPU_API_OPENGL_V4_0', 'HW_GPU_API_DIRECT3D_V8_0', 'HW_GPU_RESOLUTION_W1600H1200', 'HW_NIC_ACCEL_IPSEC', 'HW_CPU_X86_AVX512PF', 'HW_CPU_X86_SSSE3', 'HW_CPU_X86_SSE3', 'HW_GPU_RESOLUTION_W1280H768', 'HW_CPU_X86_SSE41', 'HW_GPU_RESOLUTION_W1152H864', 'HW_CPU_X86_AVX512ER', 'HW_NIC_OFFLOAD_GSO', 'HW_GPU_RESOLUTION_W320H240', 'HW_CPU_X86_BMI', 'HW_CPU_X86_3DNOW', 'HW_CPU_X86_ABM', 'HW_GPU_API_OPENGL_V4_2', 'HW_GPU_API_OPENGL_V1_4', 'HW_NIC_OFFLOAD_GRE', 'HW_GPU_RESOLUTION_W7680H4320', 'HW_GPU_RESOLUTION_W2560H1440', 'HW_NIC_OFFLOAD_RXVLAN', 'HW_GPU_API_VULKAN', 'HW_GPU_API_OPENGL_V1_2', 'HW_CPU_X86_SSE', 'HW_NIC_OFFLOAD_TSO', 'HW_GPU_API_CUDA_V1_2', 'HW_CPU_X86_MMX', 'HW_NIC_OFFLOAD_UFO', 'HW_GPU_RESOLUTION_W1366H768', 'HW_GPU_API_DIRECT3D_V12_0', 'HW_GPU_API_OPENGL_V1_1', 'HW_GPU_RESOLUTION_W1440H900', 'HW_NIC_VMDQ', 'HW_CPU_X86_AVX2', 'HW_GPU_API_OPENCL_V1_0', 'HW_NIC_OFFLOAD_L2CRC', 'HW_NIC_DCB_ETS', 'HW_NIC_MULTIQUEUE', 'HW_CPU_X86_CLMUL', 'HW_CPU_X86_SSE2', 'HW_GPU_API_OPENGL_V1_3', 'HW_CPU_X86_FMA4', 'HW_NIC_OFFLOAD_LRO', 'HW_GPU_API_CUDA_V1_3', 'HW_GPU_API_DIRECTX_V10', 'HW_NIC_ACCEL_DIFFIEH', 'HW_GPU_RESOLUTION_W1920H1080', 'HW_GPU_API_CUDA_V3_2', 'MISC_SHARES_VIA_AGGREGATE', 'HW_GPU_RESOLUTION_W1280H1024', 'HW_GPU_API_DIRECT3D_V11_2', 'HW_CPU_X86_F16C', 'HW_GPU_API_DIRECT2D', 'HW_NIC_OFFLOAD_TX', 'HW_NIC_OFFLOAD_TCS', 'HW_GPU_API_OPENGL_V4_1', 'HW_GPU_API_DIRECT3D_V10_0', 'HW_GPU_API_OPENGL_V3_3', 'HW_GPU_API_CUDA_V5_2', 'HW_GPU_API_DIRECT3D_V9_0B', 'HW_GPU_API_OPENGL_V3_2', 'HW_GPU_API_CUDA_V7_0', 'HW_GPU_RESOLUTION_W640H480', 'HW_GPU_RESOLUTION_W3840H2160', 'HW_GPU_RESOLUTION_W1920H1200', 'HW_GPU_API_OPENCL_V2_2', 'HW_CPU_X86_FMA3', 'HW_GPU_API_OPENCL_V1_2', 'HW_GPU_API_CUDA_V1_1', 'HW_GPU_API_DIRECT3D_V8_1', 'HW_GPU_RESOLUTION_W800H600', 'HW_CPU_X86_MPX', 'HW_GPU_API_CUDA_V6_2', 'HW_GPU_RESOLUTION_W1680H1050', 'HW_GPU_API_OPENGL_V3_1', 'HW_GPU_API_DXVA', 'HW_GPU_API_OPENCL_V1_1', 'HW_NIC_ACCEL_DEFLATE', 'HW_CPU_X86_AVX', 'HW_NIC_ACCEL_RSA', 'HW_GPU_API_CUDA_V3_7', 'HW_CPU_X86_AVX512CD', 'HW_GPU_RESOLUTION_W1280H720', 'HW_GPU_API_CUDA_V5_0', 'HW_CPU_X86_BMI2', 'HW_NIC_OFFLOAD_GRO', 'HW_CPU_X86_SHA', 'HW_GPU_API_OPENGL_V4_5', 'HW_NIC_OFFLOAD_RXHASH', 'HW_NIC_OFFLOAD_TXUDP', 'HW_GPU_RESOLUTION_W1024H600', 'HW_NIC_OFFLOAD_TXVLAN', 'HW_CPU_X86_SSE42', 'HW_NIC_OFFLOAD_UCS', 'HW_NIC_SRIOV_QOS_RX', 'HW_GPU_RESOLUTION_W2560H1600'}
2017-12-07 10:11:00,083 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 387 microversion: 1.10
2017-12-07 10:11:00,116 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 19 microversion: 1.0
2017-12-07 10:11:00,131 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
2017-12-07 10:11:00,292 INFO [nova.compute.claims] Attempting claim on node fake-mini: memory 512 MB, disk 1 GB, vcpus 1 CPU
2017-12-07 10:11:00,292 INFO [nova.compute.claims] Total memory: 800000 MB, used: 512.00 MB
2017-12-07 10:11:00,292 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited
2017-12-07 10:11:00,292 INFO [nova.compute.claims] Total disk: 600000 GB, used: 0.00 GB
2017-12-07 10:11:00,292 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited
2017-12-07 10:11:00,292 INFO [nova.compute.claims] Total vcpu: 1000 VCPU, used: 0.00 VCPU
2017-12-07 10:11:00,293 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited
2017-12-07 10:11:00,293 INFO [nova.compute.claims] Claim successful on node fake-mini
2017-12-07 10:11:00,349 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 413 microversion: 1.0
2017-12-07 10:11:00,450 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
2017-12-07 10:11:00,491 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.
2017-12-07 10:11:00,541 INFO [nova.compute.manager] Took 0.26 seconds to build instance.
2017-12-07 10:11:00,648 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 2061 microversion: 2.56 time: 0.097998
2017-12-07 10:11:00,658 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'compute'. Re-created its InstanceList.
2017-12-07 10:11:00,734 INFO [nova.api.openstack.requestlog] 127.0.0.1 "PUT /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/tags" status: 200 len: 18 microversion: 2.56 time: 0.083215
2017-12-07 10:11:00,782 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/os-volume_attachments" status: 200 len: 194 microversion: 2.56 time: 0.044636
2017-12-07 10:11:00,827 INFO [nova.compute.manager] Attaching volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 to /dev/sdb
2017-12-07 10:11:00,888 INFO [nova.virt.driver] Loading compute driver 'fake.FakeLiveMigrateDriver'
2017-12-07 10:11:00,888 INFO [nova.service] Starting compute node (version 17.0.0)
2017-12-07 10:11:00,907 WARNING [nova.compute.manager] No compute node record found for host host2. If this is the first time this service is starting on this host, then you can ignore this warning.
2017-12-07 10:11:00,907 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).
2017-12-07 10:11:00,911 WARNING [nova.compute.resource_tracker] No compute node record for host2:host2
2017-12-07 10:11:00,914 INFO [nova.compute.resource_tracker] Compute node record created for host2:host2 with uuid: ce8a2998-42ff-4779-9c53-d783abfc7f09
2017-12-07 10:11:00,929 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09" status: 404 len: 227 microversion: 1.0
2017-12-07 10:11:00,935 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 201 len: 0 microversion: 1.0
2017-12-07 10:11:00,936 INFO [nova.scheduler.client.report] [req-ff261f06-0071-4103-b17c-0b8977aafd50] Created resource provider record via placement API for resource provider with UUID ce8a2998-42ff-4779-9c53-d783abfc7f09 and name host2.
2017-12-07 10:11:00,943 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/aggregates" status: 200 len: 18 microversion: 1.1
2017-12-07 10:11:00,951 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/inventories" status: 200 len: 54 microversion: 1.0
2017-12-07 10:11:00,963 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/inventories" status: 200 len: 413 microversion: 1.0
2017-12-07 10:11:00,986 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/allocations" status: 200 len: 54 microversion: 1.0
2017-12-07 10:11:00,987 INFO [nova.compute.resource_tracker] Final resource view: name=host2 phys_ram=800000MB used_ram=512MB phys_disk=600000GB used_disk=0GB total_vcpus=1000 used_vcpus=0 pci_stats=[]
2017-12-07 10:11:01,001 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/inventories" status: 200 len: 413 microversion: 1.0
2017-12-07 10:11:01,090 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/action" status: 202 len: 0 microversion: 2.56 time: 0.084449
2017-12-07 10:11:01,480 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
2017-12-07 10:11:01,488 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
2017-12-07 10:11:01,509 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
2017-12-07 10:11:01,557 ERROR [nova.compute.manager] Pre live migration failed at host2
Traceback (most recent call last):
  File "/home/zuul/src/git.openstack.org/openstack/nova/nova/compute/manager.py", line 5901, in _do_live_migration
    block_migration, disk, dest, migrate_data)
  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/mock/mock.py", line 1062, in __call__
    return _mock_self._mock_call(*args, **kwargs)
  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/mock/mock.py", line 1118, in _mock_call
    raise effect
nova.exception.LiveMigrationWithOldNovaNotSupported: Live migration with API v2.25 requires all the Mitaka upgrade to be complete before it is available.
2017-12-07 10:11:01,602 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 251 microversion: 1.0
2017-12-07 10:11:01,617 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
2017-12-07 10:11:01,710 INFO [nova.virt.block_device] Attempting to driver detach volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 from mountpoint /dev/sdb
2017-12-07 10:11:01,711 WARNING [nova.virt.block_device] Detaching volume from unknown instance
2017-12-07 10:11:01,837 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 2145 microversion: 2.56 time: 0.112645
2017-12-07 10:11:01,918 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/action" status: 202 len: 0 microversion: 2.56 time: 0.077696
2017-12-07 10:11:02,019 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 2155 microversion: 2.56 time: 0.098812
2017-12-07 10:11:02,069 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.046757
2017-12-07 10:11:02,124 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.051718
2017-12-07 10:11:02,171 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.043789
2017-12-07 10:11:02,220 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.045979
2017-12-07 10:11:02,268 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.045756
2017-12-07 10:11:02,308 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.036329
2017-12-07 10:11:02,352 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.040897
2017-12-07 10:11:02,399 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.044295
2017-12-07 10:11:02,443 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.041734
2017-12-07 10:11:02,490 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
2017-12-07 10:11:02,496 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.050253
2017-12-07 10:11:02,505 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
2017-12-07 10:11:02,551 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.052349
2017-12-07 10:11:02,560 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
2017-12-07 10:11:02,597 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.043768
2017-12-07 10:11:02,636 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.035920
2017-12-07 10:11:02,680 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.041373
2017-12-07 10:11:02,726 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.042453
2017-12-07 10:11:02,765 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.036300
2017-12-07 10:11:02,808 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.040401
2017-12-07 10:11:02,856 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.045650
2017-12-07 10:11:02,926 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.066809
2017-12-07 10:11:02,976 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.047373
}}}

...


Traceback (most recent call last):
  File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/notification_sample_tests/test_instance.py", line 63, in test_live_migration_actions
    action(server)
  File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/notification_sample_tests/test_instance.py", line 139, in _test_live_migration_abort
    migrations = self._wait_and_get_migrations(server)
  File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/notification_sample_tests/notification_sample_base.py", line 267, in _wait_and_get_migrations
    self.fail('The migration table left empty.')
  File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/unittest2/case.py", line 690, in fail
    raise self.failureException(msg)
AssertionError: The migration table left empty.


This stands out:

WARNING [nova.virt.block_device] Detaching volume from unknown instance

We probably have some kind of race, or maybe an issue in the
CinderFixture used in this test.

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: testing

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

Title:
  test_live_migration_actions functional test randomly fails with
  "AssertionError: The migration table left empty."

Status in OpenStack Compute (nova):
  New

Bug description:
  Seen here:

  http://logs.openstack.org/85/330285/175/check/openstack-tox-
  functional-py35/9a23bfd/testr_results.html.gz

  ft1.1: nova.tests.functional.notification_sample_tests.test_instance.TestInstanceNotificationSampleWithMultipleComputeOldAttachFlow.test_live_migration_actions_StringException: pythonlogging:'': {{{
  2017-12-07 10:10:57,771 WARNING [oslo_config.cfg] Config option key_manager.api_class  is deprecated. Use option key_manager.backend instead.
  2017-12-07 10:10:59,554 INFO [nova.service] Starting conductor node (version 17.0.0)
  2017-12-07 10:10:59,571 INFO [nova.service] Starting scheduler node (version 17.0.0)
  2017-12-07 10:10:59,595 INFO [nova.network.driver] Loading network driver 'nova.network.linux_net'
  2017-12-07 10:10:59,596 INFO [nova.service] Starting network node (version 17.0.0)
  2017-12-07 10:10:59,624 INFO [nova.virt.driver] Loading compute driver 'fake.FakeLiveMigrateDriver'
  2017-12-07 10:10:59,624 INFO [nova.service] Starting compute node (version 17.0.0)
  2017-12-07 10:10:59,647 WARNING [nova.compute.manager] No compute node record found for host compute. If this is the first time this service is starting on this host, then you can ignore this warning.
  2017-12-07 10:10:59,647 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).
  2017-12-07 10:10:59,651 WARNING [nova.compute.resource_tracker] No compute node record for compute:fake-mini
  2017-12-07 10:10:59,654 INFO [nova.compute.resource_tracker] Compute node record created for compute:fake-mini with uuid: 6dfc5763-1a0b-47e1-941f-af8b88f2cf6e
  2017-12-07 10:10:59,672 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e" status: 404 len: 227 microversion: 1.0
  2017-12-07 10:10:59,677 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 201 len: 0 microversion: 1.0
  2017-12-07 10:10:59,678 INFO [nova.scheduler.client.report] [req-583c10f0-5400-48e0-9e17-9ca12bbd4c98] Created resource provider record via placement API for resource provider with UUID 6dfc5763-1a0b-47e1-941f-af8b88f2cf6e and name fake-mini.
  2017-12-07 10:10:59,684 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/aggregates" status: 200 len: 18 microversion: 1.1
  2017-12-07 10:10:59,692 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 54 microversion: 1.0
  2017-12-07 10:10:59,702 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 413 microversion: 1.0
  2017-12-07 10:10:59,725 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/allocations" status: 200 len: 54 microversion: 1.0
  2017-12-07 10:10:59,726 INFO [nova.compute.resource_tracker] Final resource view: name=fake-mini phys_ram=800000MB used_ram=512MB phys_disk=600000GB used_disk=0GB total_vcpus=1000 used_vcpus=0 pci_stats=[]
  2017-12-07 10:10:59,739 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 413 microversion: 1.0
  2017-12-07 10:10:59,744 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000319
  2017-12-07 10:10:59,755 WARNING [nova.policy] Start using the new action 'os_compute_api:os-flavor-manage:create'. The existing action 'os_compute_api:os-flavor-manage' is being deprecated and will be removed in future release.
  2017-12-07 10:10:59,769 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors" status: 200 len: 592 microversion: 2.56 time: 0.022701
  2017-12-07 10:10:59,772 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000249
  2017-12-07 10:10:59,792 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors/a22d5517-147c-4147-a0d1-e698df5cd4e3/os-extra_specs" status: 200 len: 51 microversion: 2.56 time: 0.018083
  2017-12-07 10:10:59,823 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/os-keypairs" status: 201 len: 379 microversion: 2.56 time: 0.027772
  2017-12-07 10:10:59,918 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 32 microversion: 2.56 time: 0.091302
  2017-12-07 10:10:59,992 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers?reservation_id=r-os80yaw0" status: 200 len: 404 microversion: 2.56 time: 0.070785
  2017-12-07 10:11:00,046 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 1815 microversion: 2.56 time: 0.051105
  2017-12-07 10:11:00,059 INFO [nova.objects.resource_provider] Synced traits from os_traits into API DB: {'HW_GPU_API_DIRECT3D_V11_3', 'HW_NIC_SRIOV_QOS_TX', 'HW_GPU_API_DIRECT3D_V11_0', 'HW_GPU_API_DIRECT3D_V7_0', 'HW_GPU_API_DIRECTX_V11', 'HW_GPU_API_DIRECT3D_V9_0L', 'HW_CPU_X86_AESNI', 'HW_GPU_API_CUDA_V2_0', 'HW_GPU_RESOLUTION_W1024H768', 'HW_GPU_RESOLUTION_W1280H800', 'HW_NIC_DCB_PFC', 'HW_NIC_OFFLOAD_GENEVE', 'HW_GPU_API_DIRECT3D_V9_0C', 'HW_GPU_API_OPENGL_V2_1', 'HW_NIC_OFFLOAD_VXLAN', 'HW_GPU_API_CUDA_V5_3', 'HW_CPU_X86_TSX', 'HW_GPU_API_CUDA_V3_5', 'HW_CPU_X86_AVX512BW', 'HW_GPU_API_OPENGL_V1_5', 'STORAGE_DISK_HDD', 'HW_GPU_API_OPENGL_V2_0', 'HW_GPU_API_DIRECT3D_V9_0', 'HW_NIC_OFFLOAD_FDF', 'HW_NIC_OFFLOAD_SCS', 'HW_GPU_API_OPENGL_V3_0', 'HW_GPU_API_OPENCL_V2_1', 'HW_NIC_SRIOV', 'HW_NIC_ACCEL_TLS', 'HW_CPU_X86_VMX', 'HW_GPU_API_CUDA_V1_0', 'HW_CPU_X86_ASF', 'HW_CPU_X86_XOP', 'HW_GPU_API_CUDA_V6_0', 'HW_GPU_RESOLUTION_W1600H900', 'HW_CPU_X86_TBM', 'HW_GPU_API_OPENGL_V4_3', 'HW_GPU_API_OPENCL_V2_0', 'HW_NIC_OFFLOAD_QINQ', 'HW_NIC_OFFLOAD_LSO', 'HW_GPU_API_DIRECT3D_V11_1', 'HW_NIC_ACCEL_LZS', 'HW_NIC_DCB_QCN', 'HW_NIC_ACCEL_SSL', 'HW_GPU_API_CUDA_V3_0', 'HW_NIC_OFFLOAD_RX', 'HW_NIC_PROGRAMMABLE_PIPELINE', 'HW_GPU_API_DIRECTX_V12', 'HW_CPU_X86_SVM', 'HW_GPU_RESOLUTION_W1360H768', 'HW_CPU_X86_AVX512DQ', 'HW_GPU_API_CUDA_V2_1', 'HW_GPU_API_DIRECT3D_V10_1', 'HW_CPU_X86_AVX512F', 'HW_GPU_API_CUDA_V7_1', 'HW_NIC_SRIOV_MULTIQUEUE', 'HW_NIC_OFFLOAD_SG', 'HW_CPU_X86_SSE4A', 'HW_CPU_X86_AVX512VL', 'HW_CPU_X86_SGX', 'HW_GPU_API_DIRECT3D_V6_0', 'HW_NIC_ACCEL_ECC', 'HW_GPU_API_CUDA_V6_1', 'HW_NIC_OFFLOAD_RDMA', 'HW_GPU_API_OPENGL_V4_4', 'STORAGE_DISK_SSD', 'HW_GPU_API_OPENGL_V4_0', 'HW_GPU_API_DIRECT3D_V8_0', 'HW_GPU_RESOLUTION_W1600H1200', 'HW_NIC_ACCEL_IPSEC', 'HW_CPU_X86_AVX512PF', 'HW_CPU_X86_SSSE3', 'HW_CPU_X86_SSE3', 'HW_GPU_RESOLUTION_W1280H768', 'HW_CPU_X86_SSE41', 'HW_GPU_RESOLUTION_W1152H864', 'HW_CPU_X86_AVX512ER', 'HW_NIC_OFFLOAD_GSO', 'HW_GPU_RESOLUTION_W320H240', 'HW_CPU_X86_BMI', 'HW_CPU_X86_3DNOW', 'HW_CPU_X86_ABM', 'HW_GPU_API_OPENGL_V4_2', 'HW_GPU_API_OPENGL_V1_4', 'HW_NIC_OFFLOAD_GRE', 'HW_GPU_RESOLUTION_W7680H4320', 'HW_GPU_RESOLUTION_W2560H1440', 'HW_NIC_OFFLOAD_RXVLAN', 'HW_GPU_API_VULKAN', 'HW_GPU_API_OPENGL_V1_2', 'HW_CPU_X86_SSE', 'HW_NIC_OFFLOAD_TSO', 'HW_GPU_API_CUDA_V1_2', 'HW_CPU_X86_MMX', 'HW_NIC_OFFLOAD_UFO', 'HW_GPU_RESOLUTION_W1366H768', 'HW_GPU_API_DIRECT3D_V12_0', 'HW_GPU_API_OPENGL_V1_1', 'HW_GPU_RESOLUTION_W1440H900', 'HW_NIC_VMDQ', 'HW_CPU_X86_AVX2', 'HW_GPU_API_OPENCL_V1_0', 'HW_NIC_OFFLOAD_L2CRC', 'HW_NIC_DCB_ETS', 'HW_NIC_MULTIQUEUE', 'HW_CPU_X86_CLMUL', 'HW_CPU_X86_SSE2', 'HW_GPU_API_OPENGL_V1_3', 'HW_CPU_X86_FMA4', 'HW_NIC_OFFLOAD_LRO', 'HW_GPU_API_CUDA_V1_3', 'HW_GPU_API_DIRECTX_V10', 'HW_NIC_ACCEL_DIFFIEH', 'HW_GPU_RESOLUTION_W1920H1080', 'HW_GPU_API_CUDA_V3_2', 'MISC_SHARES_VIA_AGGREGATE', 'HW_GPU_RESOLUTION_W1280H1024', 'HW_GPU_API_DIRECT3D_V11_2', 'HW_CPU_X86_F16C', 'HW_GPU_API_DIRECT2D', 'HW_NIC_OFFLOAD_TX', 'HW_NIC_OFFLOAD_TCS', 'HW_GPU_API_OPENGL_V4_1', 'HW_GPU_API_DIRECT3D_V10_0', 'HW_GPU_API_OPENGL_V3_3', 'HW_GPU_API_CUDA_V5_2', 'HW_GPU_API_DIRECT3D_V9_0B', 'HW_GPU_API_OPENGL_V3_2', 'HW_GPU_API_CUDA_V7_0', 'HW_GPU_RESOLUTION_W640H480', 'HW_GPU_RESOLUTION_W3840H2160', 'HW_GPU_RESOLUTION_W1920H1200', 'HW_GPU_API_OPENCL_V2_2', 'HW_CPU_X86_FMA3', 'HW_GPU_API_OPENCL_V1_2', 'HW_GPU_API_CUDA_V1_1', 'HW_GPU_API_DIRECT3D_V8_1', 'HW_GPU_RESOLUTION_W800H600', 'HW_CPU_X86_MPX', 'HW_GPU_API_CUDA_V6_2', 'HW_GPU_RESOLUTION_W1680H1050', 'HW_GPU_API_OPENGL_V3_1', 'HW_GPU_API_DXVA', 'HW_GPU_API_OPENCL_V1_1', 'HW_NIC_ACCEL_DEFLATE', 'HW_CPU_X86_AVX', 'HW_NIC_ACCEL_RSA', 'HW_GPU_API_CUDA_V3_7', 'HW_CPU_X86_AVX512CD', 'HW_GPU_RESOLUTION_W1280H720', 'HW_GPU_API_CUDA_V5_0', 'HW_CPU_X86_BMI2', 'HW_NIC_OFFLOAD_GRO', 'HW_CPU_X86_SHA', 'HW_GPU_API_OPENGL_V4_5', 'HW_NIC_OFFLOAD_RXHASH', 'HW_NIC_OFFLOAD_TXUDP', 'HW_GPU_RESOLUTION_W1024H600', 'HW_NIC_OFFLOAD_TXVLAN', 'HW_CPU_X86_SSE42', 'HW_NIC_OFFLOAD_UCS', 'HW_NIC_SRIOV_QOS_RX', 'HW_GPU_RESOLUTION_W2560H1600'}
  2017-12-07 10:11:00,083 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 387 microversion: 1.10
  2017-12-07 10:11:00,116 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 19 microversion: 1.0
  2017-12-07 10:11:00,131 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
  2017-12-07 10:11:00,292 INFO [nova.compute.claims] Attempting claim on node fake-mini: memory 512 MB, disk 1 GB, vcpus 1 CPU
  2017-12-07 10:11:00,292 INFO [nova.compute.claims] Total memory: 800000 MB, used: 512.00 MB
  2017-12-07 10:11:00,292 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited
  2017-12-07 10:11:00,292 INFO [nova.compute.claims] Total disk: 600000 GB, used: 0.00 GB
  2017-12-07 10:11:00,292 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited
  2017-12-07 10:11:00,292 INFO [nova.compute.claims] Total vcpu: 1000 VCPU, used: 0.00 VCPU
  2017-12-07 10:11:00,293 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited
  2017-12-07 10:11:00,293 INFO [nova.compute.claims] Claim successful on node fake-mini
  2017-12-07 10:11:00,349 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/6dfc5763-1a0b-47e1-941f-af8b88f2cf6e/inventories" status: 200 len: 413 microversion: 1.0
  2017-12-07 10:11:00,450 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
  2017-12-07 10:11:00,491 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.
  2017-12-07 10:11:00,541 INFO [nova.compute.manager] Took 0.26 seconds to build instance.
  2017-12-07 10:11:00,648 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 2061 microversion: 2.56 time: 0.097998
  2017-12-07 10:11:00,658 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'compute'. Re-created its InstanceList.
  2017-12-07 10:11:00,734 INFO [nova.api.openstack.requestlog] 127.0.0.1 "PUT /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/tags" status: 200 len: 18 microversion: 2.56 time: 0.083215
  2017-12-07 10:11:00,782 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/os-volume_attachments" status: 200 len: 194 microversion: 2.56 time: 0.044636
  2017-12-07 10:11:00,827 INFO [nova.compute.manager] Attaching volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 to /dev/sdb
  2017-12-07 10:11:00,888 INFO [nova.virt.driver] Loading compute driver 'fake.FakeLiveMigrateDriver'
  2017-12-07 10:11:00,888 INFO [nova.service] Starting compute node (version 17.0.0)
  2017-12-07 10:11:00,907 WARNING [nova.compute.manager] No compute node record found for host host2. If this is the first time this service is starting on this host, then you can ignore this warning.
  2017-12-07 10:11:00,907 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).
  2017-12-07 10:11:00,911 WARNING [nova.compute.resource_tracker] No compute node record for host2:host2
  2017-12-07 10:11:00,914 INFO [nova.compute.resource_tracker] Compute node record created for host2:host2 with uuid: ce8a2998-42ff-4779-9c53-d783abfc7f09
  2017-12-07 10:11:00,929 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09" status: 404 len: 227 microversion: 1.0
  2017-12-07 10:11:00,935 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 201 len: 0 microversion: 1.0
  2017-12-07 10:11:00,936 INFO [nova.scheduler.client.report] [req-ff261f06-0071-4103-b17c-0b8977aafd50] Created resource provider record via placement API for resource provider with UUID ce8a2998-42ff-4779-9c53-d783abfc7f09 and name host2.
  2017-12-07 10:11:00,943 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/aggregates" status: 200 len: 18 microversion: 1.1
  2017-12-07 10:11:00,951 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/inventories" status: 200 len: 54 microversion: 1.0
  2017-12-07 10:11:00,963 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/inventories" status: 200 len: 413 microversion: 1.0
  2017-12-07 10:11:00,986 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/allocations" status: 200 len: 54 microversion: 1.0
  2017-12-07 10:11:00,987 INFO [nova.compute.resource_tracker] Final resource view: name=host2 phys_ram=800000MB used_ram=512MB phys_disk=600000GB used_disk=0GB total_vcpus=1000 used_vcpus=0 pci_stats=[]
  2017-12-07 10:11:01,001 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/ce8a2998-42ff-4779-9c53-d783abfc7f09/inventories" status: 200 len: 413 microversion: 1.0
  2017-12-07 10:11:01,090 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/action" status: 202 len: 0 microversion: 2.56 time: 0.084449
  2017-12-07 10:11:01,480 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
  2017-12-07 10:11:01,488 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
  2017-12-07 10:11:01,509 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
  2017-12-07 10:11:01,557 ERROR [nova.compute.manager] Pre live migration failed at host2
  Traceback (most recent call last):
    File "/home/zuul/src/git.openstack.org/openstack/nova/nova/compute/manager.py", line 5901, in _do_live_migration
      block_migration, disk, dest, migrate_data)
    File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/mock/mock.py", line 1062, in __call__
      return _mock_self._mock_call(*args, **kwargs)
    File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/mock/mock.py", line 1118, in _mock_call
      raise effect
  nova.exception.LiveMigrationWithOldNovaNotSupported: Live migration with API v2.25 requires all the Mitaka upgrade to be complete before it is available.
  2017-12-07 10:11:01,602 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 251 microversion: 1.0
  2017-12-07 10:11:01,617 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
  2017-12-07 10:11:01,710 INFO [nova.virt.block_device] Attempting to driver detach volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 from mountpoint /dev/sdb
  2017-12-07 10:11:01,711 WARNING [nova.virt.block_device] Detaching volume from unknown instance
  2017-12-07 10:11:01,837 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 2145 microversion: 2.56 time: 0.112645
  2017-12-07 10:11:01,918 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/action" status: 202 len: 0 microversion: 2.56 time: 0.077696
  2017-12-07 10:11:02,019 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 2155 microversion: 2.56 time: 0.098812
  2017-12-07 10:11:02,069 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.046757
  2017-12-07 10:11:02,124 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.051718
  2017-12-07 10:11:02,171 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.043789
  2017-12-07 10:11:02,220 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.045979
  2017-12-07 10:11:02,268 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.045756
  2017-12-07 10:11:02,308 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.036329
  2017-12-07 10:11:02,352 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.040897
  2017-12-07 10:11:02,399 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.044295
  2017-12-07 10:11:02,443 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.041734
  2017-12-07 10:11:02,490 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
  2017-12-07 10:11:02,496 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.050253
  2017-12-07 10:11:02,505 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "GET /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 200 len: 134 microversion: 1.0
  2017-12-07 10:11:02,551 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.052349
  2017-12-07 10:11:02,560 INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /placement/allocations/76be29c3-9f8b-4ce0-a788-790a1e86a52a" status: 204 len: 0 microversion: 1.10
  2017-12-07 10:11:02,597 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.043768
  2017-12-07 10:11:02,636 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.035920
  2017-12-07 10:11:02,680 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 18 microversion: 2.56 time: 0.041373
  2017-12-07 10:11:02,726 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.042453
  2017-12-07 10:11:02,765 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.036300
  2017-12-07 10:11:02,808 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.040401
  2017-12-07 10:11:02,856 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.045650
  2017-12-07 10:11:02,926 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.066809
  2017-12-07 10:11:02,976 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/76be29c3-9f8b-4ce0-a788-790a1e86a52a/migrations" status: 200 len: 494 microversion: 2.56 time: 0.047373
  }}}

  ...

  
  Traceback (most recent call last):
    File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/notification_sample_tests/test_instance.py", line 63, in test_live_migration_actions
      action(server)
    File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/notification_sample_tests/test_instance.py", line 139, in _test_live_migration_abort
      migrations = self._wait_and_get_migrations(server)
    File "/home/zuul/src/git.openstack.org/openstack/nova/nova/tests/functional/notification_sample_tests/notification_sample_base.py", line 267, in _wait_and_get_migrations
      self.fail('The migration table left empty.')
    File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional-py35/lib/python3.5/site-packages/unittest2/case.py", line 690, in fail
      raise self.failureException(msg)
  AssertionError: The migration table left empty.


  This stands out:

  WARNING [nova.virt.block_device] Detaching volume from unknown
  instance

  We probably have some kind of race, or maybe an issue in the
  CinderFixture used in this test.

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

[Bug 1736976] Re: test_live_migration_actions functional test randomly fails with "AssertionError: The migration table left empty."
From: OpenStack Infra, 2017-12-13