This is nova-compute log
2018-02-22 07:19:42.899 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._check_instance_build_time run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:42.901 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:42.948 5 DEBUG nova.compute.resource_tracker [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Auditing locally available compute resources for kolla (node: domain-c7.A9A92EE9-9488-4840-9F21-57E5EFC9B133) update_available_resource /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:640
2018-02-22 07:19:42.960 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-26019f35-1067-4fdc-b728-48979804b0b5 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:42.991 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-ff16a8b0-3c64-4223-a827-529c0001c246 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:43.026 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-72206dab-5421-411b-9c7f-9e8576c95a2e request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:43.065 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-ffa55cf0-bed9-4ffd-99aa-1fa56c616590 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:43.619 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-c3c5fd57-dc15-421a-97bd-f8021fa3aa96 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:43.660 5 DEBUG nova.compute.resource_tracker [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Hypervisor/Node resource view: name=domain-c7.A9A92EE9-9488-4840-9F21-57E5EFC9B133 free_ram=1374MB free_disk=39GB free_vcpus=2 pci_devices=None _report_hypervisor_resource_view /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:776
2018-02-22 07:19:43.661 5 DEBUG oslo_concurrency.lockutils [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Lock "compute_resources" acquired by "nova.compute.resource_tracker._update_available_resource" :: waited 0.000s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-02-22 07:19:43.749 5 DEBUG nova.scheduler.client.report [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Refreshing aggregate associations for resource provider 838382f7-e055-4b4d-9ae5-45ffcdde2ffd _ensure_resource_provider /var/lib/kolla/venv/lib/python2.7/site-packages/nova/scheduler/client/report.py:498
2018-02-22 07:19:44.004 5 DEBUG nova.compute.resource_tracker [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Total usable vcpus: 2, total allocated vcpus: 0 _report_final_resource_view /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:792
2018-02-22 07:19:44.004 5 INFO nova.compute.resource_tracker [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Final resource view: name=domain-c7.A9A92EE9-9488-4840-9F21-57E5EFC9B133 phys_ram=1374MB used_ram=512MB phys_disk=72GB used_disk=0GB total_vcpus=2 used_vcpus=0 pci_stats=[]
2018-02-22 07:19:44.086 5 DEBUG nova.scheduler.client.report [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Refreshing aggregate associations for resource provider 838382f7-e055-4b4d-9ae5-45ffcdde2ffd _ensure_resource_provider /var/lib/kolla/venv/lib/python2.7/site-packages/nova/scheduler/client/report.py:498
2018-02-22 07:19:44.185 5 DEBUG nova.compute.resource_tracker [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Compute_service record updated for kolla:domain-c7.A9A92EE9-9488-4840-9F21-57E5EFC9B133 _update_available_resource /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:732
2018-02-22 07:19:44.185 5 DEBUG oslo_concurrency.lockutils [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Lock "compute_resources" released by "nova.compute.resource_tracker._update_available_resource" :: held 0.525s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-02-22 07:19:44.186 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._poll_unconfirmed_resizes run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:46.191 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:46.191 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._reclaim_queued_deletes run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:46.192 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] CONF.reclaim_instance_interval <= 0, skipping... _reclaim_queued_deletes /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:6603
2018-02-22 07:19:46.911 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:50.910 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._poll_rebooting_instances run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:52.905 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._heal_instance_info_cache run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:52.906 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Starting heal instance info cache _heal_instance_info_cache /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:5938
2018-02-22 07:19:52.906 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Rebuilding the list of instances to heal _heal_instance_info_cache /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:5942
2018-02-22 07:19:53.069 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "87be2ccc-c984-4af2-8d32-01e74dfc8eaf" acquired by "nova.compute.manager._locked_do_build_and_run_instance" :: waited 0.000s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-02-22 07:19:53.121 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Didn't find any instances for network info cache update. _heal_instance_info_cache /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:6014
2018-02-22 07:19:53.190 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Starting instance... _do_build_and_run_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:1797
2018-02-22 07:19:53.704 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "compute_resources" acquired by "nova.compute.resource_tracker.instance_claim" :: waited 0.000s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-02-22 07:19:53.706 5 DEBUG nova.compute.resource_tracker [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Memory overhead for 64 MB instance; 0 MB instance_claim /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:196
2018-02-22 07:19:53.706 5 DEBUG nova.compute.resource_tracker [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Disk overhead for 1 GB instance; 0 GB instance_claim /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:199
2018-02-22 07:19:53.707 5 DEBUG nova.compute.resource_tracker [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] CPU overhead for 1 vCPUs instance; 0 vCPU(s) instance_claim /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:202
2018-02-22 07:19:53.731 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Attempting claim on node domain-c7.A9A92EE9-9488-4840-9F21-57E5EFC9B133: memory 64 MB, disk 1 GB, vcpus 1 CPU
2018-02-22 07:19:53.732 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Total memory: 1374 MB, used: 512.00 MB
2018-02-22 07:19:53.737 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] memory limit not specified, defaulting to unlimited
2018-02-22 07:19:53.738 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Total disk: 72 GB, used: 0.00 GB
2018-02-22 07:19:53.738 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] disk limit not specified, defaulting to unlimited
2018-02-22 07:19:53.739 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Total vcpu: 2 VCPU, used: 0.00 VCPU
2018-02-22 07:19:53.739 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] vcpu limit not specified, defaulting to unlimited
2018-02-22 07:19:53.739 5 INFO nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Claim successful on node domain-c7.A9A92EE9-9488-4840-9F21-57E5EFC9B133
2018-02-22 07:19:54.203 5 DEBUG nova.compute.resource_tracker [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] We're on a Pike compute host in a deployment with all Pike compute hosts. Skipping auto-correction of allocations. _update_usage_from_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:1071
2018-02-22 07:19:54.333 5 DEBUG nova.scheduler.client.report [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Refreshing aggregate associations for resource provider 838382f7-e055-4b4d-9ae5-45ffcdde2ffd _ensure_resource_provider /var/lib/kolla/venv/lib/python2.7/site-packages/nova/scheduler/client/report.py:498
2018-02-22 07:19:54.436 5 DEBUG nova.scheduler.client.report [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Updating our resource provider generation from 10 to 11 _get_inventory_and_update_provider_generation /var/lib/kolla/venv/lib/python2.7/site-packages/nova/scheduler/client/report.py:541
2018-02-22 07:19:54.437 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "compute_resources" released by "nova.compute.resource_tracker.instance_claim" :: held 0.733s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-02-22 07:19:54.446 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Start building networks asynchronously for instance. _build_resources /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:2104
2018-02-22 07:19:54.787 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "compute_resources" acquired by "nova.compute.resource_tracker.update_usage" :: waited 0.000s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-02-22 07:19:54.849 5 DEBUG nova.scheduler.client.report [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Refreshing aggregate associations for resource provider 838382f7-e055-4b4d-9ae5-45ffcdde2ffd _ensure_resource_provider /var/lib/kolla/venv/lib/python2.7/site-packages/nova/scheduler/client/report.py:498
2018-02-22 07:19:55.008 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "compute_resources" released by "nova.compute.resource_tracker.update_usage" :: held 0.221s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-02-22 07:19:55.011 5 DEBUG nova.compute.utils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Using /dev/sd instead of None get_next_device_name /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/utils.py:172
2018-02-22 07:19:55.039 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Allocating IP information in the background. _allocate_network_async /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:1372
2018-02-22 07:19:55.040 5 DEBUG nova.network.neutronv2.api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] allocate_for_instance() allocate_for_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:829
2018-02-22 07:19:55.118 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._poll_rescued_instances run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:19:55.119 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Start building block device mappings for instance. _build_resources /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:2130
2018-02-22 07:19:56.122 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Start spawning the instance on the hypervisor. _build_and_run_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:1972
2018-02-22 07:19:56.247 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Getting desirable topologies for flavor Flavor(created_at=2018-02-21T02:47:22Z,deleted=False,deleted_at=None,disabled=False,ephemeral_gb=0,extra_specs={},flavorid='b07a956b-494d-424e-9f57-2b665ad94a35',id=1,is_public=True,memory_mb=64,name='mini',projects=<?>,root_gb=1,rxtx_factor=1.0,swap=0,updated_at=None,vcpu_weight=0,vcpus=1) and image_meta ImageMeta(checksum='39b633eaeb6b138ec995f3ee503f226d',container_format='bare',created_at=2018-02-21T02:58:22Z,direct_url=<?>,disk_format='vmdk',id=31fb6147-28b7-43c2-aa50-f0322d1ea126,min_disk=0,min_ram=0,name='trusty-cloud',owner='3233cf9d24e24812aa131d8f5cee7ff0',properties=ImageMetaProps,protected=<?>,size=21561344,status='active',tags=<?>,updated_at=2018-02-16T02:34:23Z,virtual_size=<?>,visibility=<?>), allow threads: False _get_desirable_cpu_topologies /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:560
2018-02-22 07:19:56.249 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Flavor limits 65536:65536:65536 _get_cpu_topology_constraints /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:306
2018-02-22 07:19:56.249 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Image limits 65536:65536:65536 _get_cpu_topology_constraints /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:317
2018-02-22 07:19:56.250 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Flavor pref -1:-1:-1 _get_cpu_topology_constraints /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:340
2018-02-22 07:19:56.250 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Image pref -1:-1:-1 _get_cpu_topology_constraints /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:359
2018-02-22 07:19:56.250 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Chosen -1:-1:-1 limits 65536:65536:65536 _get_cpu_topology_constraints /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:388
2018-02-22 07:19:56.261 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Topology preferred VirtCPUTopology(cores=-1,sockets=-1,threads=-1), maximum VirtCPUTopology(cores=65536,sockets=65536,threads=65536) _get_desirable_cpu_topologies /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:564
2018-02-22 07:19:56.262 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Build topologies for 1 vcpu(s) 1:1:1 _get_possible_cpu_topologies /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:427
2018-02-22 07:19:56.263 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Got 1 possible topologies _get_possible_cpu_topologies /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:454
2018-02-22 07:19:56.280 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Possible topologies [VirtCPUTopology(cores=1,sockets=1,threads=1)] _get_desirable_cpu_topologies /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:569
2018-02-22 07:19:56.281 5 DEBUG nova.virt.hardware [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Sorted desired topologies [VirtCPUTopology(cores=1,sockets=1,threads=1)] _get_desirable_cpu_topologies /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/hardware.py:595
2018-02-22 07:19:56.303 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-7e848952-406e-4985-a4f8-0929fe44a500 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:56.365 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-51a7953d-ae91-48c4-9bfc-364abf601f25 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:19:58.865 5 DEBUG nova.network.neutronv2.api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Successfully created port: 16d0ea5e-18ff-4e0c-b00b-53f509d8be14 _create_port_minimal /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:397
2018-02-22 07:20:02.901 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._cleanup_incomplete_migrations run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:20:02.901 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Cleaning up deleted instances with incomplete migration  _cleanup_incomplete_migrations /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:7052
2018-02-22 07:20:07.247 5 DEBUG nova.network.neutronv2.api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Successfully updated port: 16d0ea5e-18ff-4e0c-b00b-53f509d8be14 _update_port /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:434
2018-02-22 07:20:07.308 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Acquired semaphore "refresh_cache-87be2ccc-c984-4af2-8d32-01e74dfc8eaf" lock /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
2018-02-22 07:20:07.309 5 DEBUG nova.network.neutronv2.api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] _get_instance_nw_info() _get_instance_nw_info /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1302
2018-02-22 07:20:07.916 5 DEBUG nova.network.neutronv2.api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Instance cache missing network info. _get_preexisting_port_ids /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:2225
2018-02-22 07:20:07.957 5 DEBUG oslo_service.periodic_task [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Running periodic task ComputeManager._run_pending_deletes run_periodic_tasks /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_service/periodic_task.py:215
2018-02-22 07:20:07.958 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] Cleaning up deleted instances _run_pending_deletes /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:7009
2018-02-22 07:20:08.040 5 DEBUG nova.compute.manager [req-45d0db1a-2606-4758-9250-483843662b11 - - - - -] There are 0 instances to clean _run_pending_deletes /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:7018
2018-02-22 07:20:08.782 5 DEBUG nova.network.base_api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Updating instance_info_cache with network_info: [{"profile": {}, "ovs_interfaceid": "16d0ea5e-18ff-4e0c-b00b-53f509d8be14", "preserve_on_delete": false, "network": {"bridge": "br-int", "subnets": [{"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "192.168.10.108"}], "version": 4, "meta": {"dhcp_server": "192.168.10.100"}, "dns": [], "routes": [], "cidr": "192.168.10.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "192.168.10.2"}}], "meta": {"injected": false, "tenant_id": "3233cf9d24e24812aa131d8f5cee7ff0", "mtu": 1500}, "id": "d45a156f-c48e-4ea9-b235-abf96f43dda6", "label": "public"}, "devname": "tap16d0ea5e-18", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true, "datapath_type": "system", "ovs_hybrid_plug": true}, "address": "fa:16:3e:78:ae:05", "active": false, "type": "ovs", "id": "16d0ea5e-18ff-4e0c-b00b-53f509d8be14", "qbg_params": null}] update_instance_cache_with_nw_info /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/base_api.py:48
2018-02-22 07:20:08.885 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Releasing semaphore "refresh_cache-87be2ccc-c984-4af2-8d32-01e74dfc8eaf" lock /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
2018-02-22 07:20:08.886 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Instance network_info: |[{"profile": {}, "ovs_interfaceid": "16d0ea5e-18ff-4e0c-b00b-53f509d8be14", "preserve_on_delete": false, "network": {"bridge": "br-int", "subnets": [{"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "192.168.10.108"}], "version": 4, "meta": {"dhcp_server": "192.168.10.100"}, "dns": [], "routes": [], "cidr": "192.168.10.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "192.168.10.2"}}], "meta": {"injected": false, "tenant_id": "3233cf9d24e24812aa131d8f5cee7ff0", "mtu": 1500}, "id": "d45a156f-c48e-4ea9-b235-abf96f43dda6", "label": "public"}, "devname": "tap16d0ea5e-18", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true, "datapath_type": "system", "ovs_hybrid_plug": true}, "address": "fa:16:3e:78:ae:05", "active": false, "type": "ovs", "id": "16d0ea5e-18ff-4e0c-b00b-53f509d8be14", "qbg_params": null}]| _allocate_network_async /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:1387
2018-02-22 07:20:08.946 5 DEBUG nova.virt.vmwareapi.vm_util [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Creating VM on the ESX host create_vm /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vm_util.py:1312
2018-02-22 07:20:08.947 5 DEBUG oslo_vmware.service [-] Invoking Folder.CreateVM_Task with opID=oslo.vmware-3c45c0da-8295-4405-9115-36b8607ca849 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:20:09.228 5 DEBUG oslo_vmware.api [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Waiting for the task: (returnval){
   value = "task-142"
   _type = "Task"
 } to complete. wait_for_task /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py:395
2018-02-22 07:20:09.393 5 DEBUG nova.compute.manager [req-83c79f05-eff0-44fe-9b12-9d7a3cb0551c f354b842c3f74bb8bd824bb3d756b90e bad29dce97704f3e8948b813ef663c57 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Received event network-changed-16d0ea5e-18ff-4e0c-b00b-53f509d8be14 external_instance_event /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:6957
2018-02-22 07:20:09.394 5 DEBUG oslo_concurrency.lockutils [req-83c79f05-eff0-44fe-9b12-9d7a3cb0551c f354b842c3f74bb8bd824bb3d756b90e bad29dce97704f3e8948b813ef663c57 - default default] Acquired semaphore "refresh_cache-87be2ccc-c984-4af2-8d32-01e74dfc8eaf" lock /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212
2018-02-22 07:20:09.403 5 DEBUG nova.network.neutronv2.api [req-83c79f05-eff0-44fe-9b12-9d7a3cb0551c f354b842c3f74bb8bd824bb3d756b90e bad29dce97704f3e8948b813ef663c57 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] _get_instance_nw_info() _get_instance_nw_info /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1302
2018-02-22 07:20:09.915 5 DEBUG oslo_vmware.api [-] Task: {'id': task-142, 'name': CreateVM_Task} progress is 10%. _poll_task /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py:431
2018-02-22 07:20:10.315 5 DEBUG oslo_vmware.api [-] Task: {'id': task-142, 'name': CreateVM_Task} progress is 25%. _poll_task /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py:431
2018-02-22 07:20:10.841 5 DEBUG oslo_vmware.api [-] Task: {'id': task-142, 'name': CreateVM_Task} progress is 25%. _poll_task /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py:431
2018-02-22 07:20:11.208 5 DEBUG nova.network.base_api [req-83c79f05-eff0-44fe-9b12-9d7a3cb0551c f354b842c3f74bb8bd824bb3d756b90e bad29dce97704f3e8948b813ef663c57 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Updating instance_info_cache with network_info: [{"profile": {}, "ovs_interfaceid": "16d0ea5e-18ff-4e0c-b00b-53f509d8be14", "preserve_on_delete": false, "network": {"bridge": "br-int", "subnets": [{"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "192.168.10.108"}], "version": 4, "meta": {"dhcp_server": "192.168.10.100"}, "dns": [], "routes": [], "cidr": "192.168.10.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "192.168.10.2"}}], "meta": {"injected": false, "tenant_id": "3233cf9d24e24812aa131d8f5cee7ff0", "mtu": 1500}, "id": "d45a156f-c48e-4ea9-b235-abf96f43dda6", "label": "public"}, "devname": "tap16d0ea5e-18", "vnic_type": "normal", "qbh_params": null, "meta": {}, "details": {"port_filter": true, "datapath_type": "system", "ovs_hybrid_plug": true}, "address": "fa:16:3e:78:ae:05", "active": false, "type": "ovs", "id": "16d0ea5e-18ff-4e0c-b00b-53f509d8be14", "qbg_params": null}] update_instance_cache_with_nw_info /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/base_api.py:48
2018-02-22 07:20:11.259 5 DEBUG oslo_concurrency.lockutils [req-83c79f05-eff0-44fe-9b12-9d7a3cb0551c f354b842c3f74bb8bd824bb3d756b90e bad29dce97704f3e8948b813ef663c57 - default default] Releasing semaphore "refresh_cache-87be2ccc-c984-4af2-8d32-01e74dfc8eaf" lock /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:225
2018-02-22 07:20:11.290 5 DEBUG oslo_vmware.exceptions [-] Fault InvalidDeviceSpec not matched. get_fault_class /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/exceptions.py:295
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall [-] in fixed duration looping call: VimFaultException: Invalid configuration for device '0'.
Faults: ['InvalidDeviceSpec']
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall Traceback (most recent call last):
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/common/loopingcall.py", line 75, in _inner
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall     self.f(*self.args, **self.kw)
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py", line 452, in _poll_task
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall     raise task_ex
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall VimFaultException: Invalid configuration for device '0'.
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall Faults: ['InvalidDeviceSpec']
2018-02-22 07:20:11.290 5 ERROR oslo_vmware.common.loopingcall 
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Instance failed to spawn: VimFaultException: Invalid configuration for device '0'.
Faults: ['InvalidDeviceSpec']
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Traceback (most recent call last):
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py", line 2162, in _build_resources
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     yield resources
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py", line 1977, in _build_and_run_instance
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     block_device_info=block_device_info)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/driver.py", line 323, in spawn
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     admin_password, network_info, block_device_info)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vmops.py", line 735, in spawn
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     metadata)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vmops.py", line 301, in build_virtual_machine
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     config_spec, self._root_resource_pool)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vm_util.py", line 1333, in create_vm
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     {'ostype': config_spec.guestId})
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     self.force_reraise()
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     six.reraise(self.type_, self.value, self.tb)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vm_util.py", line 1318, in create_vm
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     task_info = session._wait_for_task(vm_create_task)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/driver.py", line 545, in _wait_for_task
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     return self.wait_for_task(task_ref)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py", line 396, in wait_for_task
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     return evt.wait()
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/eventlet/event.py", line 121, in wait
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     return hubs.get_hub().switch()
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 294, in switch
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     return self.greenlet.switch()
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/common/loopingcall.py", line 75, in _inner
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     self.f(*self.args, **self.kw)
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]   File "/var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/api.py", line 452, in _poll_task
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf]     raise task_ex
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] VimFaultException: Invalid configuration for device '0'.
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Faults: ['InvalidDeviceSpec']
2018-02-22 07:20:11.298 5 ERROR nova.compute.manager [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] 
2018-02-22 07:20:11.308 5 INFO nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Terminating instance
2018-02-22 07:20:11.330 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Start destroying the instance on the hypervisor. _shutdown_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:2276
2018-02-22 07:20:11.331 5 DEBUG nova.virt.vmwareapi.vmops [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Destroying instance destroy /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vmops.py:1122
2018-02-22 07:20:11.331 5 DEBUG oslo_vmware.service [-] Invoking SearchIndex.FindAllByUuid with opID=oslo.vmware-3a9d6a8d-ac67-49de-b6b1-1117c6b5c72b request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:20:11.377 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-633ec3f5-d68f-4048-9d43-0229166d3052 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:20:11.532 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-10ff4e55-024a-4873-9e63-656b4ba655a0 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:20:11.623 5 DEBUG oslo_vmware.service [-] Invoking PropertyCollector.RetrievePropertiesEx with opID=oslo.vmware-1820ee1f-87fd-4f65-b08d-59a2f0a1f177 request_handler /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_vmware/service.py:354
2018-02-22 07:20:11.720 5 WARNING nova.virt.vmwareapi.vmops [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Instance does not exist on backend: InstanceNotFound: Instance 87be2ccc-c984-4af2-8d32-01e74dfc8eaf could not be found.
2018-02-22 07:20:11.723 5 DEBUG nova.virt.vmwareapi.vmops [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Instance destroyed destroy /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/vmwareapi/vmops.py:1124
2018-02-22 07:20:11.723 5 INFO nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Took 0.39 seconds to destroy the instance on the hypervisor.
2018-02-22 07:20:11.724 5 DEBUG nova.compute.claims [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Aborting claim: [Claim: 64 MB memory, 1 GB disk] abort /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/claims.py:123
2018-02-22 07:20:11.725 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "compute_resources" acquired by "nova.compute.resource_tracker.abort_instance_claim" :: waited 0.000s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2018-02-22 07:20:11.728 5 DEBUG nova.compute.resource_tracker [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] We're on a Pike compute host in a deployment with all Pike compute hosts. Skipping auto-correction of allocations. _update_usage_from_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/resource_tracker.py:1071
2018-02-22 07:20:11.893 5 DEBUG nova.scheduler.client.report [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Refreshing aggregate associations for resource provider 838382f7-e055-4b4d-9ae5-45ffcdde2ffd _ensure_resource_provider /var/lib/kolla/venv/lib/python2.7/site-packages/nova/scheduler/client/report.py:498
2018-02-22 07:20:11.956 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "compute_resources" released by "nova.compute.resource_tracker.abort_instance_claim" :: held 0.231s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2018-02-22 07:20:11.959 5 DEBUG nova.compute.utils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Invalid configuration for device '0'.
Faults: ['InvalidDeviceSpec'] notify_about_instance_usage /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/utils.py:328
2018-02-22 07:20:11.965 5 DEBUG nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] [instance: 87be2ccc-c984-4af2-8d32-01e74dfc8eaf] Build of instance 87be2ccc-c984-4af2-8d32-01e74dfc8eaf was re-scheduled: Invalid configuration for device '0'.
Faults: ['InvalidDeviceSpec'] _do_build_and_run_instance /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:1847
2018-02-22 07:20:12.346 5 INFO nova.scheduler.client.report [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Deleted allocation for instance 87be2ccc-c984-4af2-8d32-01e74dfc8eaf
2018-02-22 07:20:12.346 5 WARNING nova.compute.manager [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] 4 consecutive build failures
2018-02-22 07:20:12.347 5 DEBUG oslo_concurrency.lockutils [req-45430c22-2c2c-4442-9843-45cad3e4bf73 fd69a6dd9c534e7b835a8508247a5e7b 3233cf9d24e24812aa131d8f5cee7ff0 - default default] Lock "87be2ccc-c984-4af2-8d32-01e74dfc8eaf" released by "nova.compute.manager._locked_do_build_and_run_instance" :: held 19.278s inner /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282