Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

No valid host was found during instance migrate

I am not sure what I am missing here. I am trying to migrate instances from one host to another but now stuck at "No valid host was found" after migrating some instances successfully. It seems though nova thinks there are no resources but there are no logs at all pertaining to the destination host.

I have a 3-node set up: 1 x controller and 2 x compute nodes. I have call the compute hosts compute-0 and compute-1 hosts. The compute nodes have shared iscsi storage from cinder. Before live migrating actions, we have instances running on both hosts without issue.

Version is Pike.

I was initially trying to migrate instances using the "openstack server migrate" command, but I was getting errors about there not being enough free disk on the destination. This is due to a bug with that specific command and using "nova live-migration" command instead was able to immediately live migrate. But now I have run into another issue and cannot work through it.

I am checking logs in: nova-scheduler.log nova-api.log nova-conductor.log nova-placement-api.log nova-manage.log nova-rowsflush.log

I am trying to migrate an instance from compute-0 to compute-1. I ran a tail on all of those logs and receive this output below. I cannot see any detail pertaining to compute-1 but the logs state no available hosts. Compute-0 host has the compute service disabled to prevent new VMs from being scheduled there.

I am unable to spawn new instances also.

I am trying to do this with the command: nova live-migration 8b51e704-b2fb-4674-8d82-debe0c9ea9d2 --block-migrate

Log output:

2018-07-18 06:06:37.289 129727 DEBUG nova.api.openstack.wsgi [req-1cc7ff66-7f96-41e1-ad50-ee1b2040e0e2 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:37.291 129727 INFO nova.api.openstack.requestlog [req-1cc7ff66-7f96-41e1-ad50-ee1b2040e0e2 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.002323

==> nova-placement-api.log <==
2018-07-18 06:06:37.481 129735 DEBUG nova.api.openstack.placement.requestlog [req-a08d6981-96d0-4f79-aaaf-630e03995fcb 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] Starting request: 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/aggregates" __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/placement/requestlog.py:38
2018-07-18 06:06:37.503 129735 INFO nova.api.openstack.placement.requestlog [req-a08d6981-96d0-4f79-aaaf-630e03995fcb 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/aggregates" status: 200 len: 18 microversion: 1.1
2018-07-18 06:06:37.515 129735 DEBUG nova.api.openstack.placement.requestlog [req-eeaa41ec-44d2-4cdd-b25b-d2af28279861 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] Starting request: 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/inventories" __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/placement/requestlog.py:38
2018-07-18 06:06:37.538 129735 INFO nova.api.openstack.placement.requestlog [req-eeaa41ec-44d2-4cdd-b25b-d2af28279861 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/inventories" status: 200 len: 406 microversion: 1.0

==> nova-api.log <==
2018-07-18 06:06:37.951 4617 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0013440

==> nova-placement-api.log <==
2018-07-18 06:06:38.212 129735 DEBUG nova.api.openstack.placement.requestlog [req-9d8e75e4-1085-47e3-9658-c21c7c793e09 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] Starting request: 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/allocations" __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/placement/requestlog.py:38
2018-07-18 06:06:38.348 129735 INFO nova.api.openstack.placement.requestlog [req-9d8e75e4-1085-47e3-9658-c21c7c793e09 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/allocations" status: 200 len: 4172 microversion: 1.0

==> nova-api.log <==
2018-07-18 06:06:38.395 129727 DEBUG nova.api.openstack.wsgi [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method ServersController.detail of <nova.api.openstack.compute.servers.ServersController object at 0x7f74aab89490>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:38.403 129727 DEBUG nova.compute.api [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Searching by: {'deleted': False, 'project_id': u'5664df646f7e41188b5a0ea52e2dadfc'} get_all /usr/lib/python2.7/site-packages/nova/compute/api.py:2311
2018-07-18 06:06:38.441 129727 DEBUG oslo_concurrency.lockutils [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:38.443 129727 DEBUG oslo_concurrency.lockutils [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:38.580 129727 DEBUG nova.compute.api [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Skipping already-collected cell0 list _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2511
2018-07-18 06:06:38.582 129727 DEBUG nova.compute.api [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Listing 1000 instances in cell 927dc4d6-83fa-4a3d-9634-15946076de61(default) _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2514
2018-07-18 06:06:38.584 129727 DEBUG oslo_concurrency.lockutils [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:38.586 129727 DEBUG oslo_concurrency.lockutils [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:38.741 129727 DEBUG nova.policy [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Policy check for os_compute_api:os-extended-server-attributes failed with credentials {'service_roles': [], 'user_id': u'56c3e72fe9a14b1bbe3eebe3a906478a', 'roles': [u'_member_'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': False, 'project_id': u'5664df646f7e41188b5a0ea52e2dadfc', 'project_domain_id': u'c1fbcd738b6b4b40a82d82e5e010aa4d'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168

==> nova-placement-api.log <==
2018-07-18 06:06:38.803 129735 DEBUG nova.api.openstack.placement.requestlog [req-f44d523e-419e-4d1d-917e-dcce139224dc 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] Starting request: 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/aggregates" __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/placement/requestlog.py:38

==> nova-api.log <==
2018-07-18 06:06:38.809 129727 INFO nova.api.openstack.requestlog [req-fce4277b-f5fd-462b-928d-6d02b7dccdcb 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "GET /v2.1/servers/detail" status: 200 len: 15 microversion: 2.1 time: 1.133258

==> nova-placement-api.log <==
2018-07-18 06:06:38.848 129735 INFO nova.api.openstack.placement.requestlog [req-f44d523e-419e-4d1d-917e-dcce139224dc 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/aggregates" status: 200 len: 18 microversion: 1.1
2018-07-18 06:06:38.867 129735 DEBUG nova.api.openstack.placement.requestlog [req-1aff6e6a-eff5-48c3-9177-8f2c371d93ce 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] Starting request: 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/inventories" __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/placement/requestlog.py:38
2018-07-18 06:06:38.903 129735 INFO nova.api.openstack.placement.requestlog [req-1aff6e6a-eff5-48c3-9177-8f2c371d93ce 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] 192.168.18.102 "GET /placement/resource_providers/0d2f7450-c02c-4a12-a29a-54cb34ed07d0/inventories" status: 200 len: 406 microversion: 1.0

==> nova-api.log <==
2018-07-18 06:06:39.935 129727 DEBUG nova.api.openstack.wsgi [req-1cc7ff66-7f96-41e1-ad50-ee1b2040e0e2 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:39.937 129727 INFO nova.api.openstack.requestlog [req-1cc7ff66-7f96-41e1-ad50-ee1b2040e0e2 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.002291
2018-07-18 06:06:39.955 4617 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0007391
2018-07-18 06:06:41.941 129727 DEBUG nova.api.openstack.wsgi [req-1cc7ff66-7f96-41e1-ad50-ee1b2040e0e2 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:41.944 129727 INFO nova.api.openstack.requestlog [req-1cc7ff66-7f96-41e1-ad50-ee1b2040e0e2 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.003006
2018-07-18 06:06:41.967 4615 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0012538
2018-07-18 06:06:42.981 129727 INFO nova.api.openstack.requestlog [req-f16e672d-14ea-4a47-b05e-2034f5d961fe 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "GET /v2.1" status: 302 len: None microversion: - time: 1.587271
2018-07-18 06:06:43.037 129727 DEBUG nova.api.openstack.wsgi [req-23551ced-42ec-4e6b-9ab2-849d06d175bb 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method VersionsController.show of <nova.api.openstack.compute.versionsV21.VersionsController object at 0x7f74aa48a390>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:43.040 129727 INFO nova.api.openstack.requestlog [req-23551ced-42ec-4e6b-9ab2-849d06d175bb 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "GET /v2.1/" status: 200 len: 388 microversion: 2.1 time: 0.035379
2018-07-18 06:06:43.744 129727 DEBUG nova.api.openstack.wsgi [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method ServersController.show of <nova.api.openstack.compute.servers.ServersController object at 0x7f74aacb67d0>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:43.762 129727 DEBUG nova.compute.api [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] [instance: 8b51e704-b2fb-4674-8d82-debe0c9ea9d2] Fetching instance by UUID get /usr/lib/python2.7/site-packages/nova/compute/api.py:2279
2018-07-18 06:06:43.840 129727 DEBUG oslo_concurrency.lockutils [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:43.841 129727 DEBUG oslo_concurrency.lockutils [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:43.984 4615 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0008090
2018-07-18 06:06:43.991 129727 DEBUG nova.api.openstack.wsgi [req-23551ced-42ec-4e6b-9ab2-849d06d175bb 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:43.992 129727 INFO nova.api.openstack.requestlog [req-23551ced-42ec-4e6b-9ab2-849d06d175bb 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.001655
2018-07-18 06:06:44.109 129727 DEBUG nova.objects.instance [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lazy-loading 'services' on Instance uuid 8b51e704-b2fb-4674-8d82-debe0c9ea9d2 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1048
2018-07-18 06:06:44.320 129727 DEBUG nova.policy [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731', 'roles': [u'_member_', u'admin'], 'user_domain_id': u'c1fbcd738b6b4b40a82d82e5e010aa4d', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'project_id': u'a1c09ae7084b4fbe9de5d7a17112b4c0', 'project_domain_id': u'c1fbcd738b6b4b40a82d82e5e010aa4d'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168
2018-07-18 06:06:44.542 129727 DEBUG nova.api.openstack.wsgi [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method ServersController.detail of <nova.api.openstack.compute.servers.ServersController object at 0x7f74aab89490>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:44.578 129727 DEBUG nova.compute.api [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Searching by: {'deleted': False, 'project_id': u'5664df646f7e41188b5a0ea52e2dadfc'} get_all /usr/lib/python2.7/site-packages/nova/compute/api.py:2311
2018-07-18 06:06:44.653 129727 DEBUG oslo_concurrency.lockutils [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:44.654 129727 DEBUG oslo_concurrency.lockutils [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:44.785 129727 DEBUG nova.compute.api [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Skipping already-collected cell0 list _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2511
2018-07-18 06:06:44.786 129727 DEBUG nova.compute.api [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Listing 1000 instances in cell 927dc4d6-83fa-4a3d-9634-15946076de61(default) _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2514
2018-07-18 06:06:44.788 129727 DEBUG oslo_concurrency.lockutils [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:44.788 129727 DEBUG oslo_concurrency.lockutils [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:44.944 129727 DEBUG nova.policy [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Policy check for os_compute_api:os-extended-server-attributes failed with credentials {'service_roles': [], 'user_id': u'56c3e72fe9a14b1bbe3eebe3a906478a', 'roles': [u'_member_'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': False, 'project_id': u'5664df646f7e41188b5a0ea52e2dadfc', 'project_domain_id': u'c1fbcd738b6b4b40a82d82e5e010aa4d'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168
2018-07-18 06:06:45.010 129727 INFO nova.api.openstack.requestlog [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "GET /v2.1/servers/detail" status: 200 len: 15 microversion: 2.1 time: 2.144797
2018-07-18 06:06:45.992 4606 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0011761
2018-07-18 06:06:46.027 129727 DEBUG nova.api.openstack.wsgi [-] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:46.029 129727 INFO nova.api.openstack.requestlog [-] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.002547
2018-07-18 06:06:48.009 4616 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0083840
2018-07-18 06:06:48.053 129727 DEBUG nova.api.openstack.wsgi [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:48.056 129727 INFO nova.api.openstack.requestlog [req-124c1c8b-be5c-4cb6-99bb-46ec23c67aba 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.003139
2018-07-18 06:06:48.296 129727 INFO nova.api.openstack.requestlog [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "GET /v2.1/servers/8b51e704-b2fb-4674-8d82-debe0c9ea9d2" status: 200 len: 2111 microversion: 2.25 time: 4.612656
2018-07-18 06:06:48.357 129727 DEBUG nova.api.openstack.wsgi [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Action: 'action', calling method: <bound method MigrateServerController._migrate_live of <nova.api.openstack.compute.migrate_server.MigrateServerController object at 0x7f74aaddb8d0>>, body: {"os-migrateLive": {"block_migration": true, "host": null}} _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:609
2018-07-18 06:06:48.371 129727 DEBUG nova.compute.api [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] [instance: 8b51e704-b2fb-4674-8d82-debe0c9ea9d2] Fetching instance by UUID get /usr/lib/python2.7/site-packages/nova/compute/api.py:2279
2018-07-18 06:06:48.437 129727 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:48.438 129727 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:48.723 129727 DEBUG nova.compute.api [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] [instance: 8b51e704-b2fb-4674-8d82-debe0c9ea9d2] Going to try to live migrate instance to another host live_migrate /usr/lib/python2.7/site-packages/nova/compute/api.py:3901
2018-07-18 06:06:49.042 129727 DEBUG nova.objects.instance [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lazy-loading 'flavor' on Instance uuid 8b51e704-b2fb-4674-8d82-debe0c9ea9d2 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1048

==> nova-conductor.log <==
2018-07-18 06:06:49.702 117415 DEBUG oslo_db.sqlalchemy.engines [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285
2018-07-18 06:06:49.745 117415 DEBUG nova.conductor.manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Targeting cell 927dc4d6-83fa-4a3d-9634-15946076de61(default) for conductor method migrate_server wrapper /usr/lib/python2.7/site-packages/nova/conductor/manager.py:78
2018-07-18 06:06:49.748 117415 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:49.763 117415 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.015s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:49.905 117415 DEBUG oslo_db.sqlalchemy.engines [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py:285

==> nova-api.log <==
2018-07-18 06:06:49.905 129727 DEBUG nova.api.openstack.wsgi [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method ServersController.detail of <nova.api.openstack.compute.servers.ServersController object at 0x7f74aab89490>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:49.911 129727 DEBUG nova.compute.api [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Searching by: {'deleted': False, 'project_id': u'5664df646f7e41188b5a0ea52e2dadfc'} get_all /usr/lib/python2.7/site-packages/nova/compute/api.py:2311
2018-07-18 06:06:50.014 129727 DEBUG oslo_concurrency.lockutils [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:50.015 129727 DEBUG oslo_concurrency.lockutils [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:50.023 4606 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0100560
2018-07-18 06:06:50.131 129727 DEBUG nova.api.openstack.wsgi [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:50.150 129727 INFO nova.api.openstack.requestlog [req-ba192f51-bee3-42bf-aa77-ec5f468547ca 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.019276
2018-07-18 06:06:50.227 129727 DEBUG nova.compute.api [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Skipping already-collected cell0 list _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2511
2018-07-18 06:06:50.228 129727 DEBUG nova.compute.api [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Listing 1000 instances in cell 927dc4d6-83fa-4a3d-9634-15946076de61(default) _get_instances_by_filters_all_cells /usr/lib/python2.7/site-packages/nova/compute/api.py:2514
2018-07-18 06:06:50.230 129727 DEBUG oslo_concurrency.lockutils [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:50.231 129727 DEBUG oslo_concurrency.lockutils [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282

==> nova-conductor.log <==
2018-07-18 06:06:50.428 117415 DEBUG nova.conductor.tasks.live_migrate [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] [instance: 8b51e704-b2fb-4674-8d82-debe0c9ea9d2] Requesting cell 927dc4d6-83fa-4a3d-9634-15946076de61(default) while live migrating _find_destination /usr/lib/python2.7/site-packages/nova/conductor/tasks/live_migrate.py:257

==> nova-api.log <==
2018-07-18 06:06:50.500 129727 DEBUG nova.policy [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] Policy check for os_compute_api:os-extended-server-attributes failed with credentials {'service_roles': [], 'user_id': u'56c3e72fe9a14b1bbe3eebe3a906478a', 'roles': [u'_member_'], 'user_domain_id': u'default', 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': False, 'project_id': u'5664df646f7e41188b5a0ea52e2dadfc', 'project_domain_id': u'c1fbcd738b6b4b40a82d82e5e010aa4d'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168
2018-07-18 06:06:50.575 129727 INFO nova.api.openstack.requestlog [req-70877c2c-0c68-4375-876e-fe0bec0be4fd 56c3e72fe9a14b1bbe3eebe3a906478a 5664df646f7e41188b5a0ea52e2dadfc - default c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "GET /v2.1/servers/detail" status: 200 len: 15 microversion: 2.1 time: 2.343237

==> nova-scheduler.log <==
2018-07-18 06:06:50.754 117511 DEBUG nova.scheduler.manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Starting to schedule for instances: [u'8b51e704-b2fb-4674-8d82-debe0c9ea9d2'] select_destinations /usr/lib/python2.7/site-packages/nova/scheduler/manager.py:113

==> nova-placement-api.log <==
2018-07-18 06:06:50.804 129735 DEBUG nova.api.openstack.placement.requestlog [req-e997c7cd-5a0e-40fb-b6fd-5fa81faccfad 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] Starting request: 192.168.18.102 "GET /placement/allocation_candidates?resources=DISK_GB%3A8%2CMEMORY_MB%3A8192%2CVCPU%3A2" __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/placement/requestlog.py:38
2018-07-18 06:06:51.118 129735 INFO nova.api.openstack.placement.requestlog [req-e997c7cd-5a0e-40fb-b6fd-5fa81faccfad 5418126b8be04f8cb00ead0e9714df3b b7fd1b7ff742439f96c8b46d13f3f963 - default default] 192.168.18.102 "GET /placement/allocation_candidates?resources=DISK_GB%3A8%2CMEMORY_MB%3A8192%2CVCPU%3A2" status: 200 len: 388 microversion: 1.10

==> nova-scheduler.log <==
2018-07-18 06:06:51.156 117511 DEBUG nova.scheduler.host_manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Getting compute nodes and services for cell 927dc4d6-83fa-4a3d-9634-15946076de61(default) _get_computes_for_cells /usr/lib/python2.7/site-packages/nova/scheduler/host_manager.py:621
2018-07-18 06:06:51.164 117511 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:51.165 117511 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "927dc4d6-83fa-4a3d-9634-15946076de61" released by "nova.context.get_or_set_cached_cell_and_set_connections" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:51.252 117511 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "(u'overcloud-novacompute-0.company.com', u'overcloud-novacompute-0.company.com')" acquired by "nova.scheduler.host_manager._locked_update" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-07-18 06:06:51.254 117511 DEBUG nova.scheduler.host_manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Update host state from compute node: ComputeNode(cpu_allocation_ratio=16.0,cpu_info='{"vendor": "Intel", "model": "SandyBridge", "arch": "x86_64", "features": ["pge", "avx", "xsaveopt", "clflush", "sep", "syscall", "tsc-deadline", "dtes64", "msr", "xsave", "vmx", "xtpr", "cmov", "pcid", "est", "pat", "monitor", "smx", "pbe", "lm", "tsc", "nx", "fxsr", "tm", "sse4.1", "pae", "sse4.2", "pclmuldq", "acpi", "vme", "mmx", "osxsave", "cx8", "mce", "de", "rdtscp", "ht", "dca", "lahf_lm", "pdcm", "mca", "pdpe1gb", "apic", "sse", "pse", "ds", "invtsc", "pni", "tm2", "aes", "sse2", "ss", "ds_cpl", "arat", "ssse3", "fpu", "cx16", "pse36", "mtrr", "popcnt", "x2apic"], "topology": {"cores": 6, "cells": 2, "threads": 2, "sockets": 1}}',created_at=2018-02-18T15:44:39Z,current_workload=0,deleted=False,deleted_at=None,disk_allocation_ratio=1.0,disk_available_least=102,free_disk_gb=178,free_ram_mb=18362,host='overcloud-novacompute-0.company.com',host_ip=192.168.18.106,hypervisor_hostname='overcloud-novacompute-0.company.com',hypervisor_type='QEMU',hypervisor_version=2009000,id=1,local_gb=278,local_gb_used=100,mapped=1,memory_mb=65466,memory_mb_used=47104,metrics='[]',numa_topology='{"nova_object.version": "1.2", "nova_object.changes": ["cells"], "nova_object.name": "NUMATopology", "nova_object.data": {"cells": [{"nova_object.version": "1.2", "nova_object.changes": ["cpu_usage", "memory_usage", "cpuset", "pinned_cpus", "siblings", "memory", "mempages", "id"], "nova_object.name": "NUMACell", "nova_object.data": {"cpu_usage": 0, "memory_usage": 0, "cpuset": [0, 1, 2, 3, 4, 5, 12, 13, 14, 15, 16, 17], "pinned_cpus": [], "siblings": [[3, 15], [17, 5], [1, 13], [16, 4], [0, 12], [2, 14]], "memory": 32698, "mempages": [{"nova_object.version": "1.1", "nova_object.changes": ["total", "used", "reserved", "size_kb"], "nova_object.name": "NUMAPagesTopology", "nova_object.data": {"used": 0, "total": 8370740, "reserved": 0, "size_kb": 4}, "nova_object.namespace": "nova"}, {"nova_object.version": "1.1", "nova_object.changes": ["total", "used", "reserved", "size_kb"], "nova_object.name": "NUMAPagesTopology", "nova_object.data": {"used": 0, "total": 0, "reserved": 0, "size_kb": 2048}, "nova_object.namespace": "nova"}, {"nova_object.version": "1.1", "nova_object.changes": ["total", "used", "reserved", "size_kb"], "nova_object.name": "NUMAPagesTopology", "nova_object.data": {"used": 0, "total": 0, "reserved": 0, "size_kb": 1048576}, "nova_object.namespace": "nova"}], "id": 0}, "nova_object.namespace": "nova"}, {"nova_object.version": "1.2", "nova_object.changes": ["cpu_usage", "memory_usage", "cpuset", "pinned_cpus", "siblings", "memory", "mempages", "id"], "nova_object.name": "NUMACell", "nova_object.data": {"cpu_usage": 0, "memory_usage": 0, "cpuset": [6, 7, 8, 9, 10, 11, 18, 19, 20, 21, 22, 23], "pinned_cpus": [], "siblings": [[19, 7], [8, 20], [11, 23], [18, 6], [9, 21], [10, 22]], "memory": 32768, "mempages": [{"nova_object.version": "1.1", "nova_object.changes": ["total", "used", "reserved", "size_kb"], "nova_object.name": "NUMAPagesTopology", "nova_object.data": {"used": 0, "total": 8388608, "reserved": 0, "size_kb": 4}, "nova_object.namespace": "nova"}, {"nova_object.version": "1.1", "nova_object.changes": ["total", "used", "reserved", "size_kb"], "nova_object.name": "NUMAPagesTopology", "nova_object.data": {"used": 0, "total": 0, "reserved": 0, "size_kb": 2048}, "nova_object.namespace": "nova"}, {"nova_object.version": "1.1", "nova_object.changes": ["total", "used", "reserved", "size_kb"], "nova_object.name": "NUMAPagesTopology", "nova_object.data": {"used": 0, "total": 0, "reserved": 0, "size_kb": 1048576}, "nova_object.namespace": "nova"}], "id": 1}, "nova_object.namespace": "nova"}]}, "nova_object.namespace": "nova"}',pci_device_pools=PciDevicePoolList,ram_allocation_ratio=1.5,running_vms=9,service_id=None,stats={io_workload='0',num_instances='9',num_os_type_None='9',num_proj_5dc14ca238784d0bb98aa2b9e5c85660='5',num_proj_89ad005b9562434e9bbfb45f8f3d2c5a='4',num_task_None='9',num_vm_active='8',num_vm_stopped='1'},supported_hv_specs=[HVSpec,HVSpec,HVSpec,HVSpec],updated_at=2018-07-18T06:05:57Z,uuid=ed04d796-439f-49b0-ace7-a377b2452761,vcpus=24,vcpus_used=17) _locked_update /usr/lib/python2.7/site-packages/nova/scheduler/host_manager.py:172
2018-07-18 06:06:51.260 117511 DEBUG nova.scheduler.host_manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Update host state with aggregates: [] _locked_update /usr/lib/python2.7/site-packages/nova/scheduler/host_manager.py:175
2018-07-18 06:06:51.261 117511 DEBUG nova.scheduler.host_manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Update host state with service dict: {'binary': u'nova-compute', 'uuid': '00819a18-2a67-43b1-895e-74812f783453', 'deleted': False, 'created_at': datetime.datetime(2018, 2, 18, 15, 44, 38, tzinfo=<iso8601.Utc>), 'updated_at': datetime.datetime(2018, 7, 18, 6, 6, 50, tzinfo=<iso8601.Utc>), 'report_count': 1292124, 'topic': u'compute', 'host': u'overcloud-novacompute-0.company.com', 'version': 22, 'disabled': True, 'forced_down': False, 'last_seen_up': datetime.datetime(2018, 7, 18, 6, 6, 50, tzinfo=<iso8601.Utc>), 'deleted_at': None, 'disabled_reason': u'live mig', 'id': 5} _locked_update /usr/lib/python2.7/site-packages/nova/scheduler/host_manager.py:178

2018-07-18 06:06:51.290 117511 DEBUG oslo_concurrency.lockutils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lock "(u'overcloud-novacompute-0.company.com', u'overcloud-novacompute-0.company.com')" released by "nova.scheduler.host_manager._locked_update" :: held 0.038s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-07-18 06:06:51.292 117511 INFO nova.scheduler.host_manager [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Host filter ignoring hosts: overcloud-novacompute-0.company.com
2018-07-18 06:06:51.293 117511 DEBUG nova.scheduler.filter_scheduler [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Filtered [] _get_sorted_hosts /usr/lib/python2.7/site-packages/nova/scheduler/filter_scheduler.py:313
2018-07-18 06:06:51.293 117511 DEBUG nova.scheduler.filter_scheduler [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] There are 0 hosts available but 1 instances requested to build. select_destinations /usr/lib/python2.7/site-packages/nova/scheduler/filter_scheduler.py:107

==> nova-conductor.log <==
2018-07-18 06:06:51.308 117415 WARNING nova.scheduler.utils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Failed to compute_task_migrate_server: No valid host was found. There are not enough hosts available.
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 232, in inner
    return func(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/scheduler/manager.py", line 149, in select_destinations
    alloc_reqs_by_rp_uuid, provider_summaries)

  File "/usr/lib/python2.7/site-packages/nova/scheduler/filter_scheduler.py", line 110, in select_destinations
    raise exception.NoValidHost(reason=reason)

NoValidHost: No valid host was found. There are not enough hosts available.
: NoValidHost_Remote: No valid host was found. There are not enough hosts available.
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 232, in inner
    return func(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/scheduler/manager.py", line 149, in select_destinations
    alloc_reqs_by_rp_uuid, provider_summaries)

  File "/usr/lib/python2.7/site-packages/nova/scheduler/filter_scheduler.py", line 110, in select_destinations
    raise exception.NoValidHost(reason=reason)

NoValidHost: No valid host was found. There are not enough hosts available.
2018-07-18 06:06:51.310 117415 WARNING nova.scheduler.utils [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] [instance: 8b51e704-b2fb-4674-8d82-debe0c9ea9d2] Setting instance to ACTIVE state.: NoValidHost_Remote: No valid host was found. There are not enough hosts available.
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 232, in inner
    return func(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/nova/scheduler/manager.py", line 149, in select_destinations
    alloc_reqs_by_rp_uuid, provider_summaries)

  File "/usr/lib/python2.7/site-packages/nova/scheduler/filter_scheduler.py", line 110, in select_destinations
    raise exception.NoValidHost(reason=reason)

NoValidHost: No valid host was found. There are not enough hosts available.
2018-07-18 06:06:51.585 117415 DEBUG nova.objects.instance [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lazy-loading 'metadata' on Instance uuid 8b51e704-b2fb-4674-8d82-debe0c9ea9d2 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1048
2018-07-18 06:06:51.760 117415 DEBUG nova.objects.instance [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Lazy-loading 'info_cache' on Instance uuid 8b51e704-b2fb-4674-8d82-debe0c9ea9d2 obj_load_attr /usr/lib/python2.7/site-packages/nova/objects/instance.py:1048

==> nova-api.log <==
2018-07-18 06:06:52.034 4606 INFO nova.metadata.wsgi.server [-] 192.168.18.102 "OPTIONS / HTTP/1.0" status: 200 len: 234 time: 0.0011919
2018-07-18 06:06:52.163 129727 DEBUG nova.api.openstack.wsgi [req-23551ced-42ec-4e6b-9ab2-849d06d175bb 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f74aaf45e10>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:612
2018-07-18 06:06:52.165 129727 INFO nova.api.openstack.requestlog [req-23551ced-42ec-4e6b-9ab2-849d06d175bb 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "OPTIONS /" status: 200 len: 439 microversion: - time: 0.003026
2018-07-18 06:06:52.329 129727 INFO nova.api.openstack.wsgi [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] HTTP exception thrown: No valid host was found. There are not enough hosts available.
2018-07-18 06:06:52.331 129727 DEBUG nova.api.openstack.wsgi [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] Returning 400 to user: No valid host was found. There are not enough hosts available. __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:1029
2018-07-18 06:06:52.333 129727 INFO nova.api.openstack.requestlog [req-fe846a7a-294c-463c-8272-69caf946c8d9 8581214b931a55344f5d9b39916ac246b0ef3bc441914e5711f846c34d50c731 a1c09ae7084b4fbe9de5d7a17112b4c0 - c1fbcd738b6b4b40a82d82e5e010aa4d c1fbcd738b6b4b40a82d82e5e010aa4d] 192.168.18.102 "POST /v2.1/servers/8b51e704-b2fb-4674-8d82-debe0c9ea9d2/action" status: 400 len: 106 microversion: 2.25 time: 4.004090

Any ideas here?

I did run this command and saw disk with a negative value.

nova hypervisor-stats
+----------------------+--------+
| Property             | Value  |
+----------------------+--------+
| count                | 1      |
| current_workload     | 0      |
| disk_available_least | -13    |
| free_disk_gb         | 98     |
| free_ram_mb          | 25018  |
| local_gb             | 278    |
| local_gb_used        | 180    |
| memory_mb            | 131002 |
| memory_mb_used       | 105984 |
| running_vms          | 40     |
| vcpus                | 24     |
| vcpus_used           | 58     |
+----------------------+--------+

Instances should not consume disk anyway but I tried to set the scheduler filters to ignore disk. I was going to try setting a high overcommit but the nova.conf says that value is ignored in Pike. Anyway, I am not seeing any log message that says a reason to ignore compute-1 for live migration so I am a bit stumped.