Seen here:
http://logs.openstack.org/47/638047/9/check/nova-tox-functional/71f64ae/job-output.txt.gz#_2019-04-02_00_07_32_290065
2019-04-02 00:07:32.290065 | ubuntu-bionic | {2} nova.tests.functional.notification_sample_tests.test_instance.TestInstanceNotificationSampleWithMultipleComputeOldAttachFlow.test_multiple_compute_actions [14.302238s] ... FAILED
2019-04-02 00:07:32.290219 | ubuntu-bionic |
2019-04-02 00:07:32.290275 | ubuntu-bionic | Captured traceback:
2019-04-02 00:07:32.290318 | ubuntu-bionic | ~~~~~~~~~~~~~~~~~~~
2019-04-02 00:07:32.290378 | ubuntu-bionic | Traceback (most recent call last):
2019-04-02 00:07:32.290525 | ubuntu-bionic | File "nova/tests/functional/notification_sample_tests/test_instance.py", line 68, in test_multiple_compute_actions
2019-04-02 00:07:32.290569 | ubuntu-bionic | action(server)
2019-04-02 00:07:32.290726 | ubuntu-bionic | File "nova/tests/functional/notification_sample_tests/test_instance.py", line 311, in _test_live_migration_force_complete
2019-04-02 00:07:32.290822 | ubuntu-bionic | self.assertEqual(6, len(fake_notifier.VERSIONED_NOTIFICATIONS))
2019-04-02 00:07:32.291011 | ubuntu-bionic | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/testtools/testcase.py", line 411, in assertEqual
2019-04-02 00:07:32.291148 | ubuntu-bionic | self.assertThat(observed, matcher, message)
2019-04-02 00:07:32.291351 | ubuntu-bionic | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/testtools/testcase.py", line 498, in assertThat
2019-04-02 00:07:32.291402 | ubuntu-bionic | raise mismatch_error
2019-04-02 00:07:32.291475 | ubuntu-bionic | testtools.matchers._impl.MismatchError: 6 != 7
2019-04-02 00:07:32.291497 | ubuntu-bionic |
2019-04-02 00:07:32.291515 | ubuntu-bionic |
2019-04-02 00:07:32.291558 | ubuntu-bionic | Captured pythonlogging:
2019-04-02 00:07:32.291602 | ubuntu-bionic | ~~~~~~~~~~~~~~~~~~~~~~~
2019-04-02 00:07:32.291737 | ubuntu-bionic | 2019-04-02 00:07:19,024 WARNING [placement.db_api] TransactionFactory already started, not reconfiguring.
2019-04-02 00:07:32.291908 | ubuntu-bionic | 2019-04-02 00:07:19,053 INFO [nova.service] Starting conductor node (version 19.1.0)
2019-04-02 00:07:32.292181 | ubuntu-bionic | 2019-04-02 00:07:19,073 INFO [nova.service] Starting scheduler node (version 19.1.0)
2019-04-02 00:07:32.292326 | ubuntu-bionic | 2019-04-02 00:07:19,089 INFO [nova.network.driver] Loading network driver 'nova.network.linux_net'
2019-04-02 00:07:32.292438 | ubuntu-bionic | 2019-04-02 00:07:19,090 INFO [nova.service] Starting network node (version 19.1.0)
2019-04-02 00:07:32.292606 | ubuntu-bionic | 2019-04-02 00:07:19,118 INFO [nova.virt.driver] Loading compute driver 'fake.FakeLiveMigrateDriver'
2019-04-02 00:07:32.292820 | ubuntu-bionic | 2019-04-02 00:07:19,118 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).
2019-04-02 00:07:32.292945 | ubuntu-bionic | 2019-04-02 00:07:19,119 INFO [nova.service] Starting compute node (version 19.1.0)
2019-04-02 00:07:32.293174 | ubuntu-bionic | 2019-04-02 00:07:19,141 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.
2019-04-02 00:07:32.293304 | ubuntu-bionic | 2019-04-02 00:07:19,144 WARNING [nova.compute.resource_tracker] No compute node record for compute:fake-mini
2019-04-02 00:07:32.293484 | ubuntu-bionic | 2019-04-02 00:07:19,148 INFO [nova.compute.resource_tracker] Compute node record created for compute:fake-mini with uuid: 109a2d73-cdf9-4d76-8e6e-74dc79ff7359
2019-04-02 00:07:32.293687 | ubuntu-bionic | 2019-04-02 00:07:19,187 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=109a2d73-cdf9-4d76-8e6e-74dc79ff7359" status: 200 len: 26 microversion: 1.14
2019-04-02 00:07:32.293848 | ubuntu-bionic | 2019-04-02 00:07:19,193 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 832 microversion: 1.20
2019-04-02 00:07:32.294112 | ubuntu-bionic | 2019-04-02 00:07:19,194 INFO [nova.scheduler.client.report] [req-5b6c791d-5709-4f36-8fbe-c3e02869e35d] Created resource provider record via placement API for resource provider with UUID 109a2d73-cdf9-4d76-8e6e-74dc79ff7359 and name fake-mini.
2019-04-02 00:07:32.294321 | ubuntu-bionic | 2019-04-02 00:07:19,208 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/109a2d73-cdf9-4d76-8e6e-74dc79ff7359/inventories" status: 200 len: 413 microversion: 1.26
2019-04-02 00:07:32.294693 | ubuntu-bionic | 2019-04-02 00:07:19,220 INFO [placement.requestlog] 127.0.0.1 "GET /placement/traits?name=in:COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_TRUSTED_CERTS,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_VOLUME_EXTEND,COMPUTE_DEVICE_TAGGING" status: 200 len: 226 microversion: 1.6
2019-04-02 00:07:32.294944 | ubuntu-bionic | 2019-04-02 00:07:19,234 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/109a2d73-cdf9-4d76-8e6e-74dc79ff7359/traits" status: 200 len: 261 microversion: 1.6
2019-04-02 00:07:32.295159 | ubuntu-bionic | 2019-04-02 00:07:19,239 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000296
2019-04-02 00:07:32.295377 | ubuntu-bionic | 2019-04-02 00:07:19,364 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/flavors" status: 200 len: 611 microversion: 2.72 time: 0.122205
2019-04-02 00:07:32.297249 | ubuntu-bionic | 2019-04-02 00:07:19,367 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1" status: 204 len: 0 microversion: - time: 0.000239
2019-04-02 00:07:32.297541 | ubuntu-bionic | 2019-04-02 00:07:19,386 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.72 time: 0.017107
2019-04-02 00:07:32.297859 | ubuntu-bionic | 2019-04-02 00:07:19,413 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/os-keypairs" status: 201 len: 379 microversion: 2.72 time: 0.024532
2019-04-02 00:07:32.298070 | ubuntu-bionic | 2019-04-02 00:07:19,512 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers" status: 202 len: 32 microversion: 2.72 time: 0.096062
2019-04-02 00:07:32.298335 | ubuntu-bionic | 2019-04-02 00:07:19,574 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers?reservation_id=r-hnbz5gim" status: 200 len: 404 microversion: 2.72 time: 0.058885
2019-04-02 00:07:32.298570 | ubuntu-bionic | 2019-04-02 00:07:19,614 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 674 microversion: 1.29
2019-04-02 00:07:32.298808 | ubuntu-bionic | 2019-04-02 00:07:19,637 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 1872 microversion: 2.72 time: 0.059987
2019-04-02 00:07:32.298997 | ubuntu-bionic | 2019-04-02 00:07:19,652 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.299252 | ubuntu-bionic | 2019-04-02 00:07:19,673 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 204 len: 0 microversion: 1.29
2019-04-02 00:07:32.299417 | ubuntu-bionic | 2019-04-02 00:07:19,882 INFO [nova.compute.claims] Attempting claim on node fake-mini: memory 512 MB, disk 1 GB, vcpus 1 CPU
2019-04-02 00:07:32.299532 | ubuntu-bionic | 2019-04-02 00:07:19,882 INFO [nova.compute.claims] Total memory: 800000 MB, used: 512.00 MB
2019-04-02 00:07:32.299656 | ubuntu-bionic | 2019-04-02 00:07:19,882 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited
2019-04-02 00:07:32.299765 | ubuntu-bionic | 2019-04-02 00:07:19,882 INFO [nova.compute.claims] Total disk: 600000 GB, used: 0.00 GB
2019-04-02 00:07:32.299893 | ubuntu-bionic | 2019-04-02 00:07:19,882 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited
2019-04-02 00:07:32.300038 | ubuntu-bionic | 2019-04-02 00:07:19,883 INFO [nova.compute.claims] Total vcpu: 1000 VCPU, used: 0.00 VCPU
2019-04-02 00:07:32.300191 | ubuntu-bionic | 2019-04-02 00:07:19,883 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited
2019-04-02 00:07:32.300309 | ubuntu-bionic | 2019-04-02 00:07:19,883 INFO [nova.compute.claims] Claim successful on node fake-mini
2019-04-02 00:07:32.300504 | ubuntu-bionic | 2019-04-02 00:07:20,069 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.300635 | ubuntu-bionic | 2019-04-02 00:07:20,112 INFO [nova.compute.manager] Took 0.00 seconds to spawn the instance on the hypervisor.
2019-04-02 00:07:32.300751 | ubuntu-bionic | 2019-04-02 00:07:20,171 INFO [nova.compute.manager] Took 0.30 seconds to build instance.
2019-04-02 00:07:32.300911 | ubuntu-bionic | 2019-04-02 00:07:20,229 INFO [nova.scheduler.host_manager] Received an update from an unknown host 'compute'. Re-created its InstanceList.
2019-04-02 00:07:32.301157 | ubuntu-bionic | 2019-04-02 00:07:20,258 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2118 microversion: 2.72 time: 0.103617
2019-04-02 00:07:32.301410 | ubuntu-bionic | 2019-04-02 00:07:20,347 INFO [nova.api.openstack.requestlog] 127.0.0.1 "PUT /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/tags" status: 200 len: 18 microversion: 2.72 time: 0.082867
2019-04-02 00:07:32.301678 | ubuntu-bionic | 2019-04-02 00:07:20,426 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/os-volume_attachments" status: 200 len: 207 microversion: 2.72 time: 0.076133
2019-04-02 00:07:32.301824 | ubuntu-bionic | 2019-04-02 00:07:20,468 INFO [nova.compute.manager] Attaching volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 to /dev/sdb
2019-04-02 00:07:32.301945 | ubuntu-bionic | 2019-04-02 00:07:20,562 INFO [nova.virt.driver] Loading compute driver 'fake.FakeLiveMigrateDriver'
2019-04-02 00:07:32.302148 | ubuntu-bionic | 2019-04-02 00:07:20,564 WARNING [nova.compute.monitors] Excluding nova.compute.monitors.cpu monitor virt_driver. Not in the list of enabled monitors (CONF.compute_monitors).
2019-04-02 00:07:32.302287 | ubuntu-bionic | 2019-04-02 00:07:20,565 INFO [nova.service] Starting compute node (version 19.1.0)
2019-04-02 00:07:32.302553 | ubuntu-bionic | 2019-04-02 00:07:20,586 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.
2019-04-02 00:07:32.302686 | ubuntu-bionic | 2019-04-02 00:07:20,591 WARNING [nova.compute.resource_tracker] No compute node record for host2:host2
2019-04-02 00:07:32.302861 | ubuntu-bionic | 2019-04-02 00:07:20,594 INFO [nova.compute.resource_tracker] Compute node record created for host2:host2 with uuid: e30090d2-c1ab-4528-a338-62182708f6c6
2019-04-02 00:07:32.303114 | ubuntu-bionic | 2019-04-02 00:07:20,625 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers?in_tree=e30090d2-c1ab-4528-a338-62182708f6c6" status: 200 len: 26 microversion: 1.14
2019-04-02 00:07:32.303290 | ubuntu-bionic | 2019-04-02 00:07:20,631 INFO [placement.requestlog] 127.0.0.1 "POST /placement/resource_providers" status: 200 len: 828 microversion: 1.20
2019-04-02 00:07:32.303558 | ubuntu-bionic | 2019-04-02 00:07:20,632 INFO [nova.scheduler.client.report] [req-5b6c791d-5709-4f36-8fbe-c3e02869e35d] Created resource provider record via placement API for resource provider with UUID e30090d2-c1ab-4528-a338-62182708f6c6 and name host2.
2019-04-02 00:07:32.303767 | ubuntu-bionic | 2019-04-02 00:07:20,641 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/e30090d2-c1ab-4528-a338-62182708f6c6/inventories" status: 200 len: 413 microversion: 1.26
2019-04-02 00:07:32.304155 | ubuntu-bionic | 2019-04-02 00:07:20,647 INFO [placement.requestlog] 127.0.0.1 "GET /placement/traits?name=in:COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_TRUSTED_CERTS,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_VOLUME_EXTEND,COMPUTE_DEVICE_TAGGING" status: 200 len: 226 microversion: 1.6
2019-04-02 00:07:32.304376 | ubuntu-bionic | 2019-04-02 00:07:20,658 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/resource_providers/e30090d2-c1ab-4528-a338-62182708f6c6/traits" status: 200 len: 261 microversion: 1.6
2019-04-02 00:07:32.304620 | ubuntu-bionic | 2019-04-02 00:07:20,739 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/action" status: 202 len: 0 microversion: 2.72 time: 0.076845
2019-04-02 00:07:32.304811 | ubuntu-bionic | 2019-04-02 00:07:20,769 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.305007 | ubuntu-bionic | 2019-04-02 00:07:20,776 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.305201 | ubuntu-bionic | 2019-04-02 00:07:20,782 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b8bed8a2-cd41-4511-86cd-8563dbeb2072" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.305351 | ubuntu-bionic | 2019-04-02 00:07:20,815 INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.305591 | ubuntu-bionic | 2019-04-02 00:07:20,880 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 1301 microversion: 1.29
2019-04-02 00:07:32.305725 | ubuntu-bionic | 2019-04-02 00:07:20,908 INFO [nova.scheduler.host_manager] Host filter only checking host host2 and node host2
2019-04-02 00:07:32.305834 | ubuntu-bionic | 2019-04-02 00:07:20,908 INFO [nova.scheduler.host_manager] Host filter ignoring hosts:
2019-04-02 00:07:32.306029 | ubuntu-bionic | 2019-04-02 00:07:20,917 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.306223 | ubuntu-bionic | 2019-04-02 00:07:20,937 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 204 len: 0 microversion: 1.29
2019-04-02 00:07:32.306379 | ubuntu-bionic | 2019-04-02 00:07:21,162 ERROR [nova.compute.manager] Pre live migration failed at host2
2019-04-02 00:07:32.306447 | ubuntu-bionic | Traceback (most recent call last):
2019-04-02 00:07:32.306535 | ubuntu-bionic | File "nova/compute/manager.py", line 7236, in _do_live_migration
2019-04-02 00:07:32.306602 | ubuntu-bionic | block_migration, disk, dest, migrate_data)
2019-04-02 00:07:32.306767 | ubuntu-bionic | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/mock/mock.py", line 1062, in __call__
2019-04-02 00:07:32.306860 | ubuntu-bionic | return _mock_self._mock_call(*args, **kwargs)
2019-04-02 00:07:32.307071 | ubuntu-bionic | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/mock/mock.py", line 1118, in _mock_call
2019-04-02 00:07:32.307122 | ubuntu-bionic | raise effect
2019-04-02 00:07:32.307250 | ubuntu-bionic | DestinationDiskExists: The supplied disk path (path) already exists, it is expected not to exist.
2019-04-02 00:07:32.307440 | ubuntu-bionic | 2019-04-02 00:07:21,175 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b8bed8a2-cd41-4511-86cd-8563dbeb2072" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.307658 | ubuntu-bionic | 2019-04-02 00:07:21,176 INFO [nova.compute.manager] Swapping old allocation on 109a2d73-cdf9-4d76-8e6e-74dc79ff7359 held by migration b8bed8a2-cd41-4511-86cd-8563dbeb2072 for instance
2019-04-02 00:07:32.307881 | ubuntu-bionic | 2019-04-02 00:07:21,184 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/b8bed8a2-cd41-4511-86cd-8563dbeb2072" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.308078 | ubuntu-bionic | 2019-04-02 00:07:21,191 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.308539 | ubuntu-bionic | 2019-04-02 00:07:21,192 WARNING [nova.scheduler.client.report] Overwriting current allocation {u'project_id': u'6f70656e737461636b20342065766572', u'consumer_generation': 1, u'user_id': u'fake', u'allocations': {u'e30090d2-c1ab-4528-a338-62182708f6c6': {u'generation': 3, u'resources': {u'VCPU': 1, u'DISK_GB': 1, u'MEMORY_MB': 512}}}} on consumer dc76de5a-d330-462a-9b6b-a15d59ac9199
2019-04-02 00:07:32.308733 | ubuntu-bionic | 2019-04-02 00:07:21,225 INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.308911 | ubuntu-bionic | 2019-04-02 00:07:21,322 INFO [nova.virt.block_device] Attempting to driver detach volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 from mountpoint /dev/sdb
2019-04-02 00:07:32.309032 | ubuntu-bionic | 2019-04-02 00:07:21,322 WARNING [nova.virt.block_device] Detaching volume from unknown instance
2019-04-02 00:07:32.309277 | ubuntu-bionic | 2019-04-02 00:07:21,654 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2202 microversion: 2.72 time: 0.124296
2019-04-02 00:07:32.309521 | ubuntu-bionic | 2019-04-02 00:07:21,738 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/action" status: 202 len: 0 microversion: 2.72 time: 0.080526
2019-04-02 00:07:32.309772 | ubuntu-bionic | 2019-04-02 00:07:21,823 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2212 microversion: 2.72 time: 0.082117
2019-04-02 00:07:32.309962 | ubuntu-bionic | 2019-04-02 00:07:21,868 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.310215 | ubuntu-bionic | 2019-04-02 00:07:21,875 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations" status: 200 len: 18 microversion: 2.72 time: 0.049653
2019-04-02 00:07:32.310434 | ubuntu-bionic | 2019-04-02 00:07:21,879 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.310669 | ubuntu-bionic | 2019-04-02 00:07:21,885 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/cab1a8d4-7a10-40ef-b57e-3bd9ea54dbcc" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.310836 | ubuntu-bionic | 2019-04-02 00:07:21,911 INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.311666 | ubuntu-bionic | 2019-04-02 00:07:21,968 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 1301 microversion: 1.29
2019-04-02 00:07:32.311831 | ubuntu-bionic | 2019-04-02 00:07:21,993 INFO [nova.scheduler.host_manager] Host filter only checking host host2 and node host2
2019-04-02 00:07:32.311945 | ubuntu-bionic | 2019-04-02 00:07:21,993 INFO [nova.scheduler.host_manager] Host filter ignoring hosts:
2019-04-02 00:07:32.312161 | ubuntu-bionic | 2019-04-02 00:07:22,002 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.312360 | ubuntu-bionic | 2019-04-02 00:07:22,020 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 204 len: 0 microversion: 1.29
2019-04-02 00:07:32.312509 | ubuntu-bionic | 2019-04-02 00:07:22,274 INFO [nova.compute.manager] Took 0.10 seconds for pre_live_migration on destination host host2.
2019-04-02 00:07:32.312765 | ubuntu-bionic | 2019-04-02 00:07:22,424 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations" status: 200 len: 540 microversion: 2.72 time: 0.046006
2019-04-02 00:07:32.313057 | ubuntu-bionic | 2019-04-02 00:07:22,468 INFO [nova.api.openstack.requestlog] 127.0.0.1 "DELETE /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations/2" status: 202 len: 0 microversion: 2.72 time: 0.041235
2019-04-02 00:07:32.313305 | ubuntu-bionic | 2019-04-02 00:07:22,582 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2212 microversion: 2.72 time: 0.070385
2019-04-02 00:07:32.313501 | ubuntu-bionic | 2019-04-02 00:07:22,609 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/cab1a8d4-7a10-40ef-b57e-3bd9ea54dbcc" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.313708 | ubuntu-bionic | 2019-04-02 00:07:22,611 INFO [nova.compute.manager] Swapping old allocation on 109a2d73-cdf9-4d76-8e6e-74dc79ff7359 held by migration cab1a8d4-7a10-40ef-b57e-3bd9ea54dbcc for instance
2019-04-02 00:07:32.313902 | ubuntu-bionic | 2019-04-02 00:07:22,624 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/cab1a8d4-7a10-40ef-b57e-3bd9ea54dbcc" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.314144 | ubuntu-bionic | 2019-04-02 00:07:22,641 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.314574 | ubuntu-bionic | 2019-04-02 00:07:22,642 WARNING [nova.scheduler.client.report] Overwriting current allocation {u'project_id': u'6f70656e737461636b20342065766572', u'consumer_generation': 1, u'user_id': u'fake', u'allocations': {u'e30090d2-c1ab-4528-a338-62182708f6c6': {u'generation': 4, u'resources': {u'VCPU': 1, u'DISK_GB': 1, u'MEMORY_MB': 512}}}} on consumer dc76de5a-d330-462a-9b6b-a15d59ac9199
2019-04-02 00:07:32.314728 | ubuntu-bionic | 2019-04-02 00:07:22,686 INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.314900 | ubuntu-bionic | 2019-04-02 00:07:22,742 INFO [nova.virt.block_device] Attempting to driver detach volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 from mountpoint /dev/sdb
2019-04-02 00:07:32.315023 | ubuntu-bionic | 2019-04-02 00:07:22,742 WARNING [nova.virt.block_device] Detaching volume from unknown instance
2019-04-02 00:07:32.315310 | ubuntu-bionic | 2019-04-02 00:07:23,197 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2202 microversion: 2.72 time: 0.109925
2019-04-02 00:07:32.315594 | ubuntu-bionic | 2019-04-02 00:07:23,295 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2202 microversion: 2.72 time: 0.081375
2019-04-02 00:07:32.315855 | ubuntu-bionic | 2019-04-02 00:07:23,391 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/action" status: 202 len: 0 microversion: 2.72 time: 0.092867
2019-04-02 00:07:32.316045 | ubuntu-bionic | 2019-04-02 00:07:23,421 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.316270 | ubuntu-bionic | 2019-04-02 00:07:23,430 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.316456 | ubuntu-bionic | 2019-04-02 00:07:23,437 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/1ef7333e-9209-46e5-8997-2372a7a2c1ca" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.316604 | ubuntu-bionic | 2019-04-02 00:07:23,472 INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.316817 | ubuntu-bionic | 2019-04-02 00:07:23,536 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 1301 microversion: 1.29
2019-04-02 00:07:32.316941 | ubuntu-bionic | 2019-04-02 00:07:23,568 INFO [nova.scheduler.host_manager] Host filter only checking host host2 and node host2
2019-04-02 00:07:32.317042 | ubuntu-bionic | 2019-04-02 00:07:23,568 INFO [nova.scheduler.host_manager] Host filter ignoring hosts:
2019-04-02 00:07:32.317219 | ubuntu-bionic | 2019-04-02 00:07:23,577 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.317398 | ubuntu-bionic | 2019-04-02 00:07:23,600 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 204 len: 0 microversion: 1.29
2019-04-02 00:07:32.317530 | ubuntu-bionic | 2019-04-02 00:07:23,894 INFO [nova.compute.manager] Took 0.11 seconds for pre_live_migration on destination host host2.
2019-04-02 00:07:32.317769 | ubuntu-bionic | 2019-04-02 00:07:23,984 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations" status: 200 len: 540 microversion: 2.72 time: 0.048497
2019-04-02 00:07:32.317876 | ubuntu-bionic | 2019-04-02 00:07:28,907 INFO [nova.compute.manager] _post_live_migration() is started..
2019-04-02 00:07:32.317985 | ubuntu-bionic | 2019-04-02 00:07:29,062 INFO [nova.compute.manager] Post operation of migration started
2019-04-02 00:07:32.318104 | ubuntu-bionic | 2019-04-02 00:07:29,203 WARNING [nova.compute.resource_tracker] Instance not resizing, skipping migration.
2019-04-02 00:07:32.318305 | ubuntu-bionic | 2019-04-02 00:07:29,221 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/109a2d73-cdf9-4d76-8e6e-74dc79ff7359/allocations" status: 200 len: 152 microversion: 1.0
2019-04-02 00:07:32.318422 | ubuntu-bionic | 2019-04-02 00:07:29,243 INFO [nova.compute.manager] Migrating instance to host2 finished successfully.
2019-04-02 00:07:32.318600 | ubuntu-bionic | 2019-04-02 00:07:29,260 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/1ef7333e-9209-46e5-8997-2372a7a2c1ca" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.318782 | ubuntu-bionic | 2019-04-02 00:07:29,356 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/1ef7333e-9209-46e5-8997-2372a7a2c1ca" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.318924 | ubuntu-bionic | 2019-04-02 00:07:29,357 INFO [nova.scheduler.client.report] Deleted allocation for migration 1ef7333e-9209-46e5-8997-2372a7a2c1ca
2019-04-02 00:07:32.319202 | ubuntu-bionic | 2019-04-02 00:07:29,391 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2196 microversion: 2.72 time: 0.110748
2019-04-02 00:07:32.319474 | ubuntu-bionic | 2019-04-02 00:07:29,414 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/os-services?binary=nova-compute&host=host2&" status: 200 len: 248 microversion: 2.72 time: 0.019628
2019-04-02 00:07:32.319730 | ubuntu-bionic | 2019-04-02 00:07:29,442 INFO [nova.api.openstack.requestlog] 127.0.0.1 "PUT /v2.1/6f70656e737461636b20342065766572/os-services/8b2330ad-82ec-40d7-98c8-facd2a4c415b" status: 200 len: 246 microversion: 2.72 time: 0.025102
2019-04-02 00:07:32.319962 | ubuntu-bionic | 2019-04-02 00:07:29,572 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/action" status: 200 len: 0 microversion: 2.72 time: 0.127196
2019-04-02 00:07:32.320210 | ubuntu-bionic | 2019-04-02 00:07:29,668 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2207 microversion: 2.72 time: 0.093253
2019-04-02 00:07:32.320431 | ubuntu-bionic | 2019-04-02 00:07:29,786 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 1301 microversion: 1.29
2019-04-02 00:07:32.320654 | ubuntu-bionic | 2019-04-02 00:07:29,801 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2207 microversion: 2.72 time: 0.129291
2019-04-02 00:07:32.320790 | ubuntu-bionic | 2019-04-02 00:07:29,815 INFO [nova.scheduler.host_manager] Host filter only checking host compute and node fake-mini
2019-04-02 00:07:32.320891 | ubuntu-bionic | 2019-04-02 00:07:29,815 INFO [nova.scheduler.host_manager] Host filter ignoring hosts:
2019-04-02 00:07:32.321074 | ubuntu-bionic | 2019-04-02 00:07:29,825 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 229 microversion: 1.28
2019-04-02 00:07:32.321249 | ubuntu-bionic | 2019-04-02 00:07:29,854 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 204 len: 0 microversion: 1.29
2019-04-02 00:07:32.321336 | ubuntu-bionic | 2019-04-02 00:07:29,903 INFO [nova.compute.manager] Evacuating instance
2019-04-02 00:07:32.321472 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] Attempting claim on node fake-mini: memory 512 MB, disk 1 GB, vcpus 1 CPU
2019-04-02 00:07:32.321578 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] Total memory: 800000 MB, used: 512.00 MB
2019-04-02 00:07:32.321732 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] memory limit not specified, defaulting to unlimited
2019-04-02 00:07:32.321848 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] Total disk: 600000 GB, used: 0.00 GB
2019-04-02 00:07:32.321965 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] disk limit not specified, defaulting to unlimited
2019-04-02 00:07:32.322101 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] Total vcpu: 1000 VCPU, used: 0.00 VCPU
2019-04-02 00:07:32.322223 | ubuntu-bionic | 2019-04-02 00:07:29,913 INFO [nova.compute.claims] vcpu limit not specified, defaulting to unlimited
2019-04-02 00:07:32.322323 | ubuntu-bionic | 2019-04-02 00:07:29,914 INFO [nova.compute.claims] Claim successful on node fake-mini
2019-04-02 00:07:32.322471 | ubuntu-bionic | 2019-04-02 00:07:29,958 INFO [nova.compute.resource_tracker] Updating resource usage from migration 668cec00-b769-40a9-9dba-c6b5d09c7c36
2019-04-02 00:07:32.322625 | ubuntu-bionic | 2019-04-02 00:07:29,967 INFO [nova.compute.manager] disk not on shared storage, evacuating from image: '155d900f-4e14-4e4c-a73d-069cbf4541e6'
2019-04-02 00:07:32.322803 | ubuntu-bionic | 2019-04-02 00:07:30,038 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 347 microversion: 1.28
2019-04-02 00:07:32.322928 | ubuntu-bionic | 2019-04-02 00:07:30,048 INFO [nova.compute.manager] Detaching volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113
2019-04-02 00:07:32.323153 | ubuntu-bionic | 2019-04-02 00:07:30,049 INFO [nova.virt.block_device] Attempting to driver detach volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 from mountpoint /dev/sdb
2019-04-02 00:07:32.323279 | ubuntu-bionic | 2019-04-02 00:07:30,049 WARNING [nova.virt.block_device] Detaching volume from unknown instance
2019-04-02 00:07:32.323472 | ubuntu-bionic | 2019-04-02 00:07:30,049 WARNING [nova.virt.block_device] Host mismatch detected, but stashed volume connector not found. Instance host is host2, but volume connector host is fakehost.
2019-04-02 00:07:32.323637 | ubuntu-bionic | 2019-04-02 00:07:30,093 INFO [nova.virt.block_device] Booting with volume a07f71dc-8151-4e7d-a0cc-cd24a3f11113 at /dev/sdb
2019-04-02 00:07:32.323886 | ubuntu-bionic | 2019-04-02 00:07:30,412 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2202 microversion: 2.72 time: 0.107966
2019-04-02 00:07:32.324138 | ubuntu-bionic | 2019-04-02 00:07:30,436 INFO [nova.api.openstack.requestlog] 127.0.0.1 "PUT /v2.1/6f70656e737461636b20342065766572/os-services/8b2330ad-82ec-40d7-98c8-facd2a4c415b" status: 200 len: 245 microversion: 2.72 time: 0.019086
2019-04-02 00:07:32.324378 | ubuntu-bionic | 2019-04-02 00:07:30,510 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2202 microversion: 2.72 time: 0.070536
2019-04-02 00:07:32.324607 | ubuntu-bionic | 2019-04-02 00:07:30,587 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/action" status: 202 len: 0 microversion: 2.72 time: 0.074523
2019-04-02 00:07:32.324830 | ubuntu-bionic | 2019-04-02 00:07:30,680 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 2212 microversion: 2.72 time: 0.089958
2019-04-02 00:07:32.325012 | ubuntu-bionic | 2019-04-02 00:07:30,691 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 347 microversion: 1.28
2019-04-02 00:07:32.325190 | ubuntu-bionic | 2019-04-02 00:07:30,725 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 347 microversion: 1.28
2019-04-02 00:07:32.325427 | ubuntu-bionic | 2019-04-02 00:07:30,729 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations" status: 200 len: 18 microversion: 2.72 time: 0.046856
2019-04-02 00:07:32.325603 | ubuntu-bionic | 2019-04-02 00:07:30,733 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/ec22d969-75a1-4a35-b571-1e1f7088b600" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.325745 | ubuntu-bionic | 2019-04-02 00:07:30,764 INFO [placement.requestlog] 127.0.0.1 "POST /placement/allocations" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.325963 | ubuntu-bionic | 2019-04-02 00:07:30,812 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocation_candidates?limit=1000&resources=DISK_GB%3A1%2CMEMORY_MB%3A512%2CVCPU%3A1" status: 200 len: 1303 microversion: 1.29
2019-04-02 00:07:32.326088 | ubuntu-bionic | 2019-04-02 00:07:30,838 INFO [nova.scheduler.host_manager] Host filter only checking host host2 and node host2
2019-04-02 00:07:32.326191 | ubuntu-bionic | 2019-04-02 00:07:30,838 INFO [nova.scheduler.host_manager] Host filter ignoring hosts:
2019-04-02 00:07:32.326369 | ubuntu-bionic | 2019-04-02 00:07:30,846 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 200 len: 19 microversion: 1.28
2019-04-02 00:07:32.326547 | ubuntu-bionic | 2019-04-02 00:07:30,867 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/dc76de5a-d330-462a-9b6b-a15d59ac9199" status: 204 len: 0 microversion: 1.29
2019-04-02 00:07:32.326681 | ubuntu-bionic | 2019-04-02 00:07:31,148 INFO [nova.compute.manager] Took 0.08 seconds for pre_live_migration on destination host host2.
2019-04-02 00:07:32.326950 | ubuntu-bionic | 2019-04-02 00:07:31,290 INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations" status: 200 len: 540 microversion: 2.72 time: 0.056536
2019-04-02 00:07:32.327254 | ubuntu-bionic | 2019-04-02 00:07:31,343 INFO [nova.api.openstack.requestlog] 127.0.0.1 "POST /v2.1/6f70656e737461636b20342065766572/servers/dc76de5a-d330-462a-9b6b-a15d59ac9199/migrations/5/action" status: 202 len: 0 microversion: 2.72 time: 0.049056
2019-04-02 00:07:32.327378 | ubuntu-bionic | 2019-04-02 00:07:31,882 INFO [nova.compute.manager] _post_live_migration() is started..
2019-04-02 00:07:32.327480 | ubuntu-bionic | 2019-04-02 00:07:31,942 INFO [nova.compute.manager] Post operation of migration started
2019-04-02 00:07:32.327600 | ubuntu-bionic | 2019-04-02 00:07:32,069 WARNING [nova.compute.resource_tracker] Instance not resizing, skipping migration.
2019-04-02 00:07:32.327795 | ubuntu-bionic | 2019-04-02 00:07:32,086 INFO [placement.requestlog] 127.0.0.1 "GET /placement/resource_providers/109a2d73-cdf9-4d76-8e6e-74dc79ff7359/allocations" status: 200 len: 153 microversion: 1.0
2019-04-02 00:07:32.327927 | ubuntu-bionic | 2019-04-02 00:07:32,094 WARNING [nova.compute.manager] Compute node 'fake-mini' not found in update_available_resource.
2019-04-02 00:07:32.328050 | ubuntu-bionic | 2019-04-02 00:07:32,105 INFO [nova.compute.manager] Migrating instance to host2 finished successfully.
2019-04-02 00:07:32.328290 | ubuntu-bionic | 2019-04-02 00:07:32,131 INFO [placement.requestlog] 127.0.0.1 "GET /placement/allocations/ec22d969-75a1-4a35-b571-1e1f7088b600" status: 200 len: 347 microversion: 1.28
2019-04-02 00:07:32.328473 | ubuntu-bionic | 2019-04-02 00:07:32,154 INFO [placement.requestlog] 127.0.0.1 "PUT /placement/allocations/ec22d969-75a1-4a35-b571-1e1f7088b600" status: 204 len: 0 microversion: 1.28
2019-04-02 00:07:32.328605 | ubuntu-bionic | 2019-04-02 00:07:32,155 INFO [nova.scheduler.client.report] Deleted allocation for migration ec22d969-75a1-4a35-b571-1e1f7088b600
2019-04-02 00:07:32.328708 | ubuntu-bionic | 2019-04-02 00:07:32,230 INFO [oslo_db.sqlalchemy.provision] DROP ALL OBJECTS, BACKEND sqlite://
2019-04-02 00:07:32.328813 | ubuntu-bionic | 2019-04-02 00:07:32,268 INFO [oslo_db.sqlalchemy.provision] DISPOSE ENGINE Engine(sqlite://)
I've seen this hit in two changes in logstash:
http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22File%20%5C%5C%5C%22nova%2Ftests%2Ffunctional%2Fnotification_sample_tests%2Ftest_instance.py%5C%5C%5C%22%5C%22%20AND%20message%3A%5C%22in%20_test_live_migration_force_complete%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d
But as far as I can tell those changes should have no relation to what this test is doing (NotificationSampleTestBase does not inherit from ProviderUsageBaseTestCase).
We likely need to dump the notifications when this fails to get a better idea of what's going on.
Related fix proposed to branch: master
Review: https:/